[14:44:45.231] INFO: *** Welcome to pxar ***
[14:44:45.231] INFO: *** Today: 2016/04/22
[14:44:45.250] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:44:45.250] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//dacParameters35_C15.dat
[14:44:45.293] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:44:45.293] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//defaultMaskFile.dat
[14:44:45.293] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C15.dat
[14:44:45.444] INFO: clk: 4
[14:44:45.444] INFO: ctr: 4
[14:44:45.444] INFO: sda: 19
[14:44:45.444] INFO: tin: 9
[14:44:45.444] INFO: level: 15
[14:44:45.444] INFO: triggerdelay: 0
[14:44:45.444] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:44:45.444] INFO: Log level: INFO
[14:44:45.462] QUIET: Connection to board DTB_WREKRL opened.
[14:44:45.465] 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:
------------------------------------------------------
[14:44:45.468] INFO: RPC call hashes of host and DTB match: 398089610
[14:44:46.000] INFO: DUT info:
[14:44:46.000] INFO: The DUT currently contains the following objects:
[14:44:46.000] INFO: 2 TBM Cores tbm08c (2 ON)
[14:44:46.000] INFO: TBM Core alpha (0): 7 registers set
[14:44:46.000] INFO: TBM Core beta (1): 7 registers set
[14:44:46.000] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:44:46.000] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.000] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.000] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:46.001] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:44:47.404] INFO: enter 'restricted' command line mode
[14:44:47.404] INFO: enter test to run
[14:45:03.956] INFO: test: PixelAlive no parameter change
[14:45:03.957] INFO: running: pixelalive
[14:45:03.966] INFO: ----------------------------------------------------------------------
[14:45:03.966] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:45:03.966] INFO: ----------------------------------------------------------------------
[14:45:04.293] INFO: Expecting 41600 events.
[14:45:08.631] INFO: 41600 events read in total (3620ms).
[14:45:08.793] INFO: Test took 4825ms.
[14:45:08.807] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:09.074] INFO: PixTestAlive::aliveTest() done
[14:45:09.074] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 81 0 1 0 1 0
[14:45:09.109] INFO: enter test to run
[14:45:35.652] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:45:35.652] INFO: running: highrate
[14:45:35.653] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:45:35.886] INFO: ----------------------------------------------------------------------
[14:45:35.886] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:45:35.886] INFO: ----------------------------------------------------------------------
[14:45:35.886] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:45:35.886] INFO: edge/corner pixel THR is adjusted
[14:45:35.886] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:45:36.845] INFO: Collecting data for 5 seconds...
[14:45:41.862] INFO: Done with hot pixel readout
[14:45:53.580] INFO: PixTest:: pg_setup set to default.
[14:45:53.581] INFO: 18 hot pixels found in step 0
[14:45:54.581] INFO: Collecting data for 5 seconds...
[14:45:59.598] INFO: Done with hot pixel readout
[14:46:11.481] INFO: PixTest:: pg_setup set to default.
[14:46:11.482] INFO: 20 hot pixels found in step 1
[14:46:12.479] INFO: Collecting data for 5 seconds...
[14:46:17.497] INFO: Done with hot pixel readout
[14:46:29.134] INFO: PixTest:: pg_setup set to default.
[14:46:29.134] INFO: 19 hot pixels found in step 2
[14:46:30.132] INFO: Collecting data for 5 seconds...
[14:46:35.149] INFO: Done with hot pixel readout
[14:46:47.434] INFO: PixTest:: pg_setup set to default.
[14:46:47.435] INFO: 17 hot pixels found in step 3
[14:46:48.430] INFO: Collecting data for 5 seconds...
[14:46:53.447] INFO: Done with hot pixel readout
[14:47:05.712] INFO: PixTest:: pg_setup set to default.
[14:47:05.712] INFO: 19 hot pixels found in step 4
[14:47:06.709] INFO: Collecting data for 5 seconds...
[14:47:11.725] INFO: Done with hot pixel readout
[14:47:24.009] INFO: PixTest:: pg_setup set to default.
[14:47:24.009] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:47:24.009] INFO: 22 hot pixels found in step 5
[14:47:25.006] INFO: Collecting data for 5 seconds...
[14:47:30.023] INFO: Done with hot pixel readout
[14:47:42.244] INFO: PixTest:: pg_setup set to default.
[14:47:42.244] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:47:42.244] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:47:42.245] INFO: 22 hot pixels found in step 6
[14:47:43.240] INFO: Collecting data for 5 seconds...
[14:47:48.257] INFO: Done with hot pixel readout
[14:48:00.454] INFO: PixTest:: pg_setup set to default.
[14:48:00.454] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:00.454] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:00.454] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:00.455] INFO: 16 hot pixels found in step 7
[14:48:01.450] INFO: Collecting data for 5 seconds...
[14:48:06.468] INFO: Done with hot pixel readout
[14:48:18.724] INFO: PixTest:: pg_setup set to default.
[14:48:18.724] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:18.724] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:18.724] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:18.724] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:18.724] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:18.724] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:18.725] INFO: 15 hot pixels found in step 8
[14:48:19.721] INFO: Collecting data for 5 seconds...
[14:48:24.739] INFO: Done with hot pixel readout
[14:48:36.675] INFO: PixTest:: pg_setup set to default.
[14:48:36.675] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:36.675] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:36.675] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:36.675] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:36.675] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:36.675] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:36.676] INFO: 15 hot pixels found in step 9
[14:48:37.673] INFO: Collecting data for 5 seconds...
[14:48:42.691] INFO: Done with hot pixel readout
[14:48:54.795] INFO: PixTest:: pg_setup set to default.
[14:48:54.795] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:54.795] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:54.795] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:54.795] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:48:54.796] INFO: 10 hot pixels found in step 10
[14:48:55.792] INFO: Collecting data for 5 seconds...
[14:49:00.810] INFO: Done with hot pixel readout
[14:49:12.997] INFO: PixTest:: pg_setup set to default.
[14:49:12.997] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:12.997] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:12.997] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:12.997] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:12.998] INFO: 6 hot pixels found in step 11
[14:49:13.998] INFO: Collecting data for 5 seconds...
[14:49:19.015] INFO: Done with hot pixel readout
[14:49:30.974] INFO: PixTest:: pg_setup set to default.
[14:49:30.974] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:30.974] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:30.975] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:30.975] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:30.975] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:30.975] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:30.975] INFO: 10 hot pixels found in step 12
[14:49:31.972] INFO: Collecting data for 5 seconds...
[14:49:36.989] INFO: Done with hot pixel readout
[14:49:48.874] INFO: PixTest:: pg_setup set to default.
[14:49:48.874] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:48.874] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:48.874] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:49:48.875] INFO: 7 hot pixels found in step 13
[14:49:49.871] INFO: Collecting data for 5 seconds...
[14:49:54.887] INFO: Done with hot pixel readout
[14:50:04.222] INFO: PixTest:: pg_setup set to default.
[14:50:04.222] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:50:04.222] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:50:04.222] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:50:04.222] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:50:04.222] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:50:04.223] INFO: 9 hot pixels found in step 14
[14:50:04.263] INFO: 9 hot pixels could not be trimmed and have been masked.
[14:50:04.266] INFO: PixTest::trimHotPixels() done
[14:50:04.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C0.dat
[14:50:04.272] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C1.dat
[14:50:04.292] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C2.dat
[14:50:04.298] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C3.dat
[14:50:04.303] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C4.dat
[14:50:04.309] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C5.dat
[14:50:04.315] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C6.dat
[14:50:04.320] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C7.dat
[14:50:04.325] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C8.dat
[14:50:04.331] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C9.dat
[14:50:04.336] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C10.dat
[14:50:04.341] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C11.dat
[14:50:04.347] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C12.dat
[14:50:04.352] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C13.dat
[14:50:04.357] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C14.dat
[14:50:04.363] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C15.dat
[14:50:04.368] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//defaultMaskFile.dat
[14:50:04.379] INFO: enter test to run
[14:50:35.586] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:50:35.586] INFO: running: highrate
[14:50:35.591] INFO: ----------------------------------------------------------------------
[14:50:35.591] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:50:35.591] INFO: ----------------------------------------------------------------------
[14:50:35.591] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:50:35.591] INFO: edge/corner pixel THR is adjusted
[14:50:35.591] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:50:36.549] INFO: Collecting data for 1 seconds...
[14:50:37.553] INFO: Done with hot pixel readout
[14:50:41.842] INFO: PixTest:: pg_setup set to default.
[14:50:41.843] INFO: 0 hot pixels found in step 0
[14:50:41.848] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:50:41.926] INFO: PixTest::trimHotPixels() done
[14:50:41.926] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C0.dat
[14:50:41.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C1.dat
[14:50:41.941] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C2.dat
[14:50:41.946] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C3.dat
[14:50:41.951] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C4.dat
[14:50:41.957] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C5.dat
[14:50:41.962] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C6.dat
[14:50:41.967] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C7.dat
[14:50:41.972] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C8.dat
[14:50:41.978] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C9.dat
[14:50:41.983] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C10.dat
[14:50:41.988] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C11.dat
[14:50:41.994] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C12.dat
[14:50:41.999] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C13.dat
[14:50:41.004] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C14.dat
[14:50:42.009] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//trimParameters35_C15.dat
[14:50:42.015] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-G-2-08_FPIXTest-17C-FNAL-160420-1215_2016-04-20_12h16m_1461172589/000_FPIXTest_p17//defaultMaskFile.dat
[14:50:42.025] INFO: enter test to run
[14:51:07.746] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:51:07.746] INFO: running: xray
[14:51:07.747] INFO: ----------------------------------------------------------------------
[14:51:07.747] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:51:07.747] INFO: ----------------------------------------------------------------------
[14:51:08.710] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:51:19.550] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[14:51:49.274] INFO: Resuming triggers.
[14:52:00.114] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:52:29.666] INFO: Resuming triggers.
[14:52:40.511] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:53:09.999] INFO: Resuming triggers.
[14:53:20.842] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:53:50.366] INFO: Resuming triggers.
[14:54:01.211] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[14:54:30.734] INFO: Resuming triggers.
[14:54:41.571] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[14:55:11.063] INFO: Resuming triggers.
[14:55:21.904] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[14:55:51.490] INFO: Resuming triggers.
[14:56:02.331] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[14:56:31.782] INFO: Resuming triggers.
[14:56:42.626] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[14:57:12.146] INFO: Resuming triggers.
[14:57:14.905] INFO: data taking finished, elapsed time: 100 seconds.
[14:57:22.833] INFO: PixTest:: pg_setup set to default.
[14:57:22.836] INFO: PixTestXray::doPhRun() done
[14:57:22.977] INFO: enter test to run
[14:57:46.311] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:57:46.311] INFO: running: xray
[14:57:46.312] INFO: ----------------------------------------------------------------------
[14:57:46.312] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:57:46.312] INFO: ----------------------------------------------------------------------
[14:57:47.284] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:57:53.268] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[14:58:23.260] INFO: Resuming triggers.
[14:58:29.247] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:58:59.228] INFO: Resuming triggers.
[14:59:05.213] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[14:59:35.431] INFO: Resuming triggers.
[14:59:41.418] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[15:00:10.810] INFO: Resuming triggers.
[15:00:16.792] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[15:00:46.037] INFO: Resuming triggers.
[15:00:52.021] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[15:01:22.134] INFO: Resuming triggers.
[15:01:28.116] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[15:01:58.178] INFO: Resuming triggers.
[15:02:04.166] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[15:02:34.247] INFO: Resuming triggers.
[15:02:40.232] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[15:03:10.377] INFO: Resuming triggers.
[15:03:16.356] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:03:46.452] INFO: Resuming triggers.
[15:03:52.437] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[15:04:22.537] INFO: Resuming triggers.
[15:04:28.521] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[15:04:58.560] INFO: Resuming triggers.
[15:05:04.542] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[15:05:34.673] INFO: Resuming triggers.
[15:05:40.658] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[15:06:10.828] INFO: Resuming triggers.
[15:06:16.810] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[15:06:46.999] INFO: Resuming triggers.
[15:06:52.981] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[15:07:23.259] INFO: Resuming triggers.
[15:07:27.836] INFO: data taking finished, elapsed time: 100 seconds.
[15:07:51.125] INFO: PixTest:: pg_setup set to default.
[15:07:51.128] INFO: PixTestXray::doPhRun() done
[15:07:51.276] INFO: enter test to run
[15:08:19.090] INFO: test: HighRate no parameter change
[15:08:19.090] INFO: running: highrate
[15:08:19.092] INFO: ----------------------------------------------------------------------
[15:08:19.092] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:08:19.092] INFO: ----------------------------------------------------------------------
[15:08:19.234] INFO: Expecting 768 events.
[15:08:20.367] INFO: 768 events read in total (417ms).
[15:08:20.368] INFO: Test took 1269ms.
[15:08:21.171] INFO: Expecting 41600 events.
[15:08:24.381] INFO: 41600 events read in total (2683ms).
[15:08:24.382] INFO: Test took 4006ms.
[15:08:24.420] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:25.138] INFO: Expecting 41600 events.
[15:08:28.423] INFO: 41600 events read in total (2758ms).
[15:08:28.424] INFO: Test took 3984ms.
[15:08:28.463] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:29.175] INFO: Expecting 41600 events.
[15:08:32.453] INFO: 41600 events read in total (2751ms).
[15:08:32.454] INFO: Test took 3973ms.
[15:08:32.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:33.205] INFO: Expecting 41600 events.
[15:08:36.478] INFO: 41600 events read in total (2746ms).
[15:08:36.479] INFO: Test took 3966ms.
[15:08:36.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:37.229] INFO: Expecting 41600 events.
[15:08:40.507] INFO: 41600 events read in total (2752ms).
[15:08:40.508] INFO: Test took 3969ms.
[15:08:40.546] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:41.260] INFO: Expecting 41600 events.
[15:08:44.549] INFO: 41600 events read in total (2762ms).
[15:08:44.550] INFO: Test took 3984ms.
[15:08:44.589] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:45.301] INFO: Expecting 41600 events.
[15:08:48.572] INFO: 41600 events read in total (2744ms).
[15:08:48.573] INFO: Test took 3965ms.
[15:08:48.611] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:49.328] INFO: Expecting 41600 events.
[15:08:52.607] INFO: 41600 events read in total (2753ms).
[15:08:52.608] INFO: Test took 3977ms.
[15:08:52.646] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:53.363] INFO: Expecting 41600 events.
[15:08:56.620] INFO: 41600 events read in total (2730ms).
[15:08:56.621] INFO: Test took 3956ms.
[15:08:56.659] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:57.373] INFO: Expecting 41600 events.
[15:09:00.669] INFO: 41600 events read in total (2769ms).
[15:09:00.670] INFO: Test took 3990ms.
[15:09:00.708] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:01.426] INFO: Expecting 41600 events.
[15:09:04.714] INFO: 41600 events read in total (2761ms).
[15:09:04.715] INFO: Test took 3986ms.
[15:09:04.753] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:05.472] INFO: Expecting 41600 events.
[15:09:08.765] INFO: 41600 events read in total (2766ms).
[15:09:08.766] INFO: Test took 3993ms.
[15:09:08.805] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:09.517] INFO: Expecting 41600 events.
[15:09:12.789] INFO: 41600 events read in total (2745ms).
[15:09:12.790] INFO: Test took 3966ms.
[15:09:12.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:13.546] INFO: Expecting 41600 events.
[15:09:16.810] INFO: 41600 events read in total (2737ms).
[15:09:16.811] INFO: Test took 3963ms.
[15:09:16.850] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:17.567] INFO: Expecting 41600 events.
[15:09:20.842] INFO: 41600 events read in total (2748ms).
[15:09:20.843] INFO: Test took 3972ms.
[15:09:20.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:21.600] INFO: Expecting 41600 events.
[15:09:24.893] INFO: 41600 events read in total (2766ms).
[15:09:24.894] INFO: Test took 3991ms.
[15:09:24.933] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:25.645] INFO: Expecting 41600 events.
[15:09:28.930] INFO: 41600 events read in total (2758ms).
[15:09:28.931] INFO: Test took 3976ms.
[15:09:28.970] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:29.688] INFO: Expecting 41600 events.
[15:09:32.971] INFO: 41600 events read in total (2756ms).
[15:09:32.972] INFO: Test took 3982ms.
[15:09:33.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:33.726] INFO: Expecting 41600 events.
[15:09:36.967] INFO: 41600 events read in total (2714ms).
[15:09:36.968] INFO: Test took 3935ms.
[15:09:37.006] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:37.724] INFO: Expecting 41600 events.
[15:09:40.813] INFO: 41600 events read in total (2562ms).
[15:09:40.814] INFO: Test took 3788ms.
[15:09:40.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:41.201] INFO: enter test to run
[15:09:47.578] INFO: test: HighRate no parameter change
[15:09:47.578] INFO: running: highrate
[15:09:47.579] INFO: ----------------------------------------------------------------------
[15:09:47.579] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:09:47.579] INFO: ----------------------------------------------------------------------
[15:09:48.192] INFO: Expecting 208000 events.
[15:10:00.333] INFO: 208000 events read in total (11615ms).
[15:10:00.337] INFO: Test took 12752ms.
[15:10:00.507] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:10:00.767] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 81 0 1 0 1 0
[15:10:00.767] INFO: number of red-efficiency pixels: 107 66 90 143 169 156 178 112 113 175 732 161 132 82 32 32
[15:10:00.767] INFO: number of X-ray hits detected: 80161 52356 73957 118584 128725 127358 129000 85398 89412 126575 120026 103885 107939 61770 24643 27129
[15:10:00.767] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:10:00.767] INFO: number of Vcal hits detected: 207891 207933 207909 207854 207828 207833 207820 207886 207884 207819 203005 207838 207819 207917 207918 207968
[15:10:00.767] 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.6 99.9 99.9 100.0 100.0 100.0
[15:10:00.767] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 97.6 99.9 99.9 100.0 100.0 100.0
[15:10:00.767] INFO: X-ray hit rate [MHz/cm2]: 23.5 15.3 21.7 34.8 37.7 37.3 37.8 25.0 26.2 37.1 35.2 30.4 31.6 18.1 7.2 8.0
[15:10:00.767] INFO: PixTestHighRate::doXPixelAlive() done
[15:10:00.813] INFO: PixTest:: pg_setup set to default.
[15:10:00.825] INFO: enter test to run
[15:10:19.386] INFO: test: HighRate no parameter change
[15:10:19.386] INFO: running: highrate
[15:10:19.387] INFO: ----------------------------------------------------------------------
[15:10:19.387] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:10:19.387] INFO: ----------------------------------------------------------------------
[15:10:19.003] INFO: Expecting 208000 events.
[15:10:33.378] INFO: 208000 events read in total (12849ms).
[15:10:33.386] INFO: Test took 13991ms.
[15:10:33.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:10:34.060] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 81 0 1 0 1 0
[15:10:34.060] INFO: number of red-efficiency pixels: 341 158 312 534 536 571 593 434 388 739 1420 489 430 287 86 64
[15:10:34.060] INFO: number of X-ray hits detected: 172415 112684 158594 254763 273966 273093 275493 185449 192620 271737 257218 222768 232092 132438 53277 58154
[15:10:34.060] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:10:34.060] INFO: number of Vcal hits detected: 207627 207838 207662 207407 207409 207348 207338 207518 207577 207156 201565 207467 207486 207688 207864 207936
[15:10:34.060] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.9 99.7 99.7 99.7 99.7 99.8 99.8 99.6 98.9 99.8 99.8 99.9 100.0 100.0
[15:10:34.061] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.8 99.6 96.9 99.7 99.8 99.9 99.9 100.0
[15:10:34.061] INFO: X-ray hit rate [MHz/cm2]: 50.5 33.0 46.5 74.7 80.3 80.0 80.7 54.4 56.5 79.6 75.4 65.3 68.0 38.8 15.6 17.0
[15:10:34.061] INFO: PixTestHighRate::doXPixelAlive() done
[15:10:34.108] INFO: PixTest:: pg_setup set to default.
[15:10:34.124] INFO: enter test to run
[15:10:54.473] INFO: test: HighRate no parameter change
[15:10:54.473] INFO: running: highrate
[15:10:54.474] INFO: ----------------------------------------------------------------------
[15:10:54.474] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:10:54.474] INFO: ----------------------------------------------------------------------
[15:10:55.091] INFO: Expecting 208000 events.
[15:11:11.729] INFO: 208000 events read in total (16111ms).
[15:11:11.738] INFO: Test took 17253ms.
[15:11:12.293] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:12.677] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 81 0 1 0 1 0
[15:11:12.677] INFO: number of red-efficiency pixels: 805 332 665 1214 1311 1258 1419 973 889 1731 2246 1159 934 640 104 107
[15:11:12.677] INFO: number of X-ray hits detected: 257019 169224 238545 380731 413160 407296 415469 277773 289963 406367 385676 334516 346103 198645 79897 88783
[15:11:12.677] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:11:12.677] INFO: number of Vcal hits detected: 206912 207636 207151 206435 206258 206341 206054 206633 206873 205506 199262 206489 206832 207144 207842 207891
[15:11:12.677] INFO: Vcal hit fiducial efficiency (%): 99.5 99.8 99.6 99.3 99.2 99.3 99.2 99.4 99.5 98.9 97.9 99.4 99.5 99.6 100.0 100.0
[15:11:12.677] INFO: Vcal hit overall efficiency (%): 99.5 99.8 99.6 99.2 99.2 99.2 99.1 99.3 99.5 98.8 95.8 99.3 99.4 99.6 99.9 99.9
[15:11:12.677] INFO: X-ray hit rate [MHz/cm2]: 75.3 49.6 69.9 111.6 121.1 119.4 121.8 81.4 85.0 119.1 113.0 98.0 101.4 58.2 23.4 26.0
[15:11:12.677] INFO: PixTestHighRate::doXPixelAlive() done
[15:11:12.723] INFO: PixTest:: pg_setup set to default.
[15:11:12.742] INFO: enter test to run
[15:11:35.393] INFO: test: exit no parameter change
[15:11:35.738] QUIET: Connection to board 33 closed.
[15:11:35.740] INFO: pXar: this is the end, my friend