[12:37:51.047] INFO: *** Welcome to pxar ***
[12:37:51.047] INFO: *** Today: 2016/05/30
[12:37:51.064] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:37:51.064] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//dacParameters35_C15.dat
[12:37:51.065] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:37:51.065] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//defaultMaskFile.dat
[12:37:51.066] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C15.dat
[12:37:51.140] INFO: clk: 4
[12:37:51.140] INFO: ctr: 4
[12:37:51.140] INFO: sda: 19
[12:37:51.140] INFO: tin: 9
[12:37:51.141] INFO: level: 15
[12:37:51.141] INFO: triggerdelay: 0
[12:37:51.141] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:37:51.141] INFO: Log level: INFO
[12:37:51.158] QUIET: Connection to board DTB_WREKRL opened.
[12:37:51.161] 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:
------------------------------------------------------
[12:37:51.164] INFO: RPC call hashes of host and DTB match: 398089610
[12:37:52.690] INFO: DUT info:
[12:37:52.690] INFO: The DUT currently contains the following objects:
[12:37:52.690] INFO: 2 TBM Cores tbm08c (2 ON)
[12:37:52.690] INFO: TBM Core alpha (0): 7 registers set
[12:37:52.690] INFO: TBM Core beta (1): 7 registers set
[12:37:52.690] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:37:52.691] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:52.691] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:37:53.094] INFO: enter 'restricted' command line mode
[12:37:53.094] INFO: enter test to run
[12:37:56.499] INFO: test: timing no parameter change
[12:37:56.499] INFO: running: timing
[12:37:56.508] INFO: ######################################################################
[12:37:56.508] INFO: PixTestTiming::doTest()
[12:37:56.508] INFO: ######################################################################
[12:37:56.509] INFO: ----------------------------------------------------------------------
[12:37:56.509] INFO: PixTestTiming::TBMPhaseScan()
[12:37:56.509] INFO: ----------------------------------------------------------------------
[12:42:59.577] INFO: TBM Phase Settings: 248
[12:42:59.577] INFO: 400MHz Phase: 6
[12:42:59.577] INFO: 160MHz Phase: 7
[12:42:59.577] INFO: Functional Phase Area: 4
[12:42:59.600] INFO: Test took 303091 ms.
[12:42:59.600] INFO: PixTestTiming::TBMPhaseScan() done.
[12:42:59.600] INFO: ----------------------------------------------------------------------
[12:42:59.600] INFO: PixTestTiming::ROCDelayScan()
[12:42:59.600] INFO: ----------------------------------------------------------------------
[12:45:53.910] INFO: ROC Delay Settings: 228
[12:45:53.911] INFO: ROC Header-Trailer/Token Delay: 11
[12:45:53.911] INFO: ROC Port 0 Delay: 4
[12:45:53.911] INFO: ROC Port 1 Delay: 4
[12:45:53.911] INFO: Functional ROC Area: 6
[12:45:53.914] INFO: Test took 174314 ms.
[12:45:53.914] INFO: PixTestTiming::ROCDelayScan() done.
[12:45:53.914] INFO: ----------------------------------------------------------------------
[12:45:53.914] INFO: PixTestTiming::TimingTest()
[12:45:53.914] INFO: ----------------------------------------------------------------------
[12:46:10.073] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:25.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:40.023] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:54.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:09.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:24.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:39.852] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:54.819] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:09.779] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:24.784] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:25.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:25.183] INFO: ----------------------------------------------------------------------
[12:48:25.183] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:48:25.183] INFO: ----------------------------------------------------------------------
[12:48:25.183] INFO: ----------------------------------------------------------------------
[12:48:25.183] INFO: Read back bit status: 1
[12:48:25.183] INFO: ----------------------------------------------------------------------
[12:48:25.183] INFO: ----------------------------------------------------------------------
[12:48:25.183] INFO: Timings are good!
[12:48:25.183] INFO: ----------------------------------------------------------------------
[12:48:25.183] INFO: Test took 151269 ms.
[12:48:25.183] INFO: PixTestTiming::TimingTest() done.
[12:48:25.183] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:48:25.183] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:48:25.183] INFO: PixTestTiming::doTest took 628680 ms.
[12:48:25.183] INFO: PixTestTiming::doTest() done
[12:48:25.183] INFO: Write out TBMPhaseScan_0_V0
[12:48:25.211] INFO: Write out TBMPhaseScan_1_V0
[12:48:25.212] INFO: Write out CombinedTBMPhaseScan_V0
[12:48:25.212] INFO: Write out ROCDelayScan3_V0
[12:48:25.213] INFO: enter test to run
[12:48:28.567] INFO: test: PixelAlive no parameter change
[12:48:28.567] INFO: running: pixelalive
[12:48:28.571] INFO: ----------------------------------------------------------------------
[12:48:28.571] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:48:28.571] INFO: ----------------------------------------------------------------------
[12:48:28.890] INFO: Expecting 41600 events.
[12:48:33.226] INFO: 41600 events read in total (3620ms).
[12:48:33.226] INFO: Test took 4651ms.
[12:48:33.233] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:33.630] INFO: PixTestAlive::aliveTest() done
[12:48:33.630] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0
[12:48:33.632] INFO: enter test to run
[12:48:48.831] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:48:48.831] INFO: running: highrate
[12:48:48.831] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:48:48.980] INFO: ----------------------------------------------------------------------
[12:48:48.980] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:48:48.980] INFO: ----------------------------------------------------------------------
[12:48:48.980] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:48:48.981] INFO: edge/corner pixel THR is adjusted
[12:48:48.981] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:48:49.938] INFO: Collecting data for 5 seconds...
[12:48:54.953] INFO: Done with hot pixel readout
[12:49:07.232] INFO: PixTest:: pg_setup set to default.
[12:49:07.233] INFO: 2 hot pixels found in step 0
[12:49:08.226] INFO: Collecting data for 5 seconds...
[12:49:13.242] INFO: Done with hot pixel readout
[12:49:25.505] INFO: PixTest:: pg_setup set to default.
[12:49:25.505] INFO: 4 hot pixels found in step 1
[12:49:26.499] INFO: Collecting data for 5 seconds...
[12:49:31.515] INFO: Done with hot pixel readout
[12:49:43.821] INFO: PixTest:: pg_setup set to default.
[12:49:43.822] INFO: 3 hot pixels found in step 2
[12:49:44.816] INFO: Collecting data for 5 seconds...
[12:49:49.831] INFO: Done with hot pixel readout
[12:50:02.095] INFO: PixTest:: pg_setup set to default.
[12:50:02.096] INFO: 2 hot pixels found in step 3
[12:50:03.090] INFO: Collecting data for 5 seconds...
[12:50:08.105] INFO: Done with hot pixel readout
[12:50:20.380] INFO: PixTest:: pg_setup set to default.
[12:50:20.381] INFO: 2 hot pixels found in step 4
[12:50:21.374] INFO: Collecting data for 5 seconds...
[12:50:26.390] INFO: Done with hot pixel readout
[12:50:38.610] INFO: PixTest:: pg_setup set to default.
[12:50:38.611] INFO: 2 hot pixels found in step 5
[12:50:39.605] INFO: Collecting data for 5 seconds...
[12:50:44.621] INFO: Done with hot pixel readout
[12:50:56.922] INFO: PixTest:: pg_setup set to default.
[12:50:56.923] INFO: 3 hot pixels found in step 6
[12:50:57.917] INFO: Collecting data for 5 seconds...
[12:51:02.932] INFO: Done with hot pixel readout
[12:51:15.245] INFO: PixTest:: pg_setup set to default.
[12:51:15.246] INFO: 2 hot pixels found in step 7
[12:51:16.240] INFO: Collecting data for 5 seconds...
[12:51:21.256] INFO: Done with hot pixel readout
[12:51:33.585] INFO: PixTest:: pg_setup set to default.
[12:51:33.586] INFO: 1 hot pixels found in step 8
[12:51:34.579] INFO: Collecting data for 5 seconds...
[12:51:39.594] INFO: Done with hot pixel readout
[12:51:51.928] INFO: PixTest:: pg_setup set to default.

[12:51:51.929] INFO: 3 hot pixels found in step 9
[12:51:52.926] INFO: Collecting data for 5 seconds...
[12:51:57.941] INFO: Done with hot pixel readout
[12:52:10.240] INFO: PixTest:: pg_setup set to default.
[12:52:10.241] INFO: 1 hot pixels found in step 10
[12:52:11.235] INFO: Collecting data for 5 seconds...
[12:52:16.250] INFO: Done with hot pixel readout
[12:52:28.507] INFO: PixTest:: pg_setup set to default.
[12:52:28.508] INFO: 3 hot pixels found in step 11
[12:52:29.501] INFO: Collecting data for 5 seconds...
[12:52:34.517] INFO: Done with hot pixel readout
[12:52:46.818] INFO: PixTest:: pg_setup set to default.
[12:52:46.819] INFO: 3 hot pixels found in step 12
[12:52:47.812] INFO: Collecting data for 5 seconds...
[12:52:52.828] INFO: Done with hot pixel readout
[12:53:05.216] INFO: PixTest:: pg_setup set to default.
[12:53:05.217] INFO: 2 hot pixels found in step 13
[12:53:06.211] INFO: Collecting data for 5 seconds...
[12:53:11.226] INFO: Done with hot pixel readout
[12:53:23.583] INFO: PixTest:: pg_setup set to default.
[12:53:23.584] INFO: 3 hot pixels found in step 14
[12:53:23.621] INFO: 3 hot pixels could not be trimmed and have been masked.
[12:53:23.624] INFO: PixTest::trimHotPixels() done
[12:53:23.624] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C0.dat
[12:53:23.630] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C1.dat
[12:53:23.637] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C2.dat
[12:53:23.642] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C3.dat
[12:53:23.647] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C4.dat
[12:53:23.652] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C5.dat
[12:53:23.657] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C6.dat
[12:53:23.662] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C7.dat
[12:53:23.668] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C8.dat
[12:53:23.673] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C9.dat
[12:53:23.678] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C10.dat
[12:53:23.683] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C11.dat
[12:53:23.688] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C12.dat
[12:53:23.693] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C13.dat
[12:53:23.699] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C14.dat
[12:53:23.704] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C15.dat
[12:53:23.709] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//defaultMaskFile.dat
[12:53:23.719] INFO: enter test to run
[12:54:37.236] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:54:37.236] INFO: running: highrate
[12:54:37.241] INFO: ----------------------------------------------------------------------
[12:54:37.241] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:54:37.241] INFO: ----------------------------------------------------------------------
[12:54:37.241] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:54:37.241] INFO: edge/corner pixel THR is adjusted
[12:54:37.241] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:54:38.198] INFO: Collecting data for 1 seconds...
[12:54:39.202] INFO: Done with hot pixel readout
[12:54:43.442] INFO: PixTest:: pg_setup set to default.
[12:54:43.443] INFO: 0 hot pixels found in step 0
[12:54:43.448] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:54:43.531] INFO: PixTest::trimHotPixels() done
[12:54:43.532] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C0.dat
[12:54:43.544] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C1.dat
[12:54:43.550] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C2.dat
[12:54:43.556] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C3.dat
[12:54:43.562] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C4.dat
[12:54:43.567] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C5.dat
[12:54:43.572] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C6.dat
[12:54:43.577] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C7.dat
[12:54:43.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C8.dat
[12:54:43.588] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C9.dat
[12:54:43.594] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C10.dat
[12:54:43.599] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C11.dat
[12:54:43.605] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C12.dat
[12:54:43.610] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C13.dat
[12:54:43.615] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C14.dat
[12:54:43.621] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//trimParameters35_C15.dat
[12:54:43.627] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-F-NC_FPIXTest-17C-FNAL-160520-1442_2016-05-20_14h43m_1463773381/000_FPIXTest_p17//defaultMaskFile.dat
[12:54:43.636] INFO: enter test to run
[12:55:46.556] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:55:46.556] INFO: running: xray
[12:55:46.557] INFO: ----------------------------------------------------------------------
[12:55:46.557] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:55:46.557] INFO: ----------------------------------------------------------------------
[12:55:47.543] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:55:58.648] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:56:28.210] INFO: Resuming triggers.
[12:56:39.317] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:57:08.976] INFO: Resuming triggers.
[12:57:20.081] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:57:49.731] INFO: Resuming triggers.
[12:58:00.836] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[12:58:30.439] INFO: Resuming triggers.
[12:58:41.540] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[12:59:11.157] INFO: Resuming triggers.
[12:59:22.267] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[12:59:51.913] INFO: Resuming triggers.
[13:00:03.018] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[13:00:32.694] INFO: Resuming triggers.
[13:00:43.799] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[13:01:13.395] INFO: Resuming triggers.
[13:01:24.499] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[13:01:54.127] INFO: Resuming triggers.
[13:01:54.493] INFO: data taking finished, elapsed time: 100 seconds.
[13:01:55.912] INFO: PixTest:: pg_setup set to default.
[13:01:55.915] INFO: PixTestXray::doPhRun() done
[13:01:56.058] INFO: enter test to run
[13:02:24.057] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:02:24.057] INFO: running: xray
[13:02:24.058] INFO: ----------------------------------------------------------------------
[13:02:24.058] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:02:24.058] INFO: ----------------------------------------------------------------------
[13:02:25.036] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:02:31.357] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:03:01.554] INFO: Resuming triggers.
[13:03:07.876] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[13:03:38.065] INFO: Resuming triggers.
[13:03:44.387] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[13:04:14.652] INFO: Resuming triggers.
[13:04:20.976] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[13:04:51.201] INFO: Resuming triggers.
[13:04:57.527] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[13:05:27.790] INFO: Resuming triggers.
[13:05:34.115] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[13:06:04.314] INFO: Resuming triggers.
[13:06:10.644] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[13:06:40.837] INFO: Resuming triggers.
[13:06:47.167] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[13:07:17.356] INFO: Resuming triggers.
[13:07:23.682] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:07:53.852] INFO: Resuming triggers.
[13:08:00.179] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[13:08:30.354] INFO: Resuming triggers.
[13:08:36.688] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:09:06.801] INFO: Resuming triggers.
[13:09:13.134] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[13:09:43.346] INFO: Resuming triggers.
[13:09:49.670] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:10:19.834] INFO: Resuming triggers.
[13:10:26.160] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[13:10:56.379] INFO: Resuming triggers.
[13:11:02.709] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[13:11:32.895] INFO: Resuming triggers.
[13:11:38.309] INFO: data taking finished, elapsed time: 100 seconds.
[13:12:04.526] INFO: PixTest:: pg_setup set to default.
[13:12:04.529] INFO: PixTestXray::doPhRun() done
[13:12:04.676] INFO: enter test to run
[13:12:35.508] INFO: test: HighRate no parameter change
[13:12:35.508] INFO: running: highrate
[13:12:35.509] INFO: ----------------------------------------------------------------------
[13:12:35.509] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:12:35.509] INFO: ----------------------------------------------------------------------
[13:12:35.649] INFO: Expecting 768 events.
[13:12:36.783] INFO: 768 events read in total (418ms).
[13:12:36.784] INFO: Test took 1268ms.
[13:12:37.587] INFO: Expecting 41600 events.
[13:12:40.684] INFO: 41600 events read in total (2570ms).
[13:12:40.685] INFO: Test took 3894ms.
[13:12:40.721] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:41.442] INFO: Expecting 41600 events.
[13:12:44.685] INFO: 41600 events read in total (2716ms).
[13:12:44.686] INFO: Test took 3946ms.
[13:12:44.724] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:45.442] INFO: Expecting 41600 events.
[13:12:48.716] INFO: 41600 events read in total (2747ms).
[13:12:48.717] INFO: Test took 3973ms.
[13:12:48.754] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:49.470] INFO: Expecting 41600 events.
[13:12:52.749] INFO: 41600 events read in total (2752ms).
[13:12:52.750] INFO: Test took 3978ms.
[13:12:52.787] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:53.503] INFO: Expecting 41600 events.
[13:12:56.782] INFO: 41600 events read in total (2752ms).
[13:12:56.783] INFO: Test took 3978ms.
[13:12:56.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:57.538] INFO: Expecting 41600 events.
[13:13:00.816] INFO: 41600 events read in total (2751ms).
[13:13:00.817] INFO: Test took 3979ms.
[13:13:00.855] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:01.574] INFO: Expecting 41600 events.
[13:13:04.870] INFO: 41600 events read in total (2769ms).
[13:13:04.871] INFO: Test took 3998ms.
[13:13:04.909] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:05.624] INFO: Expecting 41600 events.
[13:13:08.914] INFO: 41600 events read in total (2763ms).
[13:13:08.915] INFO: Test took 3987ms.
[13:13:08.953] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:09.670] INFO: Expecting 41600 events.
[13:13:12.956] INFO: 41600 events read in total (2759ms).
[13:13:12.957] INFO: Test took 3986ms.
[13:13:12.995] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:13.710] INFO: Expecting 41600 events.
[13:13:16.002] INFO: 41600 events read in total (2765ms).
[13:13:16.003] INFO: Test took 3988ms.
[13:13:17.040] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:17.759] INFO: Expecting 41600 events.
[13:13:21.060] INFO: 41600 events read in total (2774ms).
[13:13:21.061] INFO: Test took 4002ms.
[13:13:21.099] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:21.818] INFO: Expecting 41600 events.
[13:13:25.114] INFO: 41600 events read in total (2769ms).
[13:13:25.115] INFO: Test took 3996ms.
[13:13:25.152] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:25.871] INFO: Expecting 41600 events.
[13:13:29.156] INFO: 41600 events read in total (2758ms).
[13:13:29.157] INFO: Test took 3985ms.
[13:13:29.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:29.910] INFO: Expecting 41600 events.
[13:13:33.223] INFO: 41600 events read in total (2786ms).
[13:13:33.224] INFO: Test took 4010ms.
[13:13:33.261] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:33.977] INFO: Expecting 41600 events.
[13:13:37.271] INFO: 41600 events read in total (2767ms).
[13:13:37.272] INFO: Test took 3992ms.
[13:13:37.310] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:38.027] INFO: Expecting 41600 events.
[13:13:41.315] INFO: 41600 events read in total (2761ms).
[13:13:41.316] INFO: Test took 3987ms.
[13:13:41.354] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:42.074] INFO: Expecting 41600 events.
[13:13:45.360] INFO: 41600 events read in total (2759ms).
[13:13:45.361] INFO: Test took 3987ms.
[13:13:45.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:46.119] INFO: Expecting 41600 events.
[13:13:49.400] INFO: 41600 events read in total (2754ms).
[13:13:49.401] INFO: Test took 3982ms.
[13:13:49.439] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:50.154] INFO: Expecting 41600 events.
[13:13:53.422] INFO: 41600 events read in total (2741ms).
[13:13:53.423] INFO: Test took 3966ms.
[13:13:53.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:54.180] INFO: Expecting 41600 events.
[13:13:57.368] INFO: 41600 events read in total (2661ms).
[13:13:57.369] INFO: Test took 3890ms.
[13:13:57.407] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:57.761] INFO: enter test to run
[13:14:18.083] INFO: test: HighRate no parameter change
[13:14:18.083] INFO: running: highrate
[13:14:18.084] INFO: ----------------------------------------------------------------------
[13:14:18.084] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:14:18.085] INFO: ----------------------------------------------------------------------
[13:14:18.699] INFO: Expecting 208000 events.
[13:14:30.774] INFO: 208000 events read in total (11549ms).
[13:14:30.778] INFO: Test took 12683ms.
[13:14:30.941] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:14:31.198] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0
[13:14:31.198] INFO: number of red-efficiency pixels: 94 65 79 198 184 208 161 127 123 141 118 120 115 75 30 30
[13:14:31.198] INFO: number of X-ray hits detected: 70431 48761 78270 125668 133157 136130 132231 97670 81492 103807 105503 91180 94680 56995 25699 28354
[13:14:31.198] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:14:31.198] INFO: number of Vcal hits detected: 207901 207933 207918 207798 207814 207790 207831 207871 207874 207856 207877 207880 207883 207924 207920 207970
[13:14:31.198] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:14:31.198] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:14:31.198] INFO: X-ray hit rate [MHz/cm2]: 20.6 14.3 22.9 36.8 39.0 39.9 38.8 28.6 23.9 30.4 30.9 26.7 27.8 16.7 7.5 8.3
[13:14:31.198] INFO: PixTestHighRate::doXPixelAlive() done
[13:14:31.253] INFO: PixTest:: pg_setup set to default.
[13:14:31.264] INFO: enter test to run
[13:14:58.611] INFO: test: HighRate no parameter change
[13:14:58.611] INFO: running: highrate
[13:14:58.612] INFO: ----------------------------------------------------------------------
[13:14:58.612] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:14:58.612] INFO: ----------------------------------------------------------------------
[13:14:59.230] INFO: Expecting 208000 events.
[13:15:13.254] INFO: 208000 events read in total (13497ms).
[13:15:13.260] INFO: Test took 14639ms.
[13:15:13.586] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:13.897] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0
[13:15:13.897] INFO: number of red-efficiency pixels: 246 155 268 592 503 738 544 445 278 444 346 403 338 212 68 67
[13:15:13.897] INFO: number of X-ray hits detected: 143265 99147 158542 254922 270283 276235 268274 198089 166542 210754 214811 186446 192667 116146 53052 58408
[13:15:13.897] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:15:13.897] INFO: number of Vcal hits detected: 207737 207835 207703 207335 207451 207161 207400 207501 207707 207522 207628 207570 207645 207775 207881 207929
[13:15:13.897] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.6 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[13:15:13.897] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.6 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 99.9 100.0
[13:15:13.898] INFO: X-ray hit rate [MHz/cm2]: 42.0 29.1 46.5 74.7 79.2 81.0 78.6 58.1 48.8 61.8 63.0 54.6 56.5 34.0 15.5 17.1
[13:15:13.898] INFO: PixTestHighRate::doXPixelAlive() done
[13:15:13.948] INFO: PixTest:: pg_setup set to default.
[13:15:13.966] INFO: enter test to run
[13:15:44.571] INFO: test: HighRate no parameter change
[13:15:44.571] INFO: running: highrate
[13:15:44.572] INFO: ----------------------------------------------------------------------
[13:15:44.572] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:15:44.572] INFO: ----------------------------------------------------------------------
[13:15:45.191] INFO: Expecting 208000 events.
[13:16:01.278] INFO: 208000 events read in total (15560ms).
[13:16:01.286] INFO: Test took 16704ms.
[13:16:01.787] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:02.148] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0
[13:16:02.148] INFO: number of red-efficiency pixels: 532 315 609 1487 1188 1676 1269 1007 642 1053 782 849 831 495 105 108
[13:16:02.148] INFO: number of X-ray hits detected: 215108 148930 236286 381972 403256 414810 401172 297365 249613 317000 321840 278925 289284 174505 79153 87364
[13:16:02.148] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:16:02.148] INFO: number of Vcal hits detected: 207381 207647 207230 205927 206453 205526 206306 206641 207254 206735 207063 206988 207046 207413 207846 207889
[13:16:02.148] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.7 99.1 99.3 98.9 99.3 99.4 99.7 99.4 99.6 99.6 99.6 99.8 100.0 100.0
[13:16:02.148] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.6 99.0 99.3 98.8 99.2 99.3 99.6 99.4 99.5 99.5 99.5 99.7 99.9 99.9
[13:16:02.148] INFO: X-ray hit rate [MHz/cm2]: 63.0 43.7 69.3 112.0 118.2 121.6 117.6 87.2 73.2 92.9 94.3 81.8 84.8 51.1 23.2 25.6
[13:16:02.149] INFO: PixTestHighRate::doXPixelAlive() done
[13:16:02.201] INFO: PixTest:: pg_setup set to default.
[13:16:02.220] INFO: enter test to run
[13:16:05.291] INFO: test: exit no parameter change
[13:16:05.697] QUIET: Connection to board 33 closed.
[13:16:05.699] INFO: pXar: this is the end, my friend