[16:44:05.419] INFO: *** Welcome to pxar ***
[16:44:05.419] INFO: *** Today: 2016/06/22
[16:44:05.442] INFO: *** Version: v1.9.0-814-g7497
[16:44:05.442] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//dacParameters35_C15.dat
[16:44:05.459] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:44:05.459] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//defaultMaskFile.dat
[16:44:05.459] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C15.dat
[16:44:05.571] INFO: clk: 4
[16:44:05.571] INFO: ctr: 4
[16:44:05.571] INFO: sda: 19
[16:44:05.571] INFO: tin: 9
[16:44:05.571] INFO: level: 15
[16:44:05.571] INFO: triggerdelay: 0
[16:44:05.571] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:44:05.571] INFO: Log level: INFO
[16:44:05.586] QUIET: Connection to board DTB_WREK4U opened.
[16:44:05.590] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[16:44:05.592] INFO: RPC call hashes of host and DTB match: 398089610
[16:44:07.131] INFO: DUT info:
[16:44:07.131] INFO: The DUT currently contains the following objects:
[16:44:07.131] INFO: 2 TBM Cores tbm08c (2 ON)
[16:44:07.131] INFO: TBM Core alpha (0): 7 registers set
[16:44:07.131] INFO: TBM Core beta (1): 7 registers set
[16:44:07.131] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:44:07.131] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.131] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:44:07.535] INFO: enter 'restricted' command line mode
[16:44:07.535] INFO: enter test to run
[16:44:09.743] INFO: test: PixelAlive no parameter change
[16:44:09.743] INFO: running: pixelalive
[16:44:09.752] INFO: ----------------------------------------------------------------------
[16:44:09.752] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:44:09.753] INFO: ----------------------------------------------------------------------
[16:44:10.077] INFO: Expecting 41600 events.
[16:44:14.377] INFO: 41600 events read in total (3582ms).
[16:44:14.532] INFO: Test took 4777ms.
[16:44:14.547] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:44:14.811] INFO: PixTestAlive::aliveTest() done
[16:44:14.811] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[16:44:14.839] INFO: enter test to run
[16:44:48.030] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:44:48.030] INFO: running: highrate
[16:44:48.030] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:44:48.325] INFO: ----------------------------------------------------------------------
[16:44:48.325] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:44:48.325] INFO: ----------------------------------------------------------------------
[16:44:48.325] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:44:48.326] INFO: edge/corner pixel THR is adjusted
[16:44:48.326] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:44:49.284] INFO: Collecting data for 5 seconds...
[16:44:54.304] INFO: Done with hot pixel readout
[16:45:06.444] INFO: PixTest:: pg_setup set to default.
[16:45:06.445] INFO: 29 hot pixels found in step 0
[16:45:07.460] INFO: Collecting data for 5 seconds...
[16:45:12.477] INFO: Done with hot pixel readout
[16:45:24.574] INFO: PixTest:: pg_setup set to default.
[16:45:24.575] INFO: 20 hot pixels found in step 1
[16:45:25.565] INFO: Collecting data for 5 seconds...
[16:45:30.585] INFO: Done with hot pixel readout
[16:45:42.525] INFO: PixTest:: pg_setup set to default.
[16:45:42.525] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:45:42.526] INFO: 32 hot pixels found in step 2
[16:45:43.516] INFO: Collecting data for 5 seconds...
[16:45:48.540] INFO: Done with hot pixel readout
[16:46:00.739] INFO: PixTest:: pg_setup set to default.
[16:46:00.739] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:46:00.740] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:46:00.740] INFO: 31 hot pixels found in step 3
[16:46:01.730] INFO: Collecting data for 5 seconds...
[16:46:06.749] INFO: Done with hot pixel readout
[16:46:18.821] INFO: PixTest:: pg_setup set to default.
[16:46:18.821] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:46:18.821] INFO: 21 hot pixels found in step 4
[16:46:19.812] INFO: Collecting data for 5 seconds...
[16:46:24.829] INFO: Done with hot pixel readout
[16:46:36.755] INFO: PixTest:: pg_setup set to default.
[16:46:36.755] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:46:36.755] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:46:36.756] INFO: 19 hot pixels found in step 5
[16:46:37.745] INFO: Collecting data for 5 seconds...
[16:46:42.761] INFO: Done with hot pixel readout
[16:46:54.667] INFO: PixTest:: pg_setup set to default.
[16:46:54.667] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:46:54.667] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:46:54.667] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:46:54.667] INFO: 19 hot pixels found in step 6
[16:46:55.656] INFO: Collecting data for 5 seconds...
[16:47:00.673] INFO: Done with hot pixel readout
[16:47:12.599] INFO: PixTest:: pg_setup set to default.
[16:47:12.599] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:47:12.599] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:47:12.599] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:47:12.599] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:47:12.600] INFO: 24 hot pixels found in step 7
[16:47:13.590] INFO: Collecting data for 5 seconds...
[16:47:18.606] INFO: Done with hot pixel readout
[16:47:30.546] INFO: PixTest:: pg_setup set to default.
[16:47:30.546] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:47:30.546] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:47:30.546] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:47:30.547] INFO: 18 hot pixels found in step 8
[16:47:31.536] INFO: Collecting data for 5 seconds...
[16:47:36.554] INFO: Done with hot pixel readout
[16:47:48.500] INFO: PixTest:: pg_setup set to default.
[16:47:48.500] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:47:48.500] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:47:48.500] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:47:48.500] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:47:48.501] INFO: 16 hot pixels found in step 9
[16:47:49.490] INFO: Collecting data for 5 seconds...
[16:47:54.506] INFO: Done with hot pixel readout
[16:48:06.441] INFO: PixTest:: pg_setup set to default.
[16:48:06.441] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:48:06.441] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:48:06.441] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:48:06.442] INFO: 15 hot pixels found in step 10
[16:48:07.431] INFO: Collecting data for 5 seconds...
[16:48:12.447] INFO: Done with hot pixel readout
[16:48:24.380] INFO: PixTest:: pg_setup set to default.
[16:48:24.380] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:48:24.380] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:48:24.380] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:48:24.381] INFO: 16 hot pixels found in step 11
[16:48:25.371] INFO: Collecting data for 5 seconds...
[16:48:30.388] INFO: Done with hot pixel readout
[16:48:42.287] INFO: PixTest:: pg_setup set to default.
[16:48:42.287] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:48:42.287] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:48:42.287] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:48:42.287] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:48:42.287] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:48:42.288] INFO: 14 hot pixels found in step 12
[16:48:43.278] INFO: Collecting data for 5 seconds...
[16:48:48.296] INFO: Done with hot pixel readout
[16:49:00.211] INFO: PixTest:: pg_setup set to default.
[16:49:00.211] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:49:00.211] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:49:00.211] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:49:00.211] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:49:00.211] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:49:00.211] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:49:00.212] INFO: 15 hot pixels found in step 13
[16:49:01.202] INFO: Collecting data for 5 seconds...
[16:49:06.219] INFO: Done with hot pixel readout
[16:49:18.115] INFO: PixTest:: pg_setup set to default.
[16:49:18.115] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:49:18.115] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:49:18.115] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:49:18.115] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:49:18.115] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:49:18.115] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[16:49:18.116] INFO: 18 hot pixels found in step 14
[16:49:18.150] INFO: 18 hot pixels could not be trimmed and have been masked.
[16:49:18.153] INFO: PixTest::trimHotPixels() done
[16:49:18.158] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C0.dat
[16:49:18.164] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C1.dat
[16:49:18.170] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C2.dat
[16:49:18.176] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C3.dat
[16:49:18.181] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C4.dat
[16:49:18.186] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C5.dat
[16:49:18.192] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C6.dat
[16:49:18.197] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C7.dat
[16:49:18.202] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C8.dat
[16:49:18.208] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C9.dat
[16:49:18.213] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C10.dat
[16:49:18.218] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C11.dat
[16:49:18.224] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C12.dat
[16:49:18.229] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C13.dat
[16:49:18.234] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C14.dat
[16:49:18.240] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C15.dat
[16:49:18.245] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//defaultMaskFile.dat
[16:49:18.255] INFO: enter test to run
[16:49:37.732] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:49:37.733] INFO: running: highrate
[16:49:37.737] INFO: ----------------------------------------------------------------------
[16:49:37.737] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:49:37.737] INFO: ----------------------------------------------------------------------
[16:49:37.737] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:49:37.737] INFO: edge/corner pixel THR is adjusted
[16:49:37.737] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:49:38.695] INFO: Collecting data for 1 seconds...
[16:49:39.699] INFO: Done with hot pixel readout
[16:49:43.755] INFO: PixTest:: pg_setup set to default.
[16:49:43.756] INFO: 0 hot pixels found in step 0
[16:49:43.761] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:49:43.851] INFO: PixTest::trimHotPixels() done
[16:49:43.851] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C0.dat
[16:49:43.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C1.dat
[16:49:43.866] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C2.dat
[16:49:43.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C3.dat
[16:49:43.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C4.dat
[16:49:43.881] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C5.dat
[16:49:43.887] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C6.dat
[16:49:43.892] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C7.dat
[16:49:43.897] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C8.dat
[16:49:43.902] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C9.dat
[16:49:43.907] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C10.dat
[16:49:43.912] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C11.dat
[16:49:43.918] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C12.dat
[16:49:43.923] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C13.dat
[16:49:43.928] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C14.dat
[16:49:43.933] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//trimParameters35_C15.dat
[16:49:43.938] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-09_FPIXTest-17C-FNAL-160620-1313_2016-06-20_13h13m_1466446438/000_FPIXTest_p17//defaultMaskFile.dat
[16:49:43.950] INFO: enter test to run
[16:50:15.116] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:50:15.116] INFO: running: xray
[16:50:15.118] INFO: ----------------------------------------------------------------------
[16:50:15.118] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:50:15.118] INFO: ----------------------------------------------------------------------
[16:50:16.081] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:50:27.328] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:50:56.579] INFO: Resuming triggers.
[16:51:07.821] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[16:51:37.066] INFO: Resuming triggers.
[16:51:48.313] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:52:17.728] INFO: Resuming triggers.
[16:52:28.970] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:52:58.302] INFO: Resuming triggers.
[16:53:09.552] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[16:53:38.953] INFO: Resuming triggers.
[16:53:50.200] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[16:54:19.593] INFO: Resuming triggers.
[16:54:30.839] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[16:55:00.762] INFO: Resuming triggers.
[16:55:12.007] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[16:55:41.582] INFO: Resuming triggers.
[16:55:51.961] INFO: data taking finished, elapsed time: 100 seconds.
[16:56:19.419] INFO: PixTest:: pg_setup set to default.
[16:56:19.423] INFO: PixTestXray::doPhRun() done
[16:56:19.677] INFO: enter test to run
[16:58:17.585] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:58:17.585] INFO: running: xray
[16:58:17.586] INFO: ----------------------------------------------------------------------
[16:58:17.586] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:58:17.586] INFO: ----------------------------------------------------------------------
[16:58:18.565] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:58:25.076] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:58:55.161] INFO: Resuming triggers.
[16:59:01.675] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[16:59:31.726] INFO: Resuming triggers.
[16:59:38.238] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[17:00:08.312] INFO: Resuming triggers.
[17:00:14.820] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[17:00:44.932] INFO: Resuming triggers.
[17:00:51.447] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[17:01:21.491] INFO: Resuming triggers.
[17:01:28.006] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[17:01:58.073] INFO: Resuming triggers.
[17:02:04.584] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[17:02:34.751] INFO: Resuming triggers.
[17:02:41.266] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[17:03:11.310] INFO: Resuming triggers.
[17:03:17.826] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[17:03:48.029] INFO: Resuming triggers.
[17:03:54.541] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[17:04:24.618] INFO: Resuming triggers.
[17:04:31.134] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[17:05:01.274] INFO: Resuming triggers.
[17:05:07.787] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[17:05:37.909] INFO: Resuming triggers.
[17:05:44.428] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[17:06:15.250] INFO: Resuming triggers.
[17:06:21.770] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[17:06:52.386] INFO: Resuming triggers.
[17:06:58.900] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[17:07:29.611] INFO: Resuming triggers.
[17:07:32.238] INFO: data taking finished, elapsed time: 100 seconds.
[17:07:44.987] INFO: PixTest:: pg_setup set to default.
[17:07:44.990] INFO: PixTestXray::doPhRun() done
[17:07:45.144] INFO: enter test to run
[17:08:39.085] INFO: test: HighRate no parameter change
[17:08:39.085] INFO: running: highrate
[17:08:39.129] INFO: ----------------------------------------------------------------------
[17:08:39.129] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:08:39.129] INFO: ----------------------------------------------------------------------
[17:08:39.301] INFO: Expecting 768 events.
[17:08:40.441] INFO: 768 events read in total (424ms).
[17:08:40.442] INFO: Test took 1275ms.
[17:08:41.244] INFO: Expecting 41600 events.
[17:08:44.325] INFO: 41600 events read in total (2554ms).
[17:08:44.326] INFO: Test took 3878ms.
[17:08:44.361] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:45.084] INFO: Expecting 41600 events.
[17:08:48.404] INFO: 41600 events read in total (2793ms).
[17:08:48.405] INFO: Test took 4027ms.
[17:08:48.442] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:49.156] INFO: Expecting 41600 events.
[17:08:52.447] INFO: 41600 events read in total (2764ms).
[17:08:52.449] INFO: Test took 3989ms.
[17:08:52.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:53.194] INFO: Expecting 41600 events.
[17:08:56.583] INFO: 41600 events read in total (2862ms).
[17:08:56.584] INFO: Test took 4078ms.
[17:08:56.622] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:57.340] INFO: Expecting 41600 events.
[17:09:00.617] INFO: 41600 events read in total (2751ms).
[17:09:00.618] INFO: Test took 3978ms.
[17:09:00.655] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:01.373] INFO: Expecting 41600 events.
[17:09:04.655] INFO: 41600 events read in total (2755ms).
[17:09:04.656] INFO: Test took 3983ms.
[17:09:04.693] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:05.407] INFO: Expecting 41600 events.
[17:09:08.705] INFO: 41600 events read in total (2771ms).
[17:09:08.706] INFO: Test took 3995ms.
[17:09:08.744] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:09.458] INFO: Expecting 41600 events.
[17:09:12.803] INFO: 41600 events read in total (2818ms).
[17:09:12.804] INFO: Test took 4042ms.
[17:09:12.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:13.554] INFO: Expecting 41600 events.
[17:09:16.827] INFO: 41600 events read in total (2746ms).
[17:09:16.828] INFO: Test took 3969ms.
[17:09:16.865] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:17.582] INFO: Expecting 41600 events.
[17:09:21.040] INFO: 41600 events read in total (2931ms).
[17:09:21.040] INFO: Test took 4157ms.
[17:09:21.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:21.797] INFO: Expecting 41600 events.
[17:09:25.141] INFO: 41600 events read in total (2817ms).
[17:09:25.142] INFO: Test took 4046ms.
[17:09:25.179] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:25.898] INFO: Expecting 41600 events.
[17:09:29.148] INFO: 41600 events read in total (2723ms).
[17:09:29.149] INFO: Test took 3951ms.
[17:09:29.185] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:29.905] INFO: Expecting 41600 events.
[17:09:33.160] INFO: 41600 events read in total (2728ms).
[17:09:33.161] INFO: Test took 3956ms.
[17:09:33.197] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:33.918] INFO: Expecting 41600 events.
[17:09:37.177] INFO: 41600 events read in total (2732ms).
[17:09:37.178] INFO: Test took 3962ms.
[17:09:37.215] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:37.935] INFO: Expecting 41600 events.
[17:09:41.194] INFO: 41600 events read in total (2732ms).
[17:09:41.195] INFO: Test took 3962ms.
[17:09:41.231] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:41.950] INFO: Expecting 41600 events.
[17:09:45.179] INFO: 41600 events read in total (2702ms).
[17:09:45.180] INFO: Test took 3930ms.
[17:09:45.216] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:45.933] INFO: Expecting 41600 events.
[17:09:49.192] INFO: 41600 events read in total (2732ms).
[17:09:49.193] INFO: Test took 3959ms.
[17:09:49.228] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:49.953] INFO: Expecting 41600 events.
[17:09:53.223] INFO: 41600 events read in total (2744ms).
[17:09:53.224] INFO: Test took 3976ms.
[17:09:53.260] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:53.982] INFO: Expecting 41600 events.
[17:09:57.216] INFO: 41600 events read in total (2707ms).
[17:09:57.217] INFO: Test took 3938ms.
[17:09:57.254] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:57.975] INFO: Expecting 41600 events.
[17:10:01.007] INFO: 41600 events read in total (2505ms).
[17:10:01.008] INFO: Test took 3735ms.
[17:10:01.050] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:10:01.405] INFO: enter test to run
[17:10:07.428] INFO: test: HighRate no parameter change
[17:10:07.428] INFO: running: highrate
[17:10:07.429] INFO: ----------------------------------------------------------------------
[17:10:07.429] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:10:07.429] INFO: ----------------------------------------------------------------------
[17:10:08.045] INFO: Expecting 208000 events.
[17:10:19.976] INFO: 208000 events read in total (11404ms).
[17:10:19.979] INFO: Test took 12543ms.
[17:10:20.133] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:10:20.389] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[17:10:20.389] INFO: number of red-efficiency pixels: 81 41 78 135 138 182 160 97 91 128 125 131 98 68 22 33
[17:10:20.389] INFO: number of X-ray hits detected: 69775 43382 73263 111437 116827 127464 128650 87195 83233 104891 109343 87484 91521 52999 23838 27917
[17:10:20.389] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:10:20.389] INFO: number of Vcal hits detected: 207918 207957 207922 207862 207860 207811 207835 207899 207907 207868 207873 207867 207900 207880 207977 207967
[17:10:20.389] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[17:10:20.389] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 99.9 100.0 100.0
[17:10:20.389] INFO: X-ray hit rate [MHz/cm2]: 20.5 12.7 21.5 32.7 34.2 37.4 37.7 25.6 24.4 30.7 32.0 25.6 26.8 15.5 7.0 8.2
[17:10:20.389] INFO: PixTestHighRate::doXPixelAlive() done
[17:10:20.438] INFO: PixTest:: pg_setup set to default.
[17:10:20.452] INFO: enter test to run
[17:10:52.324] INFO: test: HighRate no parameter change
[17:10:52.324] INFO: running: highrate
[17:10:52.325] INFO: ----------------------------------------------------------------------
[17:10:52.325] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:10:52.325] INFO: ----------------------------------------------------------------------
[17:10:52.940] INFO: Expecting 208000 events.
[17:11:06.780] INFO: 208000 events read in total (13313ms).
[17:11:06.785] INFO: Test took 14450ms.
[17:11:07.098] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:11:07.403] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[17:11:07.403] INFO: number of red-efficiency pixels: 250 147 305 495 412 654 702 378 317 366 358 331 330 196 70 67
[17:11:07.403] INFO: number of X-ray hits detected: 140475 89111 148929 225937 237142 259265 260077 176984 168463 215054 222240 178300 186368 107656 48977 57089
[17:11:07.403] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:11:07.403] INFO: number of Vcal hits detected: 207724 207847 207657 207452 207557 207261 207217 207586 207668 207614 207626 207648 207650 207748 207928 207933
[17:11:07.403] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.6 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[17:11:07.403] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.8 99.6 99.6 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[17:11:07.403] INFO: X-ray hit rate [MHz/cm2]: 41.2 26.1 43.7 66.2 69.5 76.0 76.2 51.9 49.4 63.0 65.1 52.3 54.6 31.6 14.4 16.7
[17:11:07.403] INFO: PixTestHighRate::doXPixelAlive() done
[17:11:07.454] INFO: PixTest:: pg_setup set to default.
[17:11:07.474] INFO: enter test to run
[17:11:20.796] INFO: test: HighRate no parameter change
[17:11:20.796] INFO: running: highrate
[17:11:20.797] INFO: ----------------------------------------------------------------------
[17:11:20.797] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:11:20.797] INFO: ----------------------------------------------------------------------
[17:11:21.414] INFO: Expecting 208000 events.
[17:11:37.155] INFO: 208000 events read in total (15214ms).
[17:11:37.163] INFO: Test took 16357ms.
[17:11:37.624] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:11:37.981] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[17:11:37.981] INFO: number of red-efficiency pixels: 489 257 717 1127 888 1475 1404 833 661 739 803 751 766 384 96 113
[17:11:37.981] INFO: number of X-ray hits detected: 209566 132758 221916 336149 353540 383548 386889 263096 252561 318783 328922 265129 277560 160260 72389 85600
[17:11:37.981] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:11:37.981] INFO: number of Vcal hits detected: 207397 207719 207033 206514 206901 205932 206047 206949 207237 207149 207019 207095 207117 207521 207897 207886
[17:11:37.981] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.4 99.5 99.1 99.2 99.5 99.7 99.6 99.6 99.6 99.6 99.8 100.0 100.0
[17:11:37.981] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.5 99.3 99.5 99.0 99.1 99.5 99.6 99.6 99.5 99.6 99.6 99.8 100.0 99.9
[17:11:37.981] INFO: X-ray hit rate [MHz/cm2]: 61.4 38.9 65.0 98.5 103.6 112.4 113.4 77.1 74.0 93.4 96.4 77.7 81.4 47.0 21.2 25.1
[17:11:37.981] INFO: PixTestHighRate::doXPixelAlive() done
[17:11:38.029] INFO: PixTest:: pg_setup set to default.
[17:11:38.046] INFO: enter test to run
[17:11:44.291] INFO: test: exit no parameter change
[17:11:44.603] QUIET: Connection to board 32 closed.
[17:11:44.618] INFO: pXar: this is the end, my friend