[11:01:17.803] INFO: *** Welcome to pxar ***
[11:01:17.803] INFO: *** Today: 2016/06/30
[11:01:17.835] INFO: *** Version: v1.9.0-814-g7497
[11:01:17.836] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//dacParameters35_C15.dat
[11:01:17.862] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:01:17.862] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//defaultMaskFile.dat
[11:01:17.863] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C15.dat
[11:01:17.969] INFO: clk: 4
[11:01:17.969] INFO: ctr: 4
[11:01:17.969] INFO: sda: 19
[11:01:17.969] INFO: tin: 9
[11:01:17.969] INFO: level: 15
[11:01:17.969] INFO: triggerdelay: 0
[11:01:17.969] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:01:17.969] INFO: Log level: INFO
[11:01:17.988] QUIET: Connection to board DTB_WREKRL opened.
[11:01:17.991] 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:
------------------------------------------------------
[11:01:17.995] INFO: RPC call hashes of host and DTB match: 398089610
[11:01:19.529] INFO: DUT info:
[11:01:19.529] INFO: The DUT currently contains the following objects:
[11:01:19.529] INFO: 2 TBM Cores tbm08c (2 ON)
[11:01:19.529] INFO: TBM Core alpha (0): 7 registers set
[11:01:19.529] INFO: TBM Core beta (1): 7 registers set
[11:01:19.529] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:01:19.529] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.529] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.529] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.529] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.529] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.529] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.529] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.529] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.530] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.530] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.530] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.530] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.530] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.530] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.530] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.530] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:01:19.933] INFO: enter 'restricted' command line mode
[11:01:19.933] INFO: enter test to run
[11:01:28.471] INFO: test: PixelAlive no parameter change
[11:01:28.471] INFO: running: pixelalive
[11:01:28.480] INFO: ----------------------------------------------------------------------
[11:01:28.480] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:01:28.480] INFO: ----------------------------------------------------------------------
[11:01:28.799] INFO: Expecting 41600 events.
[11:01:33.135] INFO: 41600 events read in total (3617ms).
[11:01:33.302] INFO: Test took 4819ms.
[11:01:33.315] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:33.579] INFO: PixTestAlive::aliveTest() done
[11:01:33.579] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:01:33.610] INFO: enter test to run
[11:02:07.287] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:02:07.287] INFO: running: highrate
[11:02:07.287] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:02:07.607] INFO: ----------------------------------------------------------------------
[11:02:07.608] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:02:07.608] INFO: ----------------------------------------------------------------------
[11:02:07.608] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:02:07.608] INFO: edge/corner pixel THR is adjusted
[11:02:07.608] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:02:08.567] INFO: Collecting data for 5 seconds...
[11:02:13.584] INFO: Done with hot pixel readout
[11:02:25.444] INFO: PixTest:: pg_setup set to default.
[11:02:25.445] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:02:25.445] INFO: 41 hot pixels found in step 0
[11:02:26.459] INFO: Collecting data for 5 seconds...
[11:02:31.475] INFO: Done with hot pixel readout
[11:02:43.265] INFO: PixTest:: pg_setup set to default.
[11:02:43.266] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:02:43.266] INFO: 35 hot pixels found in step 1
[11:02:44.255] INFO: Collecting data for 5 seconds...
[11:02:49.271] INFO: Done with hot pixel readout
[11:03:00.810] INFO: PixTest:: pg_setup set to default.
[11:03:00.810] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:03:00.811] INFO: 30 hot pixels found in step 2
[11:03:01.798] INFO: Collecting data for 5 seconds...
[11:03:06.815] INFO: Done with hot pixel readout
[11:03:18.506] INFO: PixTest:: pg_setup set to default.
[11:03:18.506] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:03:18.506] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:03:18.507] INFO: 34 hot pixels found in step 3
[11:03:19.495] INFO: Collecting data for 5 seconds...
[11:03:24.513] INFO: Done with hot pixel readout
[11:03:36.382] INFO: PixTest:: pg_setup set to default.
[11:03:36.382] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:03:36.382] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:03:36.382] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:03:36.382] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:03:36.382] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:03:36.383] INFO: 33 hot pixels found in step 4
[11:03:37.371] INFO: Collecting data for 5 seconds...
[11:03:42.387] INFO: Done with hot pixel readout
[11:03:54.204] INFO: PixTest:: pg_setup set to default.
[11:03:54.204] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:03:54.204] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:03:54.204] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:03:54.205] INFO: 26 hot pixels found in step 5
[11:03:55.192] INFO: Collecting data for 5 seconds...
[11:04:00.208] INFO: Done with hot pixel readout
[11:04:12.034] INFO: PixTest:: pg_setup set to default.
[11:04:12.034] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:04:12.034] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:04:12.034] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:04:12.034] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:04:12.035] INFO: 15 hot pixels found in step 6
[11:04:13.023] INFO: Collecting data for 5 seconds...
[11:04:18.040] INFO: Done with hot pixel readout
[11:04:29.847] INFO: PixTest:: pg_setup set to default.
[11:04:29.847] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:04:29.847] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:04:29.847] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:04:29.848] INFO: 13 hot pixels found in step 7
[11:04:30.836] INFO: Collecting data for 5 seconds...
[11:04:35.853] INFO: Done with hot pixel readout
[11:04:47.670] INFO: PixTest:: pg_setup set to default.
[11:04:47.670] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:04:47.670] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:04:47.671] INFO: 22 hot pixels found in step 8
[11:04:48.659] INFO: Collecting data for 5 seconds...
[11:04:53.675] INFO: Done with hot pixel readout
[11:05:05.519] INFO: PixTest:: pg_setup set to default.
[11:05:05.519] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:05:05.520] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:05:05.521] INFO: 21 hot pixels found in step 9
[11:05:06.510] INFO: Collecting data for 5 seconds...
[11:05:11.526] INFO: Done with hot pixel readout
[11:05:23.350] INFO: PixTest:: pg_setup set to default.
[11:05:23.350] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:05:23.351] INFO: 17 hot pixels found in step 10
[11:05:24.339] INFO: Collecting data for 5 seconds...
[11:05:29.356] INFO: Done with hot pixel readout
[11:05:41.159] INFO: PixTest:: pg_setup set to default.
[11:05:41.159] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:05:41.160] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:05:41.160] INFO: 11 hot pixels found in step 11
[11:05:42.149] INFO: Collecting data for 5 seconds...
[11:05:47.165] INFO: Done with hot pixel readout
[11:05:58.942] INFO: PixTest:: pg_setup set to default.
[11:05:58.942] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:05:58.942] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:05:58.942] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:05:58.943] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:05:58.943] INFO: 11 hot pixels found in step 12
[11:05:59.931] INFO: Collecting data for 5 seconds...
[11:06:04.947] INFO: Done with hot pixel readout
[11:06:16.725] INFO: PixTest:: pg_setup set to default.
[11:06:16.725] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:06:16.725] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:06:16.726] INFO: 11 hot pixels found in step 13
[11:06:17.713] INFO: Collecting data for 5 seconds...
[11:06:22.729] INFO: Done with hot pixel readout
[11:06:34.410] INFO: PixTest:: pg_setup set to default.
[11:06:34.410] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:06:34.410] INFO: 15 hot pixels found in step 14
[11:06:34.442] INFO: 15 hot pixels could not be trimmed and have been masked.
[11:06:34.446] INFO: PixTest::trimHotPixels() done
[11:06:34.471] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C0.dat
[11:06:34.476] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C1.dat
[11:06:34.482] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C2.dat
[11:06:34.487] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C3.dat
[11:06:34.492] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C4.dat
[11:06:34.497] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C5.dat
[11:06:34.503] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C6.dat
[11:06:34.508] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C7.dat
[11:06:34.513] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C8.dat
[11:06:34.518] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C9.dat
[11:06:34.523] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C10.dat
[11:06:34.528] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C11.dat
[11:06:34.534] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C12.dat
[11:06:34.539] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C13.dat
[11:06:34.544] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C14.dat
[11:06:34.549] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C15.dat
[11:06:34.554] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//defaultMaskFile.dat
[11:06:34.564] INFO: enter test to run
[11:07:12.860] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:07:12.861] INFO: running: highrate
[11:07:12.865] INFO: ----------------------------------------------------------------------
[11:07:12.865] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:07:12.865] INFO: ----------------------------------------------------------------------
[11:07:12.865] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:07:12.865] INFO: edge/corner pixel THR is adjusted
[11:07:12.865] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:07:13.827] INFO: Collecting data for 1 seconds...
[11:07:14.831] INFO: Done with hot pixel readout
[11:07:18.828] INFO: PixTest:: pg_setup set to default.
[11:07:18.829] INFO: 0 hot pixels found in step 0
[11:07:18.834] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:07:18.924] INFO: PixTest::trimHotPixels() done
[11:07:18.924] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C0.dat
[11:07:18.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C1.dat
[11:07:18.943] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C2.dat
[11:07:18.948] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C3.dat
[11:07:18.953] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C4.dat
[11:07:18.959] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C5.dat
[11:07:18.964] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C6.dat
[11:07:18.969] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C7.dat
[11:07:18.974] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C8.dat
[11:07:18.980] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C9.dat
[11:07:18.985] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C10.dat
[11:07:18.990] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C11.dat
[11:07:18.996] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C12.dat
[11:07:18.001] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C13.dat
[11:07:19.007] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C14.dat
[11:07:19.012] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//trimParameters35_C15.dat
[11:07:19.017] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-47_FPIXTest-17C-FNAL-160627-1455_2016-06-27_14h55m_1467057337/000_FPIXTest_p17//defaultMaskFile.dat
[11:07:19.034] INFO: enter test to run
[11:07:54.156] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:07:54.156] INFO: running: xray
[11:07:54.171] INFO: ----------------------------------------------------------------------
[11:07:54.172] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:07:54.172] INFO: ----------------------------------------------------------------------
[11:07:55.135] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:08:06.676] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:08:36.002] INFO: Resuming triggers.
[11:08:47.541] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[11:09:17.361] INFO: Resuming triggers.
[11:09:28.902] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:09:58.498] INFO: Resuming triggers.
[11:10:10.038] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[11:10:39.841] INFO: Resuming triggers.
[11:10:51.383] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[11:11:21.887] INFO: Resuming triggers.
[11:11:33.426] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:12:03.141] INFO: Resuming triggers.
[11:12:14.683] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[11:12:44.711] INFO: Resuming triggers.
[11:12:56.249] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[11:13:25.533] INFO: Resuming triggers.
[11:13:33.568] INFO: data taking finished, elapsed time: 100 seconds.
[11:13:54.298] INFO: PixTest:: pg_setup set to default.
[11:13:54.301] INFO: PixTestXray::doPhRun() done
[11:13:54.475] INFO: enter test to run
[11:14:32.489] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:14:32.490] INFO: running: xray
[11:14:32.491] INFO: ----------------------------------------------------------------------
[11:14:32.491] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:14:32.491] INFO: ----------------------------------------------------------------------
[11:14:33.454] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:14:40.282] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:15:10.360] INFO: Resuming triggers.
[11:15:17.185] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[11:15:47.243] INFO: Resuming triggers.
[11:15:54.067] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[11:16:24.104] INFO: Resuming triggers.
[11:16:30.929] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[11:17:01.388] INFO: Resuming triggers.
[11:17:08.217] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:17:38.426] INFO: Resuming triggers.
[11:17:45.253] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[11:18:15.322] INFO: Resuming triggers.
[11:18:22.154] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[11:18:52.288] INFO: Resuming triggers.
[11:18:59.117] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[11:19:29.259] INFO: Resuming triggers.
[11:19:36.092] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[11:20:06.193] INFO: Resuming triggers.
[11:20:13.023] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:20:43.157] INFO: Resuming triggers.
[11:20:49.985] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[11:21:20.556] INFO: Resuming triggers.
[11:21:27.386] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[11:21:58.072] INFO: Resuming triggers.
[11:22:04.901] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[11:22:35.640] INFO: Resuming triggers.
[11:22:42.466] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[11:23:13.895] INFO: Resuming triggers.
[11:23:18.636] INFO: data taking finished, elapsed time: 100 seconds.
[11:23:41.187] INFO: PixTest:: pg_setup set to default.
[11:23:41.190] INFO: PixTestXray::doPhRun() done
[11:23:41.343] INFO: enter test to run
[11:24:13.237] INFO: test: HighRate no parameter change
[11:24:13.238] INFO: running: highrate
[11:24:13.257] INFO: ----------------------------------------------------------------------
[11:24:13.257] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:24:13.257] INFO: ----------------------------------------------------------------------
[11:24:13.413] INFO: Expecting 768 events.
[11:24:14.547] INFO: 768 events read in total (419ms).
[11:24:14.547] INFO: Test took 1268ms.
[11:24:15.350] INFO: Expecting 41600 events.
[11:24:18.520] INFO: 41600 events read in total (2643ms).
[11:24:18.521] INFO: Test took 3948ms.
[11:24:18.556] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:19.273] INFO: Expecting 41600 events.
[11:24:22.484] INFO: 41600 events read in total (2684ms).
[11:24:22.485] INFO: Test took 3912ms.
[11:24:22.519] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:23.241] INFO: Expecting 41600 events.
[11:24:26.459] INFO: 41600 events read in total (2692ms).
[11:24:26.460] INFO: Test took 3924ms.
[11:24:26.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:27.218] INFO: Expecting 41600 events.
[11:24:30.456] INFO: 41600 events read in total (2711ms).
[11:24:30.457] INFO: Test took 3945ms.
[11:24:30.491] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:31.217] INFO: Expecting 41600 events.
[11:24:34.473] INFO: 41600 events read in total (2729ms).
[11:24:34.474] INFO: Test took 3966ms.
[11:24:34.508] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:35.230] INFO: Expecting 41600 events.
[11:24:38.457] INFO: 41600 events read in total (2700ms).
[11:24:38.458] INFO: Test took 3931ms.
[11:24:38.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:39.214] INFO: Expecting 41600 events.
[11:24:42.455] INFO: 41600 events read in total (2714ms).
[11:24:42.456] INFO: Test took 3941ms.
[11:24:42.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:43.215] INFO: Expecting 41600 events.
[11:24:46.454] INFO: 41600 events read in total (2713ms).
[11:24:46.455] INFO: Test took 3947ms.
[11:24:46.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:47.215] INFO: Expecting 41600 events.
[11:24:50.448] INFO: 41600 events read in total (2706ms).
[11:24:50.449] INFO: Test took 3942ms.
[11:24:50.483] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:51.209] INFO: Expecting 41600 events.
[11:24:54.454] INFO: 41600 events read in total (2718ms).
[11:24:54.455] INFO: Test took 3955ms.
[11:24:54.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:55.211] INFO: Expecting 41600 events.
[11:24:58.462] INFO: 41600 events read in total (2724ms).
[11:24:58.463] INFO: Test took 3956ms.
[11:24:58.496] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:59.218] INFO: Expecting 41600 events.
[11:25:02.459] INFO: 41600 events read in total (2714ms).
[11:25:02.460] INFO: Test took 3945ms.
[11:25:02.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:03.218] INFO: Expecting 41600 events.
[11:25:06.455] INFO: 41600 events read in total (2710ms).
[11:25:06.455] INFO: Test took 3944ms.
[11:25:06.489] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:07.212] INFO: Expecting 41600 events.
[11:25:10.452] INFO: 41600 events read in total (2713ms).
[11:25:10.453] INFO: Test took 3945ms.
[11:25:10.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:11.212] INFO: Expecting 41600 events.
[11:25:14.436] INFO: 41600 events read in total (2697ms).
[11:25:14.437] INFO: Test took 3934ms.
[11:25:14.471] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:15.197] INFO: Expecting 41600 events.
[11:25:18.442] INFO: 41600 events read in total (2718ms).
[11:25:18.443] INFO: Test took 3955ms.
[11:25:18.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:19.199] INFO: Expecting 41600 events.
[11:25:22.439] INFO: 41600 events read in total (2713ms).
[11:25:22.440] INFO: Test took 3944ms.
[11:25:22.473] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:23.198] INFO: Expecting 41600 events.
[11:25:26.436] INFO: 41600 events read in total (2712ms).
[11:25:26.437] INFO: Test took 3946ms.
[11:25:26.470] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:27.196] INFO: Expecting 41600 events.
[11:25:30.408] INFO: 41600 events read in total (2685ms).
[11:25:30.409] INFO: Test took 3921ms.
[11:25:30.443] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:31.168] INFO: Expecting 41600 events.
[11:25:34.253] INFO: 41600 events read in total (2558ms).
[11:25:34.254] INFO: Test took 3794ms.
[11:25:34.287] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:34.645] INFO: enter test to run
[11:25:52.301] INFO: test: HighRate no parameter change
[11:25:52.301] INFO: running: highrate
[11:25:52.302] INFO: ----------------------------------------------------------------------
[11:25:52.302] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:25:52.302] INFO: ----------------------------------------------------------------------
[11:25:52.913] INFO: Expecting 208000 events.
[11:26:04.754] INFO: 208000 events read in total (11315ms).
[11:26:04.757] INFO: Test took 12446ms.
[11:26:04.896] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:05.147] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:26:05.148] INFO: number of red-efficiency pixels: 61 46 75 124 128 120 107 88 113 121 136 101 93 56 18 19
[11:26:05.148] INFO: number of X-ray hits detected: 64124 41816 64349 102563 110566 113962 111586 86739 86741 105981 97151 80477 81248 46816 18623 21373
[11:26:05.148] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:26:05.148] INFO: number of Vcal hits detected: 207938 207954 207925 207875 207870 207877 207892 207911 207887 207878 207863 207899 207904 207942 207982 207981
[11:26:05.148] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[11:26:05.148] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[11:26:05.148] INFO: X-ray hit rate [MHz/cm2]: 18.8 12.3 18.9 30.1 32.4 33.4 32.7 25.4 25.4 31.1 28.5 23.6 23.8 13.7 5.5 6.3
[11:26:05.148] INFO: PixTestHighRate::doXPixelAlive() done
[11:26:05.201] INFO: PixTest:: pg_setup set to default.
[11:26:05.214] INFO: enter test to run
[11:26:28.525] INFO: test: HighRate no parameter change
[11:26:28.525] INFO: running: highrate
[11:26:28.526] INFO: ----------------------------------------------------------------------
[11:26:28.526] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:26:28.526] INFO: ----------------------------------------------------------------------
[11:26:29.145] INFO: Expecting 208000 events.
[11:26:42.271] INFO: 208000 events read in total (12599ms).
[11:26:42.276] INFO: Test took 13741ms.
[11:26:42.565] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:42.864] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:26:42.864] INFO: number of red-efficiency pixels: 170 148 208 411 523 367 343 267 294 427 394 239 241 140 38 54
[11:26:42.864] INFO: number of X-ray hits detected: 130084 83812 130338 207912 224474 229781 226884 175907 176245 214183 196374 163973 164565 95219 37840 43366
[11:26:42.864] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:26:42.864] INFO: number of Vcal hits detected: 207822 207847 207771 207553 207445 207593 207642 207720 207689 207548 207581 207752 207750 207851 207962 207946
[11:26:42.864] 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.8 99.9 99.9 99.9 100.0 100.0
[11:26:42.864] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[11:26:42.864] INFO: X-ray hit rate [MHz/cm2]: 38.1 24.6 38.2 60.9 65.8 67.4 66.5 51.6 51.7 62.8 57.6 48.1 48.2 27.9 11.1 12.7
[11:26:42.864] INFO: PixTestHighRate::doXPixelAlive() done
[11:26:42.914] INFO: PixTest:: pg_setup set to default.
[11:26:42.923] INFO: enter test to run
[11:27:11.036] INFO: test: HighRate no parameter change
[11:27:11.036] INFO: running: highrate
[11:27:11.037] INFO: ----------------------------------------------------------------------
[11:27:11.037] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:27:11.037] INFO: ----------------------------------------------------------------------
[11:27:11.650] INFO: Expecting 208000 events.
[11:27:26.656] INFO: 208000 events read in total (14479ms).
[11:27:26.663] INFO: Test took 15618ms.
[11:27:27.096] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:27.444] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:27:27.444] INFO: number of red-efficiency pixels: 358 258 457 1016 1129 914 861 618 767 1020 941 563 556 293 58 70
[11:27:27.444] INFO: number of X-ray hits detected: 195867 127312 195680 314291 338545 347709 341021 265574 264895 322726 296986 247272 249982 143936 57254 65040
[11:27:27.444] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:27:27.444] INFO: number of Vcal hits detected: 207588 207709 207443 206751 206557 206915 206978 207260 207127 206759 206868 207360 207390 207673 207942 207930
[11:27:27.444] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.4 99.4 99.5 99.6 99.7 99.6 99.5 99.5 99.7 99.7 99.9 100.0 100.0
[11:27:27.444] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.4 99.3 99.5 99.5 99.6 99.6 99.4 99.5 99.7 99.7 99.8 100.0 100.0
[11:27:27.444] INFO: X-ray hit rate [MHz/cm2]: 57.4 37.3 57.4 92.1 99.2 101.9 100.0 77.8 77.6 94.6 87.0 72.5 73.3 42.2 16.8 19.1
[11:27:27.444] INFO: PixTestHighRate::doXPixelAlive() done
[11:27:27.491] INFO: PixTest:: pg_setup set to default.
[11:27:27.510] INFO: enter test to run
[11:28:01.764] INFO: test: exit no parameter change
[11:28:02.073] QUIET: Connection to board 33 closed.
[11:28:02.087] INFO: pXar: this is the end, my friend