[13:57:28.303] INFO: *** Welcome to pxar ***
[13:57:28.303] INFO: *** Today: 2016/05/17
[13:57:28.319] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:57:28.319] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//dacParameters35_C15.dat
[13:57:28.344] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:57:28.344] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//defaultMaskFile.dat
[13:57:28.344] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C15.dat
[13:57:28.438] INFO: clk: 4
[13:57:28.438] INFO: ctr: 4
[13:57:28.438] INFO: sda: 19
[13:57:28.438] INFO: tin: 9
[13:57:28.438] INFO: level: 15
[13:57:28.438] INFO: triggerdelay: 0
[13:57:28.438] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:57:28.438] INFO: Log level: INFO
[13:57:28.456] QUIET: Connection to board DTB_WREKRL opened.
[13:57:28.459] 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:
------------------------------------------------------
[13:57:28.462] INFO: RPC call hashes of host and DTB match: 398089610
[13:57:29.991] INFO: DUT info:
[13:57:29.991] INFO: The DUT currently contains the following objects:
[13:57:29.991] INFO: 2 TBM Cores tbm08c (2 ON)
[13:57:29.991] INFO: TBM Core alpha (0): 7 registers set
[13:57:29.991] INFO: TBM Core beta (1): 7 registers set
[13:57:29.991] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:57:29.991] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:29.991] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:30.395] INFO: enter 'restricted' command line mode
[13:57:30.395] INFO: enter test to run
[13:58:08.128] INFO: test: PixelAlive no parameter change
[13:58:08.128] INFO: running: pixelalive
[13:58:08.137] INFO: ----------------------------------------------------------------------
[13:58:08.137] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:58:08.137] INFO: ----------------------------------------------------------------------
[13:58:08.461] INFO: Expecting 41600 events.
[13:58:12.793] INFO: 41600 events read in total (3614ms).
[13:58:12.958] INFO: Test took 4818ms.
[13:58:12.973] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:13.233] INFO: PixTestAlive::aliveTest() done
[13:58:13.233] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:58:13.269] INFO: enter test to run
[13:59:39.855] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:59:39.855] INFO: running: highrate
[13:59:39.856] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:59:40.096] INFO: ----------------------------------------------------------------------
[13:59:40.096] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:59:40.096] INFO: ----------------------------------------------------------------------
[13:59:40.096] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:59:40.096] INFO: edge/corner pixel THR is adjusted
[13:59:40.096] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:59:41.056] INFO: Collecting data for 5 seconds...
[13:59:46.072] INFO: Done with hot pixel readout
[13:59:57.720] INFO: PixTest:: pg_setup set to default.
[13:59:57.721] INFO: 23 hot pixels found in step 0
[13:59:58.737] INFO: Collecting data for 5 seconds...
[14:00:03.753] INFO: Done with hot pixel readout
[14:00:15.389] INFO: PixTest:: pg_setup set to default.
[14:00:15.389] INFO: 20 hot pixels found in step 1
[14:00:16.377] INFO: Collecting data for 5 seconds...
[14:00:21.394] INFO: Done with hot pixel readout
[14:00:32.995] INFO: PixTest:: pg_setup set to default.
[14:00:32.996] INFO: 21 hot pixels found in step 2
[14:00:33.983] INFO: Collecting data for 5 seconds...
[14:00:38.999] INFO: Done with hot pixel readout
[14:00:50.600] INFO: PixTest:: pg_setup set to default.
[14:00:50.600] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:00:50.601] INFO: 24 hot pixels found in step 3
[14:00:51.589] INFO: Collecting data for 5 seconds...
[14:00:56.605] INFO: Done with hot pixel readout
[14:01:08.238] INFO: PixTest:: pg_setup set to default.
[14:01:08.238] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:01:08.239] INFO: 23 hot pixels found in step 4
[14:01:09.227] INFO: Collecting data for 5 seconds...
[14:01:14.243] INFO: Done with hot pixel readout
[14:01:25.857] INFO: PixTest:: pg_setup set to default.
[14:01:25.857] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:01:25.858] INFO: 21 hot pixels found in step 5
[14:01:26.846] INFO: Collecting data for 5 seconds...
[14:01:31.863] INFO: Done with hot pixel readout
[14:01:43.483] INFO: PixTest:: pg_setup set to default.
[14:01:43.483] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:01:43.483] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:01:43.484] INFO: 25 hot pixels found in step 6
[14:01:44.471] INFO: Collecting data for 5 seconds...
[14:01:49.488] INFO: Done with hot pixel readout
[14:02:01.120] INFO: PixTest:: pg_setup set to default.
[14:02:01.120] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:01.120] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:01.121] INFO: 23 hot pixels found in step 7
[14:02:02.108] INFO: Collecting data for 5 seconds...
[14:02:07.125] INFO: Done with hot pixel readout
[14:02:18.740] INFO: PixTest:: pg_setup set to default.
[14:02:18.740] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:18.740] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:18.740] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:18.740] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:18.741] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:18.741] INFO: 24 hot pixels found in step 8
[14:02:19.729] INFO: Collecting data for 5 seconds...
[14:02:24.747] INFO: Done with hot pixel readout
[14:02:36.396] INFO: PixTest:: pg_setup set to default.
[14:02:36.396] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:36.396] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:36.396] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:36.396] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:36.397] INFO: 14 hot pixels found in step 9
[14:02:37.385] INFO: Collecting data for 5 seconds...
[14:02:42.402] INFO: Done with hot pixel readout
[14:02:54.006] INFO: PixTest:: pg_setup set to default.
[14:02:54.006] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:54.006] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:54.006] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:54.006] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:54.007] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:02:54.007] INFO: 15 hot pixels found in step 10
[14:02:54.995] INFO: Collecting data for 5 seconds...
[14:03:00.011] INFO: Done with hot pixel readout
[14:03:11.636] INFO: PixTest:: pg_setup set to default.
[14:03:11.636] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:11.636] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:11.636] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:11.636] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:11.636] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:11.636] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:11.636] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:11.637] INFO: 14 hot pixels found in step 11
[14:03:12.625] INFO: Collecting data for 5 seconds...
[14:03:17.641] INFO: Done with hot pixel readout
[14:03:29.302] INFO: PixTest:: pg_setup set to default.
[14:03:29.302] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:29.302] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:29.302] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:29.302] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:29.302] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:29.302] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:29.302] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:29.303] INFO: 14 hot pixels found in step 12
[14:03:30.290] INFO: Collecting data for 5 seconds...
[14:03:35.307] INFO: Done with hot pixel readout
[14:03:46.893] INFO: PixTest:: pg_setup set to default.
[14:03:46.893] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:46.893] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:46.893] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:46.893] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:46.893] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:03:46.894] INFO: 15 hot pixels found in step 13
[14:03:47.882] INFO: Collecting data for 5 seconds...
[14:03:52.898] INFO: Done with hot pixel readout
[14:04:04.523] INFO: PixTest:: pg_setup set to default.
[14:04:04.523] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:04.523] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:04.523] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:04.523] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:04.523] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:04.524] INFO: 9 hot pixels found in step 14
[14:04:04.555] INFO: 9 hot pixels could not be trimmed and have been masked.
[14:04:04.559] INFO: PixTest::trimHotPixels() done
[14:04:04.564] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C0.dat
[14:04:04.571] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C1.dat
[14:04:04.576] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C2.dat
[14:04:04.582] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C3.dat
[14:04:04.587] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C4.dat
[14:04:04.592] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C5.dat
[14:04:04.597] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C6.dat
[14:04:04.603] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C7.dat
[14:04:04.608] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C8.dat
[14:04:04.613] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C9.dat
[14:04:04.619] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C10.dat
[14:04:04.624] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C11.dat
[14:04:04.629] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C12.dat
[14:04:04.634] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C13.dat
[14:04:04.640] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C14.dat
[14:04:04.645] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C15.dat
[14:04:04.650] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//defaultMaskFile.dat
[14:04:04.661] INFO: enter test to run
[14:04:39.733] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:04:39.733] INFO: running: highrate
[14:04:39.738] INFO: ----------------------------------------------------------------------
[14:04:39.738] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:04:39.738] INFO: ----------------------------------------------------------------------
[14:04:39.738] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:04:39.738] INFO: edge/corner pixel THR is adjusted
[14:04:39.738] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:04:40.695] INFO: Collecting data for 1 seconds...
[14:04:41.699] INFO: Done with hot pixel readout
[14:04:45.669] INFO: PixTest:: pg_setup set to default.
[14:04:45.670] INFO: 0 hot pixels found in step 0
[14:04:45.676] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:04:45.765] INFO: PixTest::trimHotPixels() done
[14:04:45.765] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C0.dat
[14:04:45.773] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C1.dat
[14:04:45.778] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C2.dat
[14:04:45.784] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C3.dat
[14:04:45.789] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C4.dat
[14:04:45.794] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C5.dat
[14:04:45.799] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C6.dat
[14:04:45.805] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C7.dat
[14:04:45.810] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C8.dat
[14:04:45.815] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C9.dat
[14:04:45.820] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C10.dat
[14:04:45.825] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C11.dat
[14:04:45.831] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C12.dat
[14:04:45.836] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C13.dat
[14:04:45.841] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C14.dat
[14:04:45.846] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//trimParameters35_C15.dat
[14:04:45.851] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-2-25_FPIXTest-17C-FNAL-160516-0905_2016-05-16_09h05m_1463407515/000_FPIXTest_p17//defaultMaskFile.dat
[14:04:45.866] INFO: enter test to run
[14:06:31.884] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:06:31.884] INFO: running: xray
[14:06:31.885] INFO: ----------------------------------------------------------------------
[14:06:31.886] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:06:31.886] INFO: ----------------------------------------------------------------------
[14:06:32.848] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:06:44.377] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:07:14.211] INFO: Resuming triggers.
[14:07:25.739] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:07:55.807] INFO: Resuming triggers.
[14:08:07.337] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:08:36.705] INFO: Resuming triggers.
[14:08:48.229] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:09:17.506] INFO: Resuming triggers.
[14:09:29.036] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:09:58.258] INFO: Resuming triggers.
[14:10:09.782] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:10:38.908] INFO: Resuming triggers.
[14:10:50.431] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:11:19.402] INFO: Resuming triggers.
[14:11:30.929] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:11:56.728] INFO: Resuming triggers.
[14:12:04.862] INFO: data taking finished, elapsed time: 100 seconds.
[14:12:25.691] INFO: PixTest:: pg_setup set to default.
[14:12:25.694] INFO: PixTestXray::doPhRun() done
[14:12:25.834] INFO: enter test to run
[14:12:55.954] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:12:55.954] INFO: running: xray
[14:12:55.955] INFO: ----------------------------------------------------------------------
[14:12:55.955] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:12:55.955] INFO: ----------------------------------------------------------------------
[14:12:56.918] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:13:03.672] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:13:33.727] INFO: Resuming triggers.
[14:13:40.483] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:14:10.608] INFO: Resuming triggers.
[14:14:17.363] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:14:47.347] INFO: Resuming triggers.
[14:14:54.102] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[14:15:24.014] INFO: Resuming triggers.
[14:15:30.770] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:16:00.852] INFO: Resuming triggers.
[14:16:07.607] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[14:16:38.179] INFO: Resuming triggers.
[14:16:44.934] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:17:14.893] INFO: Resuming triggers.
[14:17:21.646] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[14:17:52.630] INFO: Resuming triggers.
[14:17:59.382] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[14:18:30.795] INFO: Resuming triggers.
[14:18:37.545] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:19:08.263] INFO: Resuming triggers.
[14:19:15.011] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:19:45.024] INFO: Resuming triggers.
[14:19:51.775] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:20:21.690] INFO: Resuming triggers.
[14:20:28.439] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[14:20:58.422] INFO: Resuming triggers.
[14:21:05.169] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:21:35.151] INFO: Resuming triggers.
[14:21:40.951] INFO: data taking finished, elapsed time: 100 seconds.
[14:22:07.026] INFO: PixTest:: pg_setup set to default.
[14:22:07.029] INFO: PixTestXray::doPhRun() done
[14:22:07.179] INFO: enter test to run
[14:22:40.773] INFO: test: HighRate no parameter change
[14:22:40.773] INFO: running: highrate
[14:22:40.774] INFO: ----------------------------------------------------------------------
[14:22:40.774] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:22:40.774] INFO: ----------------------------------------------------------------------
[14:22:40.915] INFO: Expecting 768 events.
[14:22:42.049] INFO: 768 events read in total (418ms).
[14:22:42.050] INFO: Test took 1269ms.
[14:22:42.853] INFO: Expecting 41600 events.
[14:22:45.975] INFO: 41600 events read in total (2596ms).
[14:22:45.977] INFO: Test took 3922ms.
[14:22:46.014] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:46.728] INFO: Expecting 41600 events.
[14:22:49.929] INFO: 41600 events read in total (2674ms).
[14:22:49.930] INFO: Test took 3898ms.
[14:22:49.963] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:50.689] INFO: Expecting 41600 events.
[14:22:53.905] INFO: 41600 events read in total (2689ms).
[14:22:53.905] INFO: Test took 3924ms.
[14:22:53.938] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:54.665] INFO: Expecting 41600 events.
[14:22:57.896] INFO: 41600 events read in total (2704ms).
[14:22:57.897] INFO: Test took 3941ms.
[14:22:57.931] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:58.654] INFO: Expecting 41600 events.
[14:23:01.871] INFO: 41600 events read in total (2690ms).
[14:23:01.872] INFO: Test took 3923ms.
[14:23:01.904] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:02.631] INFO: Expecting 41600 events.
[14:23:05.855] INFO: 41600 events read in total (2697ms).
[14:23:05.856] INFO: Test took 3933ms.
[14:23:05.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:06.616] INFO: Expecting 41600 events.
[14:23:09.852] INFO: 41600 events read in total (2709ms).
[14:23:09.853] INFO: Test took 3945ms.
[14:23:09.887] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:10.613] INFO: Expecting 41600 events.
[14:23:13.838] INFO: 41600 events read in total (2699ms).
[14:23:13.839] INFO: Test took 3935ms.
[14:23:13.872] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:14.601] INFO: Expecting 41600 events.
[14:23:17.820] INFO: 41600 events read in total (2693ms).
[14:23:17.821] INFO: Test took 3931ms.
[14:23:17.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:18.580] INFO: Expecting 41600 events.
[14:23:21.825] INFO: 41600 events read in total (2718ms).
[14:23:21.826] INFO: Test took 3954ms.
[14:23:21.859] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:22.581] INFO: Expecting 41600 events.
[14:23:25.810] INFO: 41600 events read in total (2702ms).
[14:23:25.811] INFO: Test took 3934ms.
[14:23:25.844] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:26.569] INFO: Expecting 41600 events.
[14:23:29.793] INFO: 41600 events read in total (2697ms).
[14:23:29.794] INFO: Test took 3932ms.
[14:23:29.827] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:30.550] INFO: Expecting 41600 events.
[14:23:33.777] INFO: 41600 events read in total (2700ms).
[14:23:33.778] INFO: Test took 3932ms.
[14:23:33.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:34.534] INFO: Expecting 41600 events.
[14:23:37.764] INFO: 41600 events read in total (2704ms).
[14:23:37.765] INFO: Test took 3936ms.
[14:23:37.798] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:38.526] INFO: Expecting 41600 events.
[14:23:41.762] INFO: 41600 events read in total (2709ms).
[14:23:41.763] INFO: Test took 3947ms.
[14:23:41.795] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:42.524] INFO: Expecting 41600 events.
[14:23:45.755] INFO: 41600 events read in total (2704ms).
[14:23:45.756] INFO: Test took 3942ms.
[14:23:45.789] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:46.515] INFO: Expecting 41600 events.
[14:23:49.762] INFO: 41600 events read in total (2721ms).
[14:23:49.762] INFO: Test took 3954ms.
[14:23:49.796] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:50.519] INFO: Expecting 41600 events.
[14:23:53.748] INFO: 41600 events read in total (2703ms).
[14:23:53.749] INFO: Test took 3936ms.
[14:23:53.782] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:54.509] INFO: Expecting 41600 events.
[14:23:57.715] INFO: 41600 events read in total (2679ms).
[14:23:57.716] INFO: Test took 3916ms.
[14:23:57.750] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:58.473] INFO: Expecting 41600 events.
[14:24:01.506] INFO: 41600 events read in total (2506ms).
[14:24:01.507] INFO: Test took 3739ms.
[14:24:01.539] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:01.906] INFO: enter test to run
[14:24:24.316] INFO: test: HighRate no parameter change
[14:24:24.316] INFO: running: highrate
[14:24:24.318] INFO: ----------------------------------------------------------------------
[14:24:24.318] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:24:24.318] INFO: ----------------------------------------------------------------------
[14:24:24.938] INFO: Expecting 208000 events.
[14:24:36.751] INFO: 208000 events read in total (11286ms).
[14:24:36.754] INFO: Test took 12426ms.
[14:24:36.892] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:37.141] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:24:37.141] INFO: number of red-efficiency pixels: 91 33 89 101 153 153 137 77 84 91 103 103 96 51 23 32
[14:24:37.141] INFO: number of X-ray hits detected: 69297 41754 67511 103775 114434 119377 108165 76671 68983 91649 90159 80238 81390 50002 21841 24314
[14:24:37.141] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:24:37.141] INFO: number of Vcal hits detected: 207905 207966 207907 207898 207840 207844 207858 207919 207916 207909 207893 207894 207903 207948 207977 207968
[14:24:37.141] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[14:24:37.141] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0
[14:24:37.141] INFO: X-ray hit rate [MHz/cm2]: 20.3 12.2 19.8 30.4 33.5 35.0 31.7 22.5 20.2 26.9 26.4 23.5 23.9 14.7 6.4 7.1
[14:24:37.141] INFO: PixTestHighRate::doXPixelAlive() done
[14:24:37.190] INFO: PixTest:: pg_setup set to default.
[14:24:37.204] INFO: enter test to run
[14:24:58.180] INFO: test: HighRate no parameter change
[14:24:58.180] INFO: running: highrate
[14:24:58.181] INFO: ----------------------------------------------------------------------
[14:24:58.199] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:24:58.199] INFO: ----------------------------------------------------------------------
[14:24:58.809] INFO: Expecting 208000 events.
[14:25:12.380] INFO: 208000 events read in total (13044ms).
[14:25:12.386] INFO: Test took 14178ms.
[14:25:12.673] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:12.972] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:25:12.972] INFO: number of red-efficiency pixels: 262 123 255 342 414 488 541 309 184 296 305 293 299 212 63 61
[14:25:12.972] INFO: number of X-ray hits detected: 145868 89176 143223 219002 240235 251522 227293 162503 146239 194080 190668 169390 171843 105982 46310 51413
[14:25:12.972] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:25:12.972] INFO: number of Vcal hits detected: 207718 207877 207726 207632 207544 207457 207401 207662 207811 207683 207677 207690 207684 207780 207937 207935
[14:25:12.972] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[14:25:12.972] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[14:25:12.972] INFO: X-ray hit rate [MHz/cm2]: 42.8 26.1 42.0 64.2 70.4 73.7 66.6 47.6 42.9 56.9 55.9 49.6 50.4 31.1 13.6 15.1
[14:25:12.973] INFO: PixTestHighRate::doXPixelAlive() done
[14:25:13.021] INFO: PixTest:: pg_setup set to default.
[14:25:13.037] INFO: enter test to run
[14:25:44.836] INFO: test: HighRate no parameter change
[14:25:44.836] INFO: running: highrate
[14:25:44.837] INFO: ----------------------------------------------------------------------
[14:25:44.837] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:25:44.837] INFO: ----------------------------------------------------------------------
[14:25:45.453] INFO: Expecting 208000 events.
[14:26:00.884] INFO: 208000 events read in total (14905ms).
[14:26:00.892] INFO: Test took 16045ms.
[14:26:01.326] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:01.671] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:26:01.671] INFO: number of red-efficiency pixels: 631 246 521 811 921 1079 1301 714 410 753 754 691 688 425 101 97
[14:26:01.671] INFO: number of X-ray hits detected: 220611 134943 217266 329278 362692 380202 343401 245495 221180 293541 288436 256795 259108 160047 70353 78428
[14:26:01.671] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:26:01.671] INFO: number of Vcal hits detected: 207195 207740 207370 207053 206895 206586 206282 207130 207549 207146 207118 207207 207232 207512 207898 207902
[14:26:01.671] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.6 99.5 99.4 99.3 99.6 99.8 99.6 99.6 99.7 99.7 99.8 100.0 100.0
[14:26:01.671] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.7 99.5 99.5 99.3 99.2 99.6 99.8 99.6 99.6 99.6 99.6 99.8 100.0 100.0
[14:26:01.671] INFO: X-ray hit rate [MHz/cm2]: 64.7 39.6 63.7 96.5 106.3 111.4 100.7 72.0 64.8 86.0 84.5 75.3 75.9 46.9 20.6 23.0
[14:26:01.671] INFO: PixTestHighRate::doXPixelAlive() done
[14:26:01.718] INFO: PixTest:: pg_setup set to default.
[14:26:01.734] INFO: enter test to run
[14:26:05.244] INFO: test: exit no parameter change
[14:26:05.612] QUIET: Connection to board 33 closed.
[14:26:05.613] INFO: pXar: this is the end, my friend