[15:38:10.184] INFO: *** Welcome to pxar ***
[15:38:10.185] INFO: *** Today: 2016/05/20
[15:38:10.219] INFO: *** Version: v1.9.0-796-gef167-dirty
[15:38:10.219] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//dacParameters35_C15.dat
[15:38:10.241] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:38:10.241] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//defaultMaskFile.dat
[15:38:10.248] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C15.dat
[15:38:10.331] INFO: clk: 4
[15:38:10.331] INFO: ctr: 4
[15:38:10.331] INFO: sda: 19
[15:38:10.331] INFO: tin: 9
[15:38:10.331] INFO: level: 15
[15:38:10.331] INFO: triggerdelay: 0
[15:38:10.331] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[15:38:10.331] INFO: Log level: INFO
[15:38:10.349] QUIET: Connection to board DTB_WREK4U opened.
[15:38:10.353] 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:
------------------------------------------------------
[15:38:10.356] INFO: RPC call hashes of host and DTB match: 398089610
[15:38:11.895] INFO: DUT info:
[15:38:11.895] INFO: The DUT currently contains the following objects:
[15:38:11.895] INFO: 2 TBM Cores tbm08c (2 ON)
[15:38:11.895] INFO: TBM Core alpha (0): 7 registers set
[15:38:11.895] INFO: TBM Core beta (1): 7 registers set
[15:38:11.895] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:38:11.895] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:11.895] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:38:12.299] INFO: enter 'restricted' command line mode
[15:38:12.299] INFO: enter test to run
[15:38:13.778] INFO: test: PixelAlive no parameter change
[15:38:13.778] INFO: running: pixelalive
[15:38:13.787] INFO: ----------------------------------------------------------------------
[15:38:13.787] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:38:13.787] INFO: ----------------------------------------------------------------------
[15:38:14.108] INFO: Expecting 41600 events.
[15:38:18.220] INFO: 41600 events read in total (3394ms).
[15:38:18.390] INFO: Test took 4600ms.
[15:38:18.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:18.662] INFO: PixTestAlive::aliveTest() done
[15:38:18.663] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 18 0 0 0 0 3 0 0 1 0
[15:38:18.695] INFO: enter test to run
[15:38:45.930] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:38:45.930] INFO: running: highrate
[15:38:45.930] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:38:46.147] INFO: ----------------------------------------------------------------------
[15:38:46.147] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:38:46.147] INFO: ----------------------------------------------------------------------
[15:38:46.147] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:38:46.147] INFO: edge/corner pixel THR is adjusted
[15:38:46.147] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:38:47.105] INFO: Collecting data for 5 seconds...
[15:38:52.123] INFO: Done with hot pixel readout
[15:39:03.670] INFO: PixTest:: pg_setup set to default.
[15:39:03.670] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:03.671] INFO: 37 hot pixels found in step 0
[15:39:04.691] INFO: Collecting data for 5 seconds...
[15:39:09.708] INFO: Done with hot pixel readout
[15:39:21.433] INFO: PixTest:: pg_setup set to default.
[15:39:21.433] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:21.433] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:21.433] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:21.433] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:21.434] INFO: 44 hot pixels found in step 1
[15:39:22.424] INFO: Collecting data for 5 seconds...
[15:39:27.439] INFO: Done with hot pixel readout
[15:39:39.105] INFO: PixTest:: pg_setup set to default.
[15:39:39.105] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:39.106] INFO: 40 hot pixels found in step 2
[15:39:40.096] INFO: Collecting data for 5 seconds...
[15:39:45.112] INFO: Done with hot pixel readout
[15:39:55.866] INFO: PixTest:: pg_setup set to default.
[15:39:55.866] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:55.866] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:39:55.867] INFO: 40 hot pixels found in step 3
[15:39:56.857] INFO: Collecting data for 5 seconds...
[15:40:01.873] INFO: Done with hot pixel readout
[15:40:13.538] INFO: PixTest:: pg_setup set to default.
[15:40:13.539] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:40:13.539] INFO: 31 hot pixels found in step 4
[15:40:14.529] INFO: Collecting data for 5 seconds...
[15:40:19.547] INFO: Done with hot pixel readout
[15:40:31.361] INFO: PixTest:: pg_setup set to default.
[15:40:31.361] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:40:31.361] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:40:31.362] INFO: 29 hot pixels found in step 5
[15:40:32.353] INFO: Collecting data for 5 seconds...
[15:40:37.370] INFO: Done with hot pixel readout
[15:40:49.238] INFO: PixTest:: pg_setup set to default.
[15:40:49.238] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:40:49.238] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:40:49.239] INFO: 25 hot pixels found in step 6
[15:40:50.229] INFO: Collecting data for 5 seconds...
[15:40:55.246] INFO: Done with hot pixel readout
[15:41:07.146] INFO: PixTest:: pg_setup set to default.
[15:41:07.146] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:07.146] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:07.146] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:07.146] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:07.147] INFO: 28 hot pixels found in step 7
[15:41:08.137] INFO: Collecting data for 5 seconds...
[15:41:13.154] INFO: Done with hot pixel readout
[15:41:25.307] INFO: PixTest:: pg_setup set to default.
[15:41:25.307] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:25.307] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:25.308] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:25.308] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:25.308] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:25.308] INFO: 26 hot pixels found in step 8
[15:41:26.298] INFO: Collecting data for 5 seconds...
[15:41:31.315] INFO: Done with hot pixel readout
[15:41:43.420] INFO: PixTest:: pg_setup set to default.
[15:41:43.420] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:43.420] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:43.420] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:43.420] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:43.420] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:41:43.421] INFO: 27 hot pixels found in step 9
[15:41:44.411] INFO: Collecting data for 5 seconds...
[15:41:49.428] INFO: Done with hot pixel readout
[15:42:01.560] INFO: PixTest:: pg_setup set to default.
[15:42:01.560] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:01.560] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:01.560] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:01.560] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:01.561] INFO: 18 hot pixels found in step 10
[15:42:02.550] INFO: Collecting data for 5 seconds...
[15:42:07.568] INFO: Done with hot pixel readout
[15:42:19.480] INFO: PixTest:: pg_setup set to default.
[15:42:19.480] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:19.480] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:19.480] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:19.480] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:19.480] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:19.481] INFO: 18 hot pixels found in step 11
[15:42:20.472] INFO: Collecting data for 5 seconds...
[15:42:25.490] INFO: Done with hot pixel readout
[15:42:37.434] INFO: PixTest:: pg_setup set to default.
[15:42:37.434] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:37.434] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:37.434] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:37.435] INFO: 16 hot pixels found in step 12
[15:42:38.426] INFO: Collecting data for 5 seconds...
[15:42:43.443] INFO: Done with hot pixel readout
[15:42:55.248] INFO: PixTest:: pg_setup set to default.
[15:42:55.248] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:55.248] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:55.248] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:55.249] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:55.249] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:42:55.249] INFO: 23 hot pixels found in step 13
[15:42:56.239] INFO: Collecting data for 5 seconds...
[15:43:01.258] INFO: Done with hot pixel readout
[15:43:13.274] INFO: PixTest:: pg_setup set to default.
[15:43:13.274] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:43:13.274] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:43:13.274] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:43:13.274] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:43:13.274] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:43:13.274] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:43:13.275] INFO: 18 hot pixels found in step 14
[15:43:13.310] INFO: 18 hot pixels could not be trimmed and have been masked.
[15:43:13.314] INFO: PixTest::trimHotPixels() done
[15:43:13.314] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C0.dat
[15:43:13.319] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C1.dat
[15:43:13.325] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C2.dat
[15:43:13.331] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C3.dat
[15:43:13.337] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C4.dat
[15:43:13.343] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C5.dat
[15:43:13.349] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C6.dat
[15:43:13.354] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C7.dat
[15:43:13.360] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C8.dat
[15:43:13.365] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C9.dat
[15:43:13.371] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C10.dat
[15:43:13.376] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C11.dat
[15:43:13.382] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C12.dat
[15:43:13.387] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C13.dat
[15:43:13.393] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C14.dat
[15:43:13.399] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C15.dat
[15:43:13.404] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//defaultMaskFile.dat
[15:43:13.415] INFO: enter test to run
[15:43:52.663] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:43:52.663] INFO: running: highrate
[15:43:52.668] INFO: ----------------------------------------------------------------------
[15:43:52.668] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:43:52.668] INFO: ----------------------------------------------------------------------
[15:43:52.668] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:43:52.668] INFO: edge/corner pixel THR is adjusted
[15:43:52.668] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:43:53.626] INFO: Collecting data for 1 seconds...
[15:43:54.630] INFO: Done with hot pixel readout
[15:43:58.740] INFO: PixTest:: pg_setup set to default.
[15:43:58.740] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:43:58.741] INFO: 1 hot pixels found in step 0
[15:43:58.746] INFO: 1 hot pixels could not be trimmed and have been masked.
[15:43:58.834] INFO: PixTest::trimHotPixels() done
[15:43:58.834] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C0.dat
[15:43:58.847] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C1.dat
[15:43:58.854] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C2.dat
[15:43:58.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C3.dat
[15:43:58.865] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C4.dat
[15:43:58.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C5.dat
[15:43:58.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C6.dat
[15:43:58.882] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C7.dat
[15:43:58.887] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C8.dat
[15:43:58.893] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C9.dat
[15:43:58.899] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C10.dat
[15:43:58.904] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C11.dat
[15:43:58.909] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C12.dat
[15:43:58.915] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C13.dat
[15:43:58.920] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C14.dat
[15:43:58.926] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//trimParameters35_C15.dat
[15:43:58.931] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-3-48_FPIXTest-17C-FNAL-160517-1426_2016-05-17_14h26m_1463513180/000_FPIXTest_p17//defaultMaskFile.dat
[15:43:58.941] INFO: enter test to run
[15:44:14.487] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:44:14.487] INFO: running: xray
[15:44:14.489] INFO: ----------------------------------------------------------------------
[15:44:14.489] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:44:14.489] INFO: ----------------------------------------------------------------------
[15:44:15.452] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:44:26.552] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:44:52.640] INFO: Resuming triggers.
[15:45:03.740] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:45:32.488] INFO: Resuming triggers.
[15:45:43.583] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:46:12.381] INFO: Resuming triggers.
[15:46:23.475] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:46:51.452] INFO: Resuming triggers.
[15:47:02.539] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:47:30.761] INFO: Resuming triggers.
[15:47:41.845] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[15:48:09.549] INFO: Resuming triggers.
[15:48:20.630] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[15:48:49.275] INFO: Resuming triggers.
[15:49:00.354] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[15:49:29.093] INFO: Resuming triggers.
[15:49:40.174] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[15:50:08.898] INFO: Resuming triggers.
[15:50:09.431] INFO: data taking finished, elapsed time: 100 seconds.
[15:50:11.209] INFO: PixTest:: pg_setup set to default.
[15:50:11.212] INFO: PixTestXray::doPhRun() done
[15:50:11.351] INFO: enter test to run
[15:50:36.484] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:50:36.485] INFO: running: xray
[15:50:36.486] INFO: ----------------------------------------------------------------------
[15:50:36.486] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:50:36.486] INFO: ----------------------------------------------------------------------
[15:50:37.465] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:50:43.860] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:51:13.891] INFO: Resuming triggers.
[15:51:20.291] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[15:51:50.344] INFO: Resuming triggers.
[15:51:56.743] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:52:26.792] INFO: Resuming triggers.
[15:52:33.197] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[15:53:03.261] INFO: Resuming triggers.
[15:53:09.666] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[15:53:39.734] INFO: Resuming triggers.
[15:53:46.140] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[15:54:16.233] INFO: Resuming triggers.
[15:54:22.638] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:54:52.903] INFO: Resuming triggers.
[15:54:59.310] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[15:55:29.364] INFO: Resuming triggers.
[15:55:35.771] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:56:05.835] INFO: Resuming triggers.
[15:56:12.235] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[15:56:42.732] INFO: Resuming triggers.
[15:56:49.131] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[15:57:19.605] INFO: Resuming triggers.
[15:57:26.005] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[15:57:57.134] INFO: Resuming triggers.
[15:58:03.534] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[15:58:34.750] INFO: Resuming triggers.
[15:58:41.145] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[15:59:12.273] INFO: Resuming triggers.
[15:59:18.669] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[15:59:48.708] INFO: Resuming triggers.
[15:59:53.030] INFO: data taking finished, elapsed time: 100 seconds.
[16:00:13.313] INFO: PixTest:: pg_setup set to default.
[16:00:13.316] INFO: PixTestXray::doPhRun() done
[16:00:13.467] INFO: enter test to run
[16:00:33.520] INFO: test: HighRate no parameter change
[16:00:33.520] INFO: running: highrate
[16:00:33.539] INFO: ----------------------------------------------------------------------
[16:00:33.539] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:00:33.539] INFO: ----------------------------------------------------------------------
[16:00:33.694] INFO: Expecting 768 events.
[16:00:34.828] INFO: 768 events read in total (418ms).
[16:00:34.828] INFO: Test took 1267ms.
[16:00:35.632] INFO: Expecting 41600 events.
[16:00:38.721] INFO: 41600 events read in total (2562ms).
[16:00:38.722] INFO: Test took 3886ms.
[16:00:38.758] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:39.480] INFO: Expecting 41600 events.
[16:00:42.700] INFO: 41600 events read in total (2693ms).
[16:00:42.701] INFO: Test took 3926ms.
[16:00:42.736] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:43.459] INFO: Expecting 41600 events.
[16:00:46.695] INFO: 41600 events read in total (2709ms).
[16:00:46.696] INFO: Test took 3941ms.
[16:00:46.732] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:47.451] INFO: Expecting 41600 events.
[16:00:50.666] INFO: 41600 events read in total (2688ms).
[16:00:50.667] INFO: Test took 3916ms.
[16:00:50.703] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:51.424] INFO: Expecting 41600 events.
[16:00:54.663] INFO: 41600 events read in total (2712ms).
[16:00:54.664] INFO: Test took 3942ms.
[16:00:54.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:55.421] INFO: Expecting 41600 events.
[16:00:58.672] INFO: 41600 events read in total (2724ms).
[16:00:58.673] INFO: Test took 3953ms.
[16:00:58.709] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:59.431] INFO: Expecting 41600 events.
[16:01:02.675] INFO: 41600 events read in total (2717ms).
[16:01:02.676] INFO: Test took 3948ms.
[16:01:02.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:03.429] INFO: Expecting 41600 events.
[16:01:06.659] INFO: 41600 events read in total (2703ms).
[16:01:06.660] INFO: Test took 3927ms.
[16:01:06.696] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:07.413] INFO: Expecting 41600 events.
[16:01:10.670] INFO: 41600 events read in total (2730ms).
[16:01:10.671] INFO: Test took 3955ms.
[16:01:10.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:11.427] INFO: Expecting 41600 events.
[16:01:14.562] INFO: 41600 events read in total (2608ms).
[16:01:14.563] INFO: Test took 3836ms.
[16:01:14.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:15.322] INFO: Expecting 41600 events.
[16:01:18.424] INFO: 41600 events read in total (2575ms).
[16:01:18.425] INFO: Test took 3806ms.
[16:01:18.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:19.183] INFO: Expecting 41600 events.
[16:01:22.418] INFO: 41600 events read in total (2708ms).
[16:01:22.419] INFO: Test took 3940ms.
[16:01:22.456] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:23.176] INFO: Expecting 41600 events.
[16:01:26.426] INFO: 41600 events read in total (2723ms).
[16:01:26.427] INFO: Test took 3952ms.
[16:01:26.463] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:27.183] INFO: Expecting 41600 events.
[16:01:30.413] INFO: 41600 events read in total (2703ms).
[16:01:30.414] INFO: Test took 3931ms.
[16:01:30.450] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:31.174] INFO: Expecting 41600 events.
[16:01:34.432] INFO: 41600 events read in total (2731ms).
[16:01:34.433] INFO: Test took 3964ms.
[16:01:34.469] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:35.190] INFO: Expecting 41600 events.
[16:01:38.424] INFO: 41600 events read in total (2707ms).
[16:01:38.425] INFO: Test took 3936ms.
[16:01:38.461] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:39.178] INFO: Expecting 41600 events.
[16:01:42.411] INFO: 41600 events read in total (2706ms).
[16:01:42.412] INFO: Test took 3931ms.
[16:01:42.448] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:43.172] INFO: Expecting 41600 events.
[16:01:46.355] INFO: 41600 events read in total (2656ms).
[16:01:46.356] INFO: Test took 3888ms.
[16:01:46.392] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:47.113] INFO: Expecting 41600 events.
[16:01:50.358] INFO: 41600 events read in total (2718ms).
[16:01:50.359] INFO: Test took 3947ms.
[16:01:50.395] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:51.116] INFO: Expecting 41600 events.
[16:01:54.241] INFO: 41600 events read in total (2599ms).
[16:01:54.241] INFO: Test took 3825ms.
[16:01:54.278] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:54.635] INFO: enter test to run
[16:02:00.368] INFO: test: HighRate no parameter change
[16:02:00.368] INFO: running: highrate
[16:02:00.369] INFO: ----------------------------------------------------------------------
[16:02:00.369] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:02:00.369] INFO: ----------------------------------------------------------------------
[16:02:00.983] INFO: Expecting 208000 events.
[16:02:12.761] INFO: 208000 events read in total (11251ms).
[16:02:12.765] INFO: Test took 12387ms.
[16:02:12.919] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:13.174] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 18 0 0 0 0 4 0 0 0 0
[16:02:13.174] INFO: number of red-efficiency pixels: 96 39 111 171 173 209 177 120 78 163 126 107 119 72 29 26
[16:02:13.174] INFO: number of X-ray hits detected: 68672 45968 74016 116710 123765 128708 135693 89778 77106 102928 101805 88595 93669 54108 24005 26295
[16:02:13.174] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:02:13.174] INFO: number of Vcal hits detected: 207901 207960 207885 207825 207822 207788 206910 207878 207919 207833 207872 207695 207881 207907 207971 207974
[16:02:13.174] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[16:02:13.174] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.5 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[16:02:13.174] INFO: X-ray hit rate [MHz/cm2]: 20.1 13.5 21.7 34.2 36.3 37.7 39.8 26.3 22.6 30.2 29.8 26.0 27.5 15.9 7.0 7.7
[16:02:13.174] INFO: PixTestHighRate::doXPixelAlive() done
[16:02:13.219] INFO: PixTest:: pg_setup set to default.
[16:02:13.230] INFO: enter test to run
[16:02:25.175] INFO: test: HighRate no parameter change
[16:02:25.175] INFO: running: highrate
[16:02:25.176] INFO: ----------------------------------------------------------------------
[16:02:25.176] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:02:25.176] INFO: ----------------------------------------------------------------------
[16:02:25.794] INFO: Expecting 208000 events.
[16:02:39.608] INFO: 208000 events read in total (13287ms).
[16:02:39.613] INFO: Test took 14428ms.
[16:02:39.937] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:40.243] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 18 0 0 0 0 3 0 0 0 0
[16:02:40.243] INFO: number of red-efficiency pixels: 269 111 343 555 625 683 587 387 275 481 402 354 360 182 52 58
[16:02:40.243] INFO: number of X-ray hits detected: 140739 94343 150977 238627 251981 261315 273336 183822 158111 210854 208705 181217 191489 110385 49426 53871
[16:02:40.243] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:02:40.243] INFO: number of Vcal hits detected: 207710 207885 207607 207384 207322 207212 206453 207582 207717 207469 207567 207434 207614 207790 207947 207941
[16:02:40.243] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.6 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[16:02:40.243] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.6 99.3 99.8 99.9 99.7 99.8 99.7 99.8 99.9 100.0 100.0
[16:02:40.243] INFO: X-ray hit rate [MHz/cm2]: 41.3 27.7 44.3 69.9 73.9 76.6 80.1 53.9 46.3 61.8 61.2 53.1 56.1 32.4 14.5 15.8
[16:02:40.243] INFO: PixTestHighRate::doXPixelAlive() done
[16:02:40.288] INFO: PixTest:: pg_setup set to default.
[16:02:40.301] INFO: enter test to run
[16:02:53.879] INFO: test: HighRate no parameter change
[16:02:53.879] INFO: running: highrate
[16:02:53.881] INFO: ----------------------------------------------------------------------
[16:02:53.881] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:02:53.881] INFO: ----------------------------------------------------------------------
[16:02:54.498] INFO: Expecting 208000 events.
[16:03:10.340] INFO: 208000 events read in total (15315ms).
[16:03:10.348] INFO: Test took 16459ms.
[16:03:10.839] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:11.197] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 16 0 0 0 0 3 0 0 0 0
[16:03:11.197] INFO: number of red-efficiency pixels: 547 242 741 1367 1515 1557 1343 942 590 1075 1029 866 883 370 92 115
[16:03:11.197] INFO: number of X-ray hits detected: 213027 142776 230814 360547 382425 398364 412046 279249 241045 320827 315140 276124 290240 169152 75663 82162
[16:03:11.197] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:03:11.197] INFO: number of Vcal hits detected: 207342 207738 206954 206192 205941 205821 205275 206758 207325 206643 206740 206784 206942 207527 207902 207879
[16:03:11.197] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.2 99.1 99.0 99.2 99.5 99.7 99.4 99.4 99.5 99.5 99.8 100.0 99.9
[16:03:11.197] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.5 99.1 99.0 99.0 98.7 99.4 99.7 99.3 99.4 99.4 99.5 99.8 100.0 99.9
[16:03:11.197] INFO: X-ray hit rate [MHz/cm2]: 62.4 41.8 67.7 105.7 112.1 116.8 120.8 81.8 70.7 94.0 92.4 80.9 85.1 49.6 22.2 24.1
[16:03:11.197] INFO: PixTestHighRate::doXPixelAlive() done
[16:03:11.243] INFO: PixTest:: pg_setup set to default.
[16:03:11.261] INFO: enter test to run
[16:03:16.095] INFO: test: exit no parameter change
[16:03:16.414] QUIET: Connection to board 32 closed.
[16:03:16.428] INFO: pXar: this is the end, my friend