[09:41:00.941] INFO: *** Welcome to pxar ***
[09:41:00.941] INFO: *** Today: 2016/07/29
[09:41:01.557] INFO: *** Version: v1.9.0-818-g96727
[09:41:01.557] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//dacParameters35_C15.dat
[09:41:01.630] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:41:01.655] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//defaultMaskFile.dat
[09:41:01.661] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C15.dat
[09:41:01.784] INFO: clk: 4
[09:41:01.784] INFO: ctr: 4
[09:41:01.784] INFO: sda: 19
[09:41:01.784] INFO: tin: 9
[09:41:01.784] INFO: level: 15
[09:41:01.784] INFO: triggerdelay: 0
[09:41:01.784] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[09:41:01.784] INFO: Log level: INFO
[09:41:01.836] QUIET: Connection to board DTB_WREKRL opened.
[09:41:01.839] 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:
------------------------------------------------------
[09:41:01.842] INFO: RPC call hashes of host and DTB match: 398089610
[09:41:03.372] INFO: DUT info:
[09:41:03.373] INFO: The DUT currently contains the following objects:
[09:41:03.373] INFO: 2 TBM Cores tbm08c (2 ON)
[09:41:03.373] INFO: TBM Core alpha (0): 7 registers set
[09:41:03.373] INFO: TBM Core beta (1): 7 registers set
[09:41:03.373] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:41:03.373] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.373] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:41:03.812] INFO: enter 'restricted' command line mode
[09:41:03.813] INFO: enter test to run
[09:41:29.386] INFO: test: PixelAlive no parameter change
[09:41:29.386] INFO: running: pixelalive
[09:41:29.465] INFO: ----------------------------------------------------------------------
[09:41:29.465] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:41:29.465] INFO: ----------------------------------------------------------------------
[09:41:29.790] INFO: Expecting 41600 events.
[09:41:34.129] INFO: 41600 events read in total (3620ms).
[09:41:34.296] INFO: Test took 4827ms.
[09:41:34.310] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:34.583] INFO: PixTestAlive::aliveTest() done
[09:41:34.583] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 39 99 2 0 0 0 0 0 0 0
[09:41:34.638] INFO: enter test to run
[09:42:34.162] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:42:34.162] INFO: running: highrate
[09:42:34.177] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:42:34.415] INFO: ----------------------------------------------------------------------
[09:42:34.415] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:42:34.415] INFO: ----------------------------------------------------------------------
[09:42:34.415] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:42:34.415] INFO: edge/corner pixel THR is adjusted
[09:42:34.415] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:42:35.373] INFO: Collecting data for 5 seconds...
[09:42:40.392] INFO: Done with hot pixel readout
[09:42:52.522] INFO: PixTest:: pg_setup set to default.
[09:42:52.524] INFO: 72 hot pixels found in step 0
[09:42:53.516] INFO: Collecting data for 5 seconds...
[09:42:58.533] INFO: Done with hot pixel readout
[09:43:10.150] INFO: PixTest:: pg_setup set to default.
[09:43:10.151] INFO: 38 hot pixels found in step 1
[09:43:11.139] INFO: Collecting data for 5 seconds...
[09:43:16.157] INFO: Done with hot pixel readout
[09:43:27.921] INFO: PixTest:: pg_setup set to default.
[09:43:27.922] INFO: 30 hot pixels found in step 2
[09:43:28.914] INFO: Collecting data for 5 seconds...
[09:43:33.935] INFO: Done with hot pixel readout
[09:43:45.651] INFO: PixTest:: pg_setup set to default.
[09:43:45.652] INFO: 26 hot pixels found in step 3
[09:43:46.644] INFO: Collecting data for 5 seconds...
[09:43:51.662] INFO: Done with hot pixel readout
[09:44:03.309] INFO: PixTest:: pg_setup set to default.
[09:44:03.309] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:44:03.310] INFO: 21 hot pixels found in step 4
[09:44:04.302] INFO: Collecting data for 5 seconds...
[09:44:09.321] INFO: Done with hot pixel readout
[09:44:21.081] INFO: PixTest:: pg_setup set to default.
[09:44:21.081] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:44:21.081] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:44:21.081] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:44:21.082] INFO: 20 hot pixels found in step 5
[09:44:22.074] INFO: Collecting data for 5 seconds...
[09:44:27.092] INFO: Done with hot pixel readout
[09:44:38.947] INFO: PixTest:: pg_setup set to default.
[09:44:38.947] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:44:38.947] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:44:38.948] INFO: 15 hot pixels found in step 6
[09:44:39.940] INFO: Collecting data for 5 seconds...
[09:44:44.960] INFO: Done with hot pixel readout
[09:44:57.105] INFO: PixTest:: pg_setup set to default.
[09:44:57.105] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:44:57.105] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:44:57.105] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:44:57.105] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:44:57.106] INFO: 10 hot pixels found in step 7
[09:44:58.099] INFO: Collecting data for 5 seconds...
[09:45:03.118] INFO: Done with hot pixel readout
[09:45:15.285] INFO: PixTest:: pg_setup set to default.
[09:45:15.285] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:15.285] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:15.285] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:15.285] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:15.285] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:15.285] INFO: 11 hot pixels found in step 8
[09:45:16.277] INFO: Collecting data for 5 seconds...
[09:45:21.299] INFO: Done with hot pixel readout
[09:45:33.417] INFO: PixTest:: pg_setup set to default.
[09:45:33.417] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:33.417] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:33.417] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:33.417] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:33.418] INFO: 12 hot pixels found in step 9
[09:45:34.410] INFO: Collecting data for 5 seconds...
[09:45:39.430] INFO: Done with hot pixel readout
[09:45:51.329] INFO: PixTest:: pg_setup set to default.
[09:45:51.329] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:51.329] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:51.329] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:51.329] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:51.329] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:45:51.330] INFO: 12 hot pixels found in step 10
[09:45:52.322] INFO: Collecting data for 5 seconds...
[09:45:57.343] INFO: Done with hot pixel readout
[09:46:09.077] INFO: PixTest:: pg_setup set to default.
[09:46:09.077] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:09.077] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:09.077] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:09.077] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:09.077] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:09.077] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:09.077] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:09.078] INFO: 15 hot pixels found in step 11
[09:46:10.071] INFO: Collecting data for 5 seconds...
[09:46:15.092] INFO: Done with hot pixel readout
[09:46:26.959] INFO: PixTest:: pg_setup set to default.
[09:46:26.960] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:26.960] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:26.960] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:26.960] INFO: 10 hot pixels found in step 12
[09:46:27.955] INFO: Collecting data for 5 seconds...
[09:46:32.976] INFO: Done with hot pixel readout
[09:46:44.991] INFO: PixTest:: pg_setup set to default.
[09:46:44.991] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:44.991] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:44.991] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:44.991] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:46:44.992] INFO: 13 hot pixels found in step 13
[09:46:45.985] INFO: Collecting data for 5 seconds...
[09:46:50.001] INFO: Done with hot pixel readout
[09:47:02.883] INFO: PixTest:: pg_setup set to default.
[09:47:02.883] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:47:02.883] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:47:02.883] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:47:02.883] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:47:02.884] INFO: 11 hot pixels found in step 14
[09:47:02.920] INFO: 11 hot pixels could not be trimmed and have been masked.
[09:47:02.923] INFO: PixTest::trimHotPixels() done
[09:47:02.923] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C0.dat
[09:47:02.943] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C1.dat
[09:47:02.955] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C2.dat
[09:47:02.967] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C3.dat
[09:47:02.972] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C4.dat
[09:47:02.977] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C5.dat
[09:47:02.983] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C6.dat
[09:47:02.988] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C7.dat
[09:47:02.993] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C8.dat
[09:47:02.998] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C9.dat
[09:47:02.004] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C10.dat
[09:47:03.009] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C11.dat
[09:47:03.014] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C12.dat
[09:47:03.019] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C13.dat
[09:47:03.025] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C14.dat
[09:47:03.030] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C15.dat
[09:47:03.035] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//defaultMaskFile.dat
[09:47:03.051] INFO: enter test to run
[09:47:34.936] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:47:34.936] INFO: running: highrate
[09:47:34.940] INFO: ----------------------------------------------------------------------
[09:47:34.940] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:47:34.941] INFO: ----------------------------------------------------------------------
[09:47:34.941] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:47:34.941] INFO: edge/corner pixel THR is adjusted
[09:47:34.941] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:47:35.898] INFO: Collecting data for 1 seconds...
[09:47:36.902] INFO: Done with hot pixel readout
[09:47:40.821] INFO: PixTest:: pg_setup set to default.
[09:47:40.822] INFO: 0 hot pixels found in step 0
[09:47:40.827] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:47:40.923] INFO: PixTest::trimHotPixels() done
[09:47:40.923] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C0.dat
[09:47:40.931] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C1.dat
[09:47:40.938] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C2.dat
[09:47:40.943] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C3.dat
[09:47:40.948] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C4.dat
[09:47:40.954] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C5.dat
[09:47:40.959] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C6.dat
[09:47:40.964] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C7.dat
[09:47:40.969] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C8.dat
[09:47:40.974] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C9.dat
[09:47:40.979] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C10.dat
[09:47:40.984] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C11.dat
[09:47:40.990] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C12.dat
[09:47:40.995] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C13.dat
[09:47:40.000] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C14.dat
[09:47:40.005] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//trimParameters35_C15.dat
[09:47:41.010] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-27_FPIXTest-17C-FNAL-160727-1057_2016-07-27_10h57m_1469635077/000_FPIXTest_p17//defaultMaskFile.dat
[09:47:41.019] INFO: enter test to run
[09:48:00.303] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:48:00.303] INFO: running: xray
[09:48:00.305] INFO: ----------------------------------------------------------------------
[09:48:00.305] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:48:00.305] INFO: ----------------------------------------------------------------------
[09:48:01.268] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:48:12.867] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[09:48:42.540] INFO: Resuming triggers.
[09:48:54.142] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[09:49:23.899] INFO: Resuming triggers.
[09:49:35.505] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[09:50:05.146] INFO: Resuming triggers.
[09:50:16.752] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[09:50:46.438] INFO: Resuming triggers.
[09:50:58.042] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[09:51:27.629] INFO: Resuming triggers.
[09:51:39.232] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[09:52:08.928] INFO: Resuming triggers.
[09:52:20.531] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[09:52:50.233] INFO: Resuming triggers.
[09:53:01.834] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[09:53:31.703] INFO: Resuming triggers.
[09:53:39.202] INFO: data taking finished, elapsed time: 100 seconds.
[09:53:58.479] INFO: PixTest:: pg_setup set to default.
[09:53:58.482] INFO: PixTestXray::doPhRun() done
[09:53:58.728] INFO: enter test to run
[09:54:18.109] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[09:54:18.109] INFO: running: xray
[09:54:18.110] INFO: ----------------------------------------------------------------------
[09:54:18.110] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:54:18.110] INFO: ----------------------------------------------------------------------
[09:54:19.074] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:54:26.125] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[09:54:57.322] INFO: Resuming triggers.
[09:55:04.378] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[09:55:35.144] INFO: Resuming triggers.
[09:55:42.200] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[09:56:13.063] INFO: Resuming triggers.
[09:56:20.122] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[09:56:51.804] INFO: Resuming triggers.
[09:56:58.859] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[09:57:30.367] INFO: Resuming triggers.
[09:57:37.427] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[09:58:08.818] INFO: Resuming triggers.
[09:58:15.875] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[09:58:46.168] INFO: Resuming triggers.
[09:58:53.227] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[09:59:23.605] INFO: Resuming triggers.
[09:59:30.664] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[10:00:01.035] INFO: Resuming triggers.
[10:00:08.093] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[10:00:38.297] INFO: Resuming triggers.
[10:00:45.360] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[10:01:15.608] INFO: Resuming triggers.
[10:01:22.665] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[10:01:52.000] INFO: Resuming triggers.
[10:02:00.054] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[10:02:30.367] INFO: Resuming triggers.
[10:02:37.421] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[10:03:07.625] INFO: Resuming triggers.
[10:03:09.173] INFO: data taking finished, elapsed time: 100 seconds.
[10:03:16.177] INFO: PixTest:: pg_setup set to default.
[10:03:16.180] INFO: PixTestXray::doPhRun() done
[10:03:16.328] INFO: enter test to run
[10:07:56.647] INFO: test: HighRate no parameter change
[10:07:56.648] INFO: running: highrate
[10:07:56.649] INFO: ----------------------------------------------------------------------
[10:07:56.649] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:07:56.649] INFO: ----------------------------------------------------------------------
[10:07:56.788] INFO: Expecting 768 events.
[10:07:57.923] INFO: 768 events read in total (419ms).
[10:07:57.923] INFO: Test took 1268ms.
[10:07:58.726] INFO: Expecting 41600 events.
[10:08:01.733] INFO: 41600 events read in total (2480ms).
[10:08:01.734] INFO: Test took 3789ms.
[10:08:01.767] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:02.488] INFO: Expecting 41600 events.
[10:08:05.687] INFO: 41600 events read in total (2672ms).
[10:08:05.688] INFO: Test took 3903ms.
[10:08:05.721] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:06.444] INFO: Expecting 41600 events.
[10:08:09.706] INFO: 41600 events read in total (2735ms).
[10:08:09.707] INFO: Test took 3969ms.
[10:08:09.741] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:10.455] INFO: Expecting 41600 events.
[10:08:13.681] INFO: 41600 events read in total (2699ms).
[10:08:13.682] INFO: Test took 3925ms.
[10:08:13.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:14.441] INFO: Expecting 41600 events.
[10:08:17.740] INFO: 41600 events read in total (2772ms).
[10:08:17.741] INFO: Test took 4007ms.
[10:08:17.776] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:18.497] INFO: Expecting 41600 events.
[10:08:21.802] INFO: 41600 events read in total (2779ms).
[10:08:21.803] INFO: Test took 4010ms.
[10:08:21.837] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:22.556] INFO: Expecting 41600 events.
[10:08:25.825] INFO: 41600 events read in total (2742ms).
[10:08:25.826] INFO: Test took 3972ms.
[10:08:25.860] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:26.583] INFO: Expecting 41600 events.
[10:08:29.825] INFO: 41600 events read in total (2716ms).
[10:08:29.826] INFO: Test took 3949ms.
[10:08:29.860] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:30.583] INFO: Expecting 41600 events.
[10:08:33.850] INFO: 41600 events read in total (2741ms).
[10:08:33.851] INFO: Test took 3974ms.
[10:08:33.885] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:34.594] INFO: Expecting 41600 events.
[10:08:37.924] INFO: 41600 events read in total (2804ms).
[10:08:37.925] INFO: Test took 4023ms.
[10:08:37.959] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:38.680] INFO: Expecting 41600 events.
[10:08:41.953] INFO: 41600 events read in total (2746ms).
[10:08:41.954] INFO: Test took 3977ms.
[10:08:41.988] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:42.706] INFO: Expecting 41600 events.
[10:08:46.021] INFO: 41600 events read in total (2789ms).
[10:08:46.022] INFO: Test took 4016ms.
[10:08:46.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:46.780] INFO: Expecting 41600 events.
[10:08:50.080] INFO: 41600 events read in total (2774ms).
[10:08:50.081] INFO: Test took 4007ms.
[10:08:50.114] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:50.824] INFO: Expecting 41600 events.
[10:08:54.039] INFO: 41600 events read in total (2688ms).
[10:08:54.040] INFO: Test took 3908ms.
[10:08:54.074] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:54.800] INFO: Expecting 41600 events.
[10:08:58.106] INFO: 41600 events read in total (2779ms).
[10:08:58.107] INFO: Test took 4015ms.
[10:08:58.141] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:58.866] INFO: Expecting 41600 events.
[10:09:02.163] INFO: 41600 events read in total (2770ms).
[10:09:02.164] INFO: Test took 4005ms.
[10:09:02.197] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:02.923] INFO: Expecting 41600 events.
[10:09:06.287] INFO: 41600 events read in total (2837ms).
[10:09:06.287] INFO: Test took 4070ms.
[10:09:06.321] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:07.044] INFO: Expecting 41600 events.
[10:09:10.402] INFO: 41600 events read in total (2831ms).
[10:09:10.403] INFO: Test took 4063ms.
[10:09:10.437] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:11.158] INFO: Expecting 41600 events.
[10:09:14.382] INFO: 41600 events read in total (2697ms).
[10:09:14.383] INFO: Test took 3928ms.
[10:09:14.417] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:15.140] INFO: Expecting 41600 events.
[10:09:18.227] INFO: 41600 events read in total (2561ms).
[10:09:18.228] INFO: Test took 3794ms.
[10:09:18.262] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:18.642] INFO: enter test to run
[10:09:48.023] INFO: test: HighRate no parameter change
[10:09:48.023] INFO: running: highrate
[10:09:48.024] INFO: ----------------------------------------------------------------------
[10:09:48.024] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:09:48.024] INFO: ----------------------------------------------------------------------
[10:09:48.656] INFO: Expecting 208000 events.
[10:10:00.950] INFO: 208000 events read in total (11768ms).
[10:10:00.953] INFO: Test took 12918ms.
[10:10:01.100] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:10:01.354] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 39 100 3 0 0 0 0 0 0 0
[10:10:01.354] INFO: number of red-efficiency pixels: 91 59 94 114 137 113 221 190 131 91 106 78 83 50 21 18
[10:10:01.354] INFO: number of X-ray hits detected: 68147 40129 65671 102840 106024 108028 111056 75095 92358 92648 88200 79377 83884 50824 21524 25410
[10:10:01.354] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:10:01.354] INFO: number of Vcal hits detected: 207904 207941 207904 207884 207858 207886 205859 202906 207718 207905 207892 207922 207914 207950 207979 207982
[10:10:01.354] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[10:10:01.354] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.0 97.6 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[10:10:01.354] INFO: X-ray hit rate [MHz/cm2]: 20.0 11.8 19.2 30.1 31.1 31.7 32.6 22.0 27.1 27.2 25.9 23.3 24.6 14.9 6.3 7.4
[10:10:01.354] INFO: PixTestHighRate::doXPixelAlive() done
[10:10:01.399] INFO: PixTest:: pg_setup set to default.
[10:10:01.411] INFO: enter test to run
[10:10:13.919] INFO: test: HighRate no parameter change
[10:10:13.919] INFO: running: highrate
[10:10:13.920] INFO: ----------------------------------------------------------------------
[10:10:13.920] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:10:13.920] INFO: ----------------------------------------------------------------------
[10:10:14.541] INFO: Expecting 208000 events.
[10:10:28.653] INFO: 208000 events read in total (13585ms).
[10:10:28.658] INFO: Test took 14729ms.
[10:10:28.956] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:10:29.255] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 38 100 3 0 0 0 0 0 0 0
[10:10:29.255] INFO: number of red-efficiency pixels: 243 96 272 335 448 339 548 312 318 318 305 281 238 131 48 52
[10:10:29.255] INFO: number of X-ray hits detected: 136420 81122 132486 205850 213369 215710 221554 147234 178923 185181 176846 158424 168894 101823 43234 50768
[10:10:29.255] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:10:29.255] INFO: number of Vcal hits detected: 207732 207899 207702 207648 207524 207640 205487 202759 207520 207669 207674 207703 207751 207862 207951 207948
[10:10:29.255] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.7 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[10:10:29.256] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 98.8 97.5 99.8 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[10:10:29.256] INFO: X-ray hit rate [MHz/cm2]: 40.0 23.8 38.8 60.3 62.5 63.2 64.9 43.2 52.4 54.3 51.8 46.4 49.5 29.8 12.7 14.9
[10:10:29.256] INFO: PixTestHighRate::doXPixelAlive() done
[10:10:29.301] INFO: PixTest:: pg_setup set to default.
[10:10:29.317] INFO: enter test to run
[10:11:06.990] INFO: test: HighRate no parameter change
[10:11:06.990] INFO: running: highrate
[10:11:06.991] INFO: ----------------------------------------------------------------------
[10:11:06.991] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:11:06.991] INFO: ----------------------------------------------------------------------
[10:11:07.611] INFO: Expecting 208000 events.
[10:11:22.661] INFO: 208000 events read in total (14523ms).
[10:11:22.670] INFO: Test took 15668ms.
[10:11:23.098] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:23.441] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 39 100 2 0 0 0 0 0 0 0
[10:11:23.441] INFO: number of red-efficiency pixels: 549 217 572 728 1064 755 1111 489 672 580 727 564 483 312 94 83
[10:11:23.441] INFO: number of X-ray hits detected: 203682 121356 197430 307024 318889 322252 332188 217913 266839 277511 263642 237594 252101 153775 64789 76732
[10:11:23.441] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:11:23.442] INFO: number of Vcal hits detected: 207325 207765 207275 207183 206680 207081 204645 202545 207071 207345 207158 207348 207470 207649 207902 207915
[10:11:23.442] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.6 99.4 99.6 99.4 99.8 99.6 99.7 99.6 99.7 99.8 99.9 100.0 100.0
[10:11:23.442] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.6 99.4 99.6 98.4 97.4 99.6 99.7 99.6 99.7 99.7 99.8 100.0 100.0
[10:11:23.442] INFO: X-ray hit rate [MHz/cm2]: 59.7 35.6 57.9 90.0 93.5 94.5 97.4 63.9 78.2 81.3 77.3 69.6 73.9 45.1 19.0 22.5
[10:11:23.442] INFO: PixTestHighRate::doXPixelAlive() done
[10:11:23.491] INFO: PixTest:: pg_setup set to default.
[10:11:23.505] INFO: enter test to run
[10:11:39.510] INFO: test: exit no parameter change
[10:11:39.918] QUIET: Connection to board 33 closed.
[10:11:39.919] INFO: pXar: this is the end, my friend