[09:52:02.405] INFO: *** Welcome to pxar ***
[09:52:02.405] INFO: *** Today: 2016/05/11
[09:52:02.829] INFO: *** Version: v1.9.0-796-gef167-dirty
[09:52:02.829] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//dacParameters35_C15.dat
[09:52:02.870] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:52:02.870] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//defaultMaskFile.dat
[09:52:02.872] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C15.dat
[09:52:03.016] INFO: clk: 4
[09:52:03.016] INFO: ctr: 4
[09:52:03.016] INFO: sda: 19
[09:52:03.016] INFO: tin: 9
[09:52:03.016] INFO: level: 15
[09:52:03.016] INFO: triggerdelay: 0
[09:52:03.016] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[09:52:03.016] INFO: Log level: INFO
[09:52:03.033] QUIET: Connection to board DTB_WREKRL opened.
[09:52:03.037] 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:52:03.039] INFO: RPC call hashes of host and DTB match: 398089610
[09:52:04.574] INFO: DUT info:
[09:52:04.575] INFO: The DUT currently contains the following objects:
[09:52:04.575] INFO: 2 TBM Cores tbm08c (2 ON)
[09:52:04.575] INFO: TBM Core alpha (0): 7 registers set
[09:52:04.575] INFO: TBM Core beta (1): 7 registers set
[09:52:04.575] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:52:04.575] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.575] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.575] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.575] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.575] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.575] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.575] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.575] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.576] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.576] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.576] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.576] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.576] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.576] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.576] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:04.576] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.021] INFO: enter 'restricted' command line mode
[09:52:05.021] INFO: enter test to run
[09:52:13.672] INFO: test: PixelAlive no parameter change
[09:52:13.672] INFO: running: pixelalive
[09:52:13.739] INFO: ----------------------------------------------------------------------
[09:52:13.739] 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:52:13.739] INFO: ----------------------------------------------------------------------
[09:52:14.056] INFO: Expecting 41600 events.
[09:52:18.402] INFO: 41600 events read in total (3628ms).
[09:52:18.569] INFO: Test took 4827ms.
[09:52:18.582] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:52:18.847] INFO: PixTestAlive::aliveTest() done
[09:52:18.848] INFO: number of dead pixels (per ROC): 0 0 0 3 0 2 0 0 0 1 0 1 0 0 0 0
[09:52:18.916] INFO: enter test to run
[09:52:56.191] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:52:56.192] INFO: running: highrate
[09:52:56.192] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:52:56.442] INFO: ----------------------------------------------------------------------
[09:52:56.442] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:52:56.442] INFO: ----------------------------------------------------------------------
[09:52:56.442] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:52:56.442] INFO: edge/corner pixel THR is adjusted
[09:52:56.442] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:52:57.400] INFO: Collecting data for 5 seconds...
[09:53:02.419] INFO: Done with hot pixel readout
[09:53:14.795] INFO: PixTest:: pg_setup set to default.
[09:53:14.822] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:53:14.822] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:53:14.822] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:53:14.823] INFO: 83 hot pixels found in step 0
[09:53:15.817] INFO: Collecting data for 5 seconds...
[09:53:20.835] INFO: Done with hot pixel readout
[09:53:33.723] INFO: PixTest:: pg_setup set to default.
[09:53:33.723] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:53:33.724] INFO: 66 hot pixels found in step 1
[09:53:34.720] INFO: Collecting data for 5 seconds...
[09:53:39.740] INFO: Done with hot pixel readout
[09:53:52.664] INFO: PixTest:: pg_setup set to default.
[09:53:52.664] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:53:52.664] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:53:52.665] INFO: 50 hot pixels found in step 2
[09:53:53.663] INFO: Collecting data for 5 seconds...
[09:53:58.684] INFO: Done with hot pixel readout
[09:54:11.680] INFO: PixTest:: pg_setup set to default.
[09:54:11.680] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:54:11.681] INFO: 46 hot pixels found in step 3
[09:54:12.681] INFO: Collecting data for 5 seconds...
[09:54:17.701] INFO: Done with hot pixel readout
[09:54:30.718] INFO: PixTest:: pg_setup set to default.
[09:54:30.718] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:54:30.718] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:54:30.718] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:54:30.718] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:54:30.719] INFO: 44 hot pixels found in step 4
[09:54:31.717] INFO: Collecting data for 5 seconds...
[09:54:36.736] INFO: Done with hot pixel readout
[09:54:49.544] INFO: PixTest:: pg_setup set to default.
[09:54:49.544] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:54:49.544] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:54:49.545] INFO: 54 hot pixels found in step 5
[09:54:50.544] INFO: Collecting data for 5 seconds...
[09:54:55.565] INFO: Done with hot pixel readout
[09:55:08.354] INFO: PixTest:: pg_setup set to default.
[09:55:08.354] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:08.354] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:08.355] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:08.355] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:08.355] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:08.355] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:08.355] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:08.355] INFO: 45 hot pixels found in step 6
[09:55:09.353] INFO: Collecting data for 5 seconds...
[09:55:14.370] INFO: Done with hot pixel readout
[09:55:27.005] INFO: PixTest:: pg_setup set to default.
[09:55:27.005] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:27.005] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:27.005] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:27.006] INFO: 50 hot pixels found in step 7
[09:55:28.004] INFO: Collecting data for 5 seconds...
[09:55:33.021] INFO: Done with hot pixel readout
[09:55:45.688] INFO: PixTest:: pg_setup set to default.
[09:55:45.688] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:45.688] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:45.688] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:55:45.689] INFO: 48 hot pixels found in step 8
[09:55:46.689] INFO: Collecting data for 5 seconds...
[09:55:51.705] INFO: Done with hot pixel readout
[09:56:04.365] INFO: PixTest:: pg_setup set to default.
[09:56:04.365] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:04.365] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:04.365] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:04.366] INFO: 40 hot pixels found in step 9
[09:56:05.364] INFO: Collecting data for 5 seconds...
[09:56:10.381] INFO: Done with hot pixel readout
[09:56:23.088] INFO: PixTest:: pg_setup set to default.
[09:56:23.088] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:23.088] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:23.088] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:23.088] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:23.089] INFO: 45 hot pixels found in step 10
[09:56:24.088] INFO: Collecting data for 5 seconds...
[09:56:29.105] INFO: Done with hot pixel readout
[09:56:41.821] INFO: PixTest:: pg_setup set to default.
[09:56:41.821] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:41.821] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:41.821] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:41.821] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:41.821] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:41.821] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:41.821] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:41.821] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:41.822] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:41.822] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:56:41.822] INFO: 55 hot pixels found in step 11
[09:56:42.822] INFO: Collecting data for 5 seconds...
[09:56:47.838] INFO: Done with hot pixel readout
[09:57:00.502] INFO: PixTest:: pg_setup set to default.
[09:57:00.503] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:00.503] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:00.503] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:00.503] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:00.503] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:00.503] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:00.503] INFO: 39 hot pixels found in step 12
[09:57:01.501] INFO: Collecting data for 5 seconds...
[09:57:06.520] INFO: Done with hot pixel readout
[09:57:19.212] INFO: PixTest:: pg_setup set to default.
[09:57:19.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:19.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:19.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:19.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:19.212] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:19.213] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:19.213] INFO: 37 hot pixels found in step 13
[09:57:20.211] INFO: Collecting data for 5 seconds...
[09:57:25.228] INFO: Done with hot pixel readout
[09:57:37.895] INFO: PixTest:: pg_setup set to default.
[09:57:37.895] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:37.895] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:37.895] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[09:57:37.896] INFO: 35 hot pixels found in step 14
[09:57:37.938] INFO: 35 hot pixels could not be trimmed and have been masked.
[09:57:37.942] INFO: PixTest::trimHotPixels() done
[09:57:37.942] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C0.dat
[09:57:37.947] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C1.dat
[09:57:37.954] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C2.dat
[09:57:37.960] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C3.dat
[09:57:37.965] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C4.dat
[09:57:37.970] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C5.dat
[09:57:37.975] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C6.dat
[09:57:37.980] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C7.dat
[09:57:37.986] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C8.dat
[09:57:37.991] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C9.dat
[09:57:37.996] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C10.dat
[09:57:37.001] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C11.dat
[09:57:38.006] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C12.dat
[09:57:38.011] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C13.dat
[09:57:38.017] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C14.dat
[09:57:38.022] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C15.dat
[09:57:38.027] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//defaultMaskFile.dat
[09:57:38.037] INFO: enter test to run
[09:58:35.213] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:58:35.213] INFO: running: highrate
[09:58:35.218] INFO: ----------------------------------------------------------------------
[09:58:35.218] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:58:35.218] INFO: ----------------------------------------------------------------------
[09:58:35.218] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:58:35.218] INFO: edge/corner pixel THR is adjusted
[09:58:35.218] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:58:36.176] INFO: Collecting data for 1 seconds...
[09:58:37.180] INFO: Done with hot pixel readout
[09:58:41.746] INFO: PixTest:: pg_setup set to default.
[09:58:41.747] INFO: 0 hot pixels found in step 0
[09:58:41.752] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:58:41.823] INFO: PixTest::trimHotPixels() done
[09:58:41.823] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C0.dat
[09:58:41.834] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C1.dat
[09:58:41.839] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C2.dat
[09:58:41.845] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C3.dat
[09:58:41.850] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C4.dat
[09:58:41.855] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C5.dat
[09:58:41.860] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C6.dat
[09:58:41.866] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C7.dat
[09:58:41.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C8.dat
[09:58:41.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C9.dat
[09:58:41.881] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C10.dat
[09:58:41.886] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C11.dat
[09:58:41.891] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C12.dat
[09:58:41.897] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C13.dat
[09:58:41.902] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C14.dat
[09:58:41.907] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//trimParameters35_C15.dat
[09:58:41.912] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-P-NE_FPIXTest-17C-FNAL-160505-1041_2016-05-05_10h42m_1462462925/000_FPIXTest_p17//defaultMaskFile.dat
[09:58:41.922] INFO: enter test to run
[09:59:27.613] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:59:27.613] INFO: running: xray
[09:59:27.614] INFO: ----------------------------------------------------------------------
[09:59:27.614] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:59:27.614] INFO: ----------------------------------------------------------------------
[09:59:28.597] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:59:39.358] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[10:00:09.114] INFO: Resuming triggers.
[10:00:19.875] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[10:00:49.644] INFO: Resuming triggers.
[10:01:00.409] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[10:01:30.337] INFO: Resuming triggers.
[10:01:41.103] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[10:02:10.943] INFO: Resuming triggers.
[10:02:21.708] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[10:02:51.516] INFO: Resuming triggers.
[10:03:02.285] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[10:03:32.599] INFO: Resuming triggers.
[10:03:43.367] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[10:04:12.679] INFO: Resuming triggers.
[10:04:23.448] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[10:04:53.718] INFO: Resuming triggers.
[10:05:04.489] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[10:05:34.702] INFO: Resuming triggers.
[10:05:38.157] INFO: data taking finished, elapsed time: 100 seconds.
[10:05:48.307] INFO: PixTest:: pg_setup set to default.
[10:05:48.310] INFO: PixTestXray::doPhRun() done
[10:05:48.451] INFO: enter test to run
[10:06:31.034] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:06:31.034] INFO: running: xray
[10:06:31.035] INFO: ----------------------------------------------------------------------
[10:06:31.035] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:06:31.035] INFO: ----------------------------------------------------------------------
[10:06:32.007] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:06:37.806] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[10:07:08.225] INFO: Resuming triggers.
[10:07:14.031] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:07:44.470] INFO: Resuming triggers.
[10:07:50.276] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[10:08:20.629] INFO: Resuming triggers.
[10:08:26.436] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:08:56.837] INFO: Resuming triggers.
[10:09:02.643] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[10:09:33.081] INFO: Resuming triggers.
[10:09:38.890] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:10:09.268] INFO: Resuming triggers.
[10:10:15.080] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[10:10:45.508] INFO: Resuming triggers.
[10:10:51.317] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:11:21.754] INFO: Resuming triggers.
[10:11:27.568] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[10:11:57.983] INFO: Resuming triggers.
[10:12:03.794] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[10:12:34.217] INFO: Resuming triggers.
[10:12:40.031] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[10:13:10.470] INFO: Resuming triggers.
[10:13:16.282] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:13:46.713] INFO: Resuming triggers.
[10:13:52.524] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[10:14:23.736] INFO: Resuming triggers.
[10:14:29.548] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[10:15:00.335] INFO: Resuming triggers.
[10:15:06.150] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[10:15:37.378] INFO: Resuming triggers.
[10:15:43.189] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:16:14.998] INFO: Resuming triggers.
[10:16:20.814] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[10:16:52.304] INFO: Resuming triggers.
[10:16:53.877] INFO: data taking finished, elapsed time: 100 seconds.
[10:17:02.409] INFO: PixTest:: pg_setup set to default.
[10:17:02.412] INFO: PixTestXray::doPhRun() done
[10:17:02.563] INFO: enter test to run
[10:17:28.133] INFO: test: HighRate no parameter change
[10:17:28.133] INFO: running: highrate
[10:17:28.134] INFO: ----------------------------------------------------------------------
[10:17:28.134] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:17:28.134] INFO: ----------------------------------------------------------------------
[10:17:28.277] INFO: Expecting 768 events.
[10:17:29.411] INFO: 768 events read in total (419ms).
[10:17:29.411] INFO: Test took 1269ms.
[10:17:30.215] INFO: Expecting 41600 events.
[10:17:33.422] INFO: 41600 events read in total (2681ms).
[10:17:33.423] INFO: Test took 3989ms.
[10:17:33.461] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:34.180] INFO: Expecting 41600 events.
[10:17:37.446] INFO: 41600 events read in total (2739ms).
[10:17:37.447] INFO: Test took 3966ms.
[10:17:37.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:38.204] INFO: Expecting 41600 events.
[10:17:41.472] INFO: 41600 events read in total (2741ms).
[10:17:41.473] INFO: Test took 3966ms.
[10:17:41.511] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:42.225] INFO: Expecting 41600 events.
[10:17:45.507] INFO: 41600 events read in total (2755ms).
[10:17:45.508] INFO: Test took 3976ms.
[10:17:45.546] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:46.264] INFO: Expecting 41600 events.
[10:17:49.552] INFO: 41600 events read in total (2761ms).
[10:17:49.553] INFO: Test took 3986ms.
[10:17:49.591] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:50.309] INFO: Expecting 41600 events.
[10:17:53.590] INFO: 41600 events read in total (2754ms).
[10:17:53.591] INFO: Test took 3981ms.
[10:17:53.632] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:54.339] INFO: Expecting 41600 events.
[10:17:57.603] INFO: 41600 events read in total (2738ms).
[10:17:57.604] INFO: Test took 3952ms.
[10:17:57.642] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:58.358] INFO: Expecting 41600 events.
[10:18:01.647] INFO: 41600 events read in total (2762ms).
[10:18:01.649] INFO: Test took 3987ms.
[10:18:01.687] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:02.403] INFO: Expecting 41600 events.
[10:18:05.689] INFO: 41600 events read in total (2760ms).
[10:18:05.691] INFO: Test took 3985ms.
[10:18:05.729] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:06.443] INFO: Expecting 41600 events.
[10:18:09.712] INFO: 41600 events read in total (2742ms).
[10:18:09.713] INFO: Test took 3963ms.
[10:18:09.751] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:10.469] INFO: Expecting 41600 events.
[10:18:13.767] INFO: 41600 events read in total (2770ms).
[10:18:13.768] INFO: Test took 3996ms.
[10:18:13.805] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:14.523] INFO: Expecting 41600 events.
[10:18:17.821] INFO: 41600 events read in total (2771ms).
[10:18:17.822] INFO: Test took 3998ms.
[10:18:17.860] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:18.574] INFO: Expecting 41600 events.
[10:18:21.855] INFO: 41600 events read in total (2754ms).
[10:18:21.856] INFO: Test took 3976ms.
[10:18:21.894] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:22.610] INFO: Expecting 41600 events.
[10:18:25.901] INFO: 41600 events read in total (2764ms).
[10:18:25.902] INFO: Test took 3987ms.
[10:18:25.941] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:26.658] INFO: Expecting 41600 events.
[10:18:29.952] INFO: 41600 events read in total (2767ms).
[10:18:29.953] INFO: Test took 3991ms.
[10:18:29.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:30.705] INFO: Expecting 41600 events.
[10:18:34.008] INFO: 41600 events read in total (2776ms).
[10:18:34.008] INFO: Test took 3997ms.
[10:18:34.047] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:34.757] INFO: Expecting 41600 events.
[10:18:38.034] INFO: 41600 events read in total (2751ms).
[10:18:38.035] INFO: Test took 3968ms.
[10:18:38.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:38.792] INFO: Expecting 41600 events.
[10:18:42.086] INFO: 41600 events read in total (2768ms).
[10:18:42.087] INFO: Test took 3994ms.
[10:18:42.126] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:42.841] INFO: Expecting 41600 events.
[10:18:46.104] INFO: 41600 events read in total (2736ms).
[10:18:46.105] INFO: Test took 3959ms.
[10:18:46.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:46.857] INFO: Expecting 41600 events.
[10:18:49.918] INFO: 41600 events read in total (2534ms).
[10:18:49.919] INFO: Test took 3756ms.
[10:18:49.956] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:50.315] INFO: enter test to run
[10:18:57.564] INFO: test: HighRate no parameter change
[10:18:57.564] INFO: running: highrate
[10:18:57.565] INFO: ----------------------------------------------------------------------
[10:18:57.565] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:18:57.565] INFO: ----------------------------------------------------------------------
[10:18:58.184] INFO: Expecting 208000 events.
[10:19:10.293] INFO: 208000 events read in total (11582ms).
[10:19:10.297] INFO: Test took 12724ms.
[10:19:10.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:10.720] INFO: number of dead pixels (per ROC): 0 0 1 3 0 2 0 0 0 1 0 1 0 0 0 0
[10:19:10.720] INFO: number of red-efficiency pixels: 103 50 91 169 166 173 156 112 117 144 164 151 137 74 22 20
[10:19:10.720] INFO: number of X-ray hits detected: 71184 49125 78861 129727 129396 131702 133489 97230 86972 114688 109634 103832 103353 61172 24042 28010
[10:19:10.720] 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:19:10.720] INFO: number of Vcal hits detected: 207895 207949 207858 207669 207828 207725 207842 207887 207880 207802 207830 207798 207862 207922 207978 207980
[10:19:10.720] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[10:19:10.720] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[10:19:10.720] INFO: X-ray hit rate [MHz/cm2]: 20.9 14.4 23.1 38.0 37.9 38.6 39.1 28.5 25.5 33.6 32.1 30.4 30.3 17.9 7.0 8.2
[10:19:10.720] INFO: PixTestHighRate::doXPixelAlive() done
[10:19:10.764] INFO: PixTest:: pg_setup set to default.
[10:19:10.779] INFO: enter test to run
[10:19:34.620] INFO: test: HighRate no parameter change
[10:19:34.620] INFO: running: highrate
[10:19:34.621] INFO: ----------------------------------------------------------------------
[10:19:34.621] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:19:34.621] INFO: ----------------------------------------------------------------------
[10:19:35.238] INFO: Expecting 208000 events.
[10:19:49.535] INFO: 208000 events read in total (13770ms).
[10:19:49.541] INFO: Test took 14911ms.
[10:19:49.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:50.209] INFO: number of dead pixels (per ROC): 0 0 1 3 0 2 0 0 0 1 0 0 0 0 0 0
[10:19:50.209] INFO: number of red-efficiency pixels: 299 150 318 559 585 606 609 397 370 435 508 498 417 238 61 77
[10:19:50.209] INFO: number of X-ray hits detected: 153108 104730 168886 278326 276632 282660 284304 207444 188015 245493 235581 222545 222076 130721 50722 60657
[10:19:50.209] 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:19:50.209] INFO: number of Vcal hits detected: 207676 207843 207602 207222 207362 207242 207320 207571 207601 207475 207454 207393 207557 207736 207935 207921
[10:19:50.209] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.7 99.7 99.8 99.8 99.8 99.8 99.7 99.8 99.9 100.0 100.0
[10:19:50.209] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.6 99.7 99.6 99.7 99.8 99.8 99.7 99.7 99.7 99.8 99.9 100.0 100.0
[10:19:50.209] INFO: X-ray hit rate [MHz/cm2]: 44.9 30.7 49.5 81.6 81.1 82.8 83.3 60.8 55.1 72.0 69.1 65.2 65.1 38.3 14.9 17.8
[10:19:50.209] INFO: PixTestHighRate::doXPixelAlive() done
[10:19:50.258] INFO: PixTest:: pg_setup set to default.
[10:19:50.273] INFO: enter test to run
[10:20:31.275] INFO: test: HighRate no parameter change
[10:20:31.275] INFO: running: highrate
[10:20:31.277] INFO: ----------------------------------------------------------------------
[10:20:31.277] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:20:31.277] INFO: ----------------------------------------------------------------------
[10:20:31.892] INFO: Expecting 208000 events.
[10:20:48.993] INFO: 208000 events read in total (16574ms).
[10:20:49.002] INFO: Test took 17716ms.
[10:20:49.554] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:49.939] INFO: number of dead pixels (per ROC): 0 0 1 3 0 2 0 0 0 1 0 1 0 0 0 0
[10:20:49.939] INFO: number of red-efficiency pixels: 678 299 812 1453 1475 1599 1552 927 767 1159 1242 1236 1112 573 118 111
[10:20:49.939] INFO: number of X-ray hits detected: 241841 166055 266215 438696 435811 444283 447673 327829 295564 387499 370704 352623 349362 207551 80698 96082
[10:20:49.939] 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:20:49.939] INFO: number of Vcal hits detected: 207134 207679 206772 205804 205965 205662 205815 206749 207093 206489 206373 206277 206605 207279 207878 207888
[10:20:49.939] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.5 99.1 99.1 99.0 99.1 99.5 99.6 99.4 99.3 99.3 99.4 99.7 99.9 99.9
[10:20:49.939] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.4 98.9 99.0 98.9 98.9 99.4 99.6 99.3 99.2 99.2 99.3 99.7 99.9 99.9
[10:20:49.939] INFO: X-ray hit rate [MHz/cm2]: 70.9 48.7 78.0 128.6 127.7 130.2 131.2 96.1 86.6 113.6 108.7 103.4 102.4 60.8 23.7 28.2
[10:20:49.939] INFO: PixTestHighRate::doXPixelAlive() done
[10:20:49.984] INFO: PixTest:: pg_setup set to default.
[10:20:49.999] INFO: enter test to run
[10:20:59.987] INFO: test: exit no parameter change
[10:21:00.334] QUIET: Connection to board 33 closed.
[10:21:00.335] INFO: pXar: this is the end, my friend