[10:07:24.829] INFO: *** Welcome to pxar ***
[10:07:24.829] INFO: *** Today: 2016/04/12
[10:07:25.257] INFO: *** Version: v1.9.0-796-gef167-dirty
[10:07:25.257] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//dacParameters35_C15.dat
[10:07:25.333] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:07:25.343] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//defaultMaskFile.dat
[10:07:25.351] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C15.dat
[10:07:25.503] INFO: clk: 4
[10:07:25.503] INFO: ctr: 4
[10:07:25.503] INFO: sda: 19
[10:07:25.503] INFO: tin: 9
[10:07:25.503] INFO: level: 15
[10:07:25.503] INFO: triggerdelay: 0
[10:07:25.511] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[10:07:25.511] INFO: Log level: INFO
[10:07:25.549] QUIET: Connection to board DTB_WREKRL opened.
[10:07:25.552] 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:
------------------------------------------------------
[10:07:25.555] INFO: RPC call hashes of host and DTB match: 398089610
[10:07:27.087] INFO: DUT info:
[10:07:27.087] INFO: The DUT currently contains the following objects:
[10:07:27.087] INFO: 2 TBM Cores tbm08c (2 ON)
[10:07:27.087] INFO: TBM Core alpha (0): 7 registers set
[10:07:27.087] INFO: TBM Core beta (1): 7 registers set
[10:07:27.087] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:07:27.087] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.087] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.087] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.087] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.087] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.087] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.087] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.087] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.087] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.087] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.087] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.087] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.087] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.088] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.088] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.088] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:07:27.570] INFO: enter 'restricted' command line mode
[10:07:27.570] INFO: enter test to run
[10:07:42.837] INFO: test: PixelAlive no parameter change
[10:07:42.837] INFO: running: pixelalive
[10:07:42.888] INFO: ----------------------------------------------------------------------
[10:07:42.888] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:07:42.888] INFO: ----------------------------------------------------------------------
[10:07:43.210] INFO: Expecting 41600 events.





















[10:07:47.733] INFO: 0 events read in total (3804ms).

[10:07:48.228] INFO: Expecting 41600 events.
[10:07:52.543] INFO: 41600 events read in total (3600ms).
[10:07:52.544] INFO: Test took 4629ms.
[10:07:52.550] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:07:52.948] INFO: PixTestAlive::aliveTest() done
[10:07:52.948] INFO: number of dead pixels (per ROC): 3 0 26 0 2 0 0 1 0 0 0 1 0 0 0 0
[10:07:53.027] INFO: enter test to run
[10:08:07.061] INFO: test: timing no parameter change
[10:08:07.061] INFO: running: timing
[10:08:07.064] INFO: ######################################################################
[10:08:07.064] INFO: PixTestTiming::doTest()
[10:08:07.064] INFO: ######################################################################
[10:08:07.064] INFO: ----------------------------------------------------------------------
[10:08:07.065] INFO: PixTestTiming::TBMPhaseScan()
[10:08:07.065] INFO: ----------------------------------------------------------------------
[10:13:29.548] INFO: TBM Phase Settings: 236
[10:13:29.549] INFO: 400MHz Phase: 3
[10:13:29.549] INFO: 160MHz Phase: 7
[10:13:29.549] INFO: Functional Phase Area: 4
[10:13:29.559] INFO: Test took 322495 ms.
[10:13:29.559] INFO: PixTestTiming::TBMPhaseScan() done.
[10:13:29.559] INFO: ----------------------------------------------------------------------
[10:13:29.559] INFO: PixTestTiming::ROCDelayScan()
[10:13:29.559] INFO: ----------------------------------------------------------------------
[10:15:52.868] INFO: ROC Delay Settings: 228
[10:15:52.868] INFO: ROC Header-Trailer/Token Delay: 11
[10:15:52.868] INFO: ROC Port 0 Delay: 4
[10:15:52.868] INFO: ROC Port 1 Delay: 4
[10:15:52.868] INFO: Functional ROC Area: 5
[10:15:52.871] INFO: Test took 143312 ms.
[10:15:52.871] INFO: PixTestTiming::ROCDelayScan() done.
[10:15:52.871] INFO: ----------------------------------------------------------------------
[10:15:52.871] INFO: PixTestTiming::TimingTest()
[10:15:52.871] INFO: ----------------------------------------------------------------------
[10:16:09.015] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:23.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:38.948] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:53.904] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:08.864] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:23.818] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:38.772] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:53.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:08.664] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:23.616] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:23.998] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:24.015] INFO: ----------------------------------------------------------------------
[10:18:24.015] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[10:18:24.015] INFO: ----------------------------------------------------------------------
[10:18:24.015] INFO: ----------------------------------------------------------------------
[10:18:24.015] INFO: Read back bit status: 1
[10:18:24.015] INFO: ----------------------------------------------------------------------
[10:18:24.015] INFO: ----------------------------------------------------------------------
[10:18:24.015] INFO: Timings are good!
[10:18:24.015] INFO: ----------------------------------------------------------------------
[10:18:24.016] INFO: Test took 151145 ms.
[10:18:24.016] INFO: PixTestTiming::TimingTest() done.
[10:18:24.016] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//tbmParameters_C0a.dat
[10:18:24.016] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:18:24.016] INFO: PixTestTiming::doTest took 616955 ms.
[10:18:24.016] INFO: PixTestTiming::doTest() done
[10:18:24.016] INFO: Write out TBMPhaseScan_0_V0
[10:18:24.016] INFO: Write out TBMPhaseScan_1_V0
[10:18:24.016] INFO: Write out CombinedTBMPhaseScan_V0
[10:18:24.050] INFO: Write out ROCDelayScan3_V0
[10:18:24.051] INFO: enter test to run
[10:20:28.519] INFO: test: PixelAlive no parameter change
[10:20:28.519] INFO: running: pixelalive
[10:20:28.523] INFO: ----------------------------------------------------------------------
[10:20:28.523] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:20:28.524] INFO: ----------------------------------------------------------------------
[10:20:28.837] INFO: Expecting 41600 events.
[10:20:32.954] INFO: 41600 events read in total (3401ms).
[10:20:32.954] INFO: Test took 4428ms.
[10:20:32.961] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:33.363] INFO: PixTestAlive::aliveTest() done
[10:20:33.363] INFO: number of dead pixels (per ROC): 4 0 26 0 2 0 0 1 0 0 0 1 0 0 0 0
[10:20:33.365] INFO: enter test to run
[10:21:00.279] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:21:00.279] INFO: running: highrate
[10:21:00.280] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:21:00.542] INFO: ----------------------------------------------------------------------
[10:21:00.543] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:21:00.543] INFO: ----------------------------------------------------------------------
[10:21:00.543] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:21:00.543] INFO: edge/corner pixel THR is adjusted
[10:21:00.543] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:21:01.517] INFO: Collecting data for 5 seconds...
[10:21:06.534] INFO: Done with hot pixel readout
[10:21:18.519] INFO: PixTest:: pg_setup set to default.
[10:21:18.520] INFO: 33 hot pixels found in step 0
[10:21:19.515] INFO: Collecting data for 5 seconds...
[10:21:24.532] INFO: Done with hot pixel readout
[10:21:36.592] INFO: PixTest:: pg_setup set to default.

[10:21:36.593] INFO: 27 hot pixels found in step 1
[10:21:37.587] INFO: Collecting data for 5 seconds...
[10:21:42.604] INFO: Done with hot pixel readout
[10:21:54.638] INFO: PixTest:: pg_setup set to default.

[10:21:54.639] INFO: 26 hot pixels found in step 2
[10:21:55.633] INFO: Collecting data for 5 seconds...
[10:22:00.650] INFO: Done with hot pixel readout
[10:22:12.699] INFO: PixTest:: pg_setup set to default.

[10:22:12.700] INFO: 28 hot pixels found in step 3
[10:22:13.695] INFO: Collecting data for 5 seconds...
[10:22:18.712] INFO: Done with hot pixel readout
[10:22:30.754] INFO: PixTest:: pg_setup set to default.


[10:22:30.755] INFO: 14 hot pixels found in step 4
[10:22:31.750] INFO: Collecting data for 5 seconds...
[10:22:36.766] INFO: Done with hot pixel readout
[10:22:48.756] INFO: PixTest:: pg_setup set to default.

[10:22:48.757] INFO: 24 hot pixels found in step 5
[10:22:49.751] INFO: Collecting data for 5 seconds...
[10:22:54.768] INFO: Done with hot pixel readout
[10:23:06.818] INFO: PixTest:: pg_setup set to default.

[10:23:06.819] INFO: 24 hot pixels found in step 6
[10:23:07.813] INFO: Collecting data for 5 seconds...
[10:23:12.829] INFO: Done with hot pixel readout
[10:23:24.877] INFO: PixTest:: pg_setup set to default.


[10:23:24.878] INFO: 24 hot pixels found in step 7
[10:23:25.872] INFO: Collecting data for 5 seconds...
[10:23:30.889] INFO: Done with hot pixel readout
[10:23:42.971] INFO: PixTest:: pg_setup set to default.

[10:23:42.972] INFO: 19 hot pixels found in step 8
[10:23:43.965] INFO: Collecting data for 5 seconds...
[10:23:48.982] INFO: Done with hot pixel readout
[10:24:01.039] INFO: PixTest:: pg_setup set to default.


[10:24:01.040] INFO: 17 hot pixels found in step 9
[10:24:02.035] INFO: Collecting data for 5 seconds...
[10:24:07.051] INFO: Done with hot pixel readout
[10:24:19.060] INFO: PixTest:: pg_setup set to default.


[10:24:19.061] INFO: 21 hot pixels found in step 10
[10:24:20.056] INFO: Collecting data for 5 seconds...
[10:24:25.073] INFO: Done with hot pixel readout
[10:24:37.140] INFO: PixTest:: pg_setup set to default.





[10:24:37.141] INFO: 25 hot pixels found in step 11
[10:24:38.135] INFO: Collecting data for 5 seconds...
[10:24:43.151] INFO: Done with hot pixel readout
[10:24:55.142] INFO: PixTest:: pg_setup set to default.

[10:24:55.143] INFO: 17 hot pixels found in step 12
[10:24:56.137] INFO: Collecting data for 5 seconds...
[10:25:01.154] INFO: Done with hot pixel readout
[10:25:13.188] INFO: PixTest:: pg_setup set to default.


[10:25:13.189] INFO: 22 hot pixels found in step 13
[10:25:14.184] INFO: Collecting data for 5 seconds...
[10:25:19.200] INFO: Done with hot pixel readout
[10:25:31.294] INFO: PixTest:: pg_setup set to default.


[10:25:31.295] INFO: 15 hot pixels found in step 14
[10:25:31.333] INFO: 15 hot pixels could not be trimmed and have been masked.
[10:25:31.336] INFO: PixTest::trimHotPixels() done
[10:25:31.337] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C0.dat
[10:25:31.343] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C1.dat
[10:25:31.376] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C2.dat
[10:25:31.387] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C3.dat
[10:25:31.392] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C4.dat
[10:25:31.398] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C5.dat
[10:25:31.403] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C6.dat
[10:25:31.408] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C7.dat
[10:25:31.413] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C8.dat
[10:25:31.419] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C9.dat
[10:25:31.424] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C10.dat
[10:25:31.429] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C11.dat
[10:25:31.435] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C12.dat
[10:25:31.440] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C13.dat
[10:25:31.445] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C14.dat
[10:25:31.451] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C15.dat
[10:25:31.456] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//defaultMaskFile.dat
[10:25:31.466] INFO: enter test to run
[10:26:59.221] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:26:59.221] INFO: running: highrate
[10:26:59.225] INFO: ----------------------------------------------------------------------
[10:26:59.225] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:26:59.225] INFO: ----------------------------------------------------------------------
[10:26:59.225] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:26:59.225] INFO: edge/corner pixel THR is adjusted
[10:26:59.225] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:27:00.183] INFO: Collecting data for 1 seconds...
[10:27:01.187] INFO: Done with hot pixel readout
[10:27:05.341] INFO: PixTest:: pg_setup set to default.
[10:27:05.342] INFO: 0 hot pixels found in step 0
[10:27:05.347] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:27:05.435] INFO: PixTest::trimHotPixels() done
[10:27:05.435] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C0.dat
[10:27:05.444] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C1.dat
[10:27:05.449] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C2.dat
[10:27:05.455] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C3.dat
[10:27:05.460] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C4.dat
[10:27:05.465] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C5.dat
[10:27:05.470] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C6.dat
[10:27:05.476] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C7.dat
[10:27:05.481] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C8.dat
[10:27:05.486] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C9.dat
[10:27:05.492] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C10.dat
[10:27:05.497] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C11.dat
[10:27:05.502] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C12.dat
[10:27:05.508] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C13.dat
[10:27:05.513] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C14.dat
[10:27:05.518] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//trimParameters35_C15.dat
[10:27:05.524] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-3-22_FPIXTest-17C-FNAL-160407-1223_2016-04-07_12h23m_1460049836/000_FPIXTest_p17//defaultMaskFile.dat
[10:27:05.533] INFO: enter test to run
[10:27:49.588] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:27:49.588] INFO: running: xray
[10:27:49.590] INFO: ----------------------------------------------------------------------
[10:27:49.590] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:27:49.590] INFO: ----------------------------------------------------------------------
[10:27:50.566] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:28:01.748] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:28:31.204] INFO: Resuming triggers.
[10:28:42.389] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[10:29:11.881] INFO: Resuming triggers.
[10:29:23.061] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[10:29:52.554] INFO: Resuming triggers.
[10:30:03.732] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[10:30:32.680] INFO: Resuming triggers.
[10:30:43.863] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[10:31:13.270] INFO: Resuming triggers.
[10:31:24.452] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[10:31:53.908] INFO: Resuming triggers.
[10:32:05.091] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[10:32:34.510] INFO: Resuming triggers.
[10:32:45.688] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[10:33:15.133] INFO: Resuming triggers.
[10:33:25.995] INFO: data taking finished, elapsed time: 100 seconds.
[10:33:54.855] INFO: PixTest:: pg_setup set to default.
[10:33:54.858] INFO: PixTestXray::doPhRun() done
[10:33:55.022] INFO: enter test to run
[10:34:18.025] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:34:18.026] INFO: running: xray
[10:34:18.027] INFO: ----------------------------------------------------------------------
[10:34:18.027] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:34:18.027] INFO: ----------------------------------------------------------------------
[10:34:19.011] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:34:25.341] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:34:55.386] INFO: Resuming triggers.
[10:35:01.718] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[10:35:31.704] INFO: Resuming triggers.
[10:35:38.039] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[10:36:08.033] INFO: Resuming triggers.
[10:36:14.366] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[10:36:44.447] INFO: Resuming triggers.
[10:36:50.783] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[10:37:20.816] INFO: Resuming triggers.
[10:37:27.155] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[10:37:57.247] INFO: Resuming triggers.
[10:38:03.586] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[10:38:33.659] INFO: Resuming triggers.
[10:38:39.997] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[10:39:10.011] INFO: Resuming triggers.
[10:39:16.353] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[10:39:46.342] INFO: Resuming triggers.
[10:39:52.678] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[10:40:22.707] INFO: Resuming triggers.
[10:40:29.044] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:40:55.065] INFO: Resuming triggers.
[10:41:01.400] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[10:41:31.435] INFO: Resuming triggers.
[10:41:37.773] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[10:42:07.810] INFO: Resuming triggers.
[10:42:14.145] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[10:42:44.187] INFO: Resuming triggers.
[10:42:50.523] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[10:43:20.590] INFO: Resuming triggers.
[10:43:25.884] INFO: data taking finished, elapsed time: 100 seconds.
[10:43:51.069] INFO: PixTest:: pg_setup set to default.
[10:43:51.072] INFO: PixTestXray::doPhRun() done
[10:43:51.221] INFO: enter test to run
[10:44:35.773] INFO: test: HighRate no parameter change
[10:44:35.773] INFO: running: highrate
[10:44:35.774] INFO: ----------------------------------------------------------------------
[10:44:35.774] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:44:35.774] INFO: ----------------------------------------------------------------------
[10:44:35.915] INFO: Expecting 768 events.
[10:44:37.049] INFO: 768 events read in total (419ms).
[10:44:37.058] INFO: Test took 1277ms.
[10:44:37.852] INFO: Expecting 41600 events.
[10:44:40.961] INFO: 41600 events read in total (2582ms).
[10:44:40.962] INFO: Test took 3896ms.
[10:44:40.997] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:41.724] INFO: Expecting 41600 events.
[10:44:44.955] INFO: 41600 events read in total (2704ms).
[10:44:44.956] INFO: Test took 3941ms.
[10:44:44.992] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:45.711] INFO: Expecting 41600 events.
[10:44:48.965] INFO: 41600 events read in total (2727ms).
[10:44:48.966] INFO: Test took 3954ms.
[10:44:48.002] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:49.722] INFO: Expecting 41600 events.
[10:44:52.995] INFO: 41600 events read in total (2746ms).
[10:44:52.996] INFO: Test took 3976ms.
[10:44:53.033] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:53.751] INFO: Expecting 41600 events.
[10:44:57.006] INFO: 41600 events read in total (2729ms).
[10:44:57.007] INFO: Test took 3955ms.
[10:44:57.044] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:57.765] INFO: Expecting 41600 events.
[10:45:01.016] INFO: 41600 events read in total (2724ms).
[10:45:01.017] INFO: Test took 3954ms.
[10:45:01.053] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:01.775] INFO: Expecting 41600 events.
[10:45:05.045] INFO: 41600 events read in total (2744ms).
[10:45:05.046] INFO: Test took 3975ms.
[10:45:05.083] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:05.800] INFO: Expecting 41600 events.
[10:45:09.069] INFO: 41600 events read in total (2742ms).
[10:45:09.070] INFO: Test took 3969ms.
[10:45:09.105] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:09.827] INFO: Expecting 41600 events.
[10:45:13.087] INFO: 41600 events read in total (2733ms).
[10:45:13.088] INFO: Test took 3964ms.
[10:45:13.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:13.845] INFO: Expecting 41600 events.
[10:45:17.120] INFO: 41600 events read in total (2749ms).
[10:45:17.121] INFO: Test took 3977ms.
[10:45:17.157] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:17.877] INFO: Expecting 41600 events.
[10:45:21.150] INFO: 41600 events read in total (2746ms).
[10:45:21.151] INFO: Test took 3974ms.
[10:45:21.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:21.909] INFO: Expecting 41600 events.
[10:45:25.171] INFO: 41600 events read in total (2735ms).
[10:45:25.172] INFO: Test took 3966ms.
[10:45:25.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:25.930] INFO: Expecting 41600 events.
[10:45:29.213] INFO: 41600 events read in total (2756ms).
[10:45:29.214] INFO: Test took 3986ms.
[10:45:29.251] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:29.970] INFO: Expecting 41600 events.
[10:45:33.248] INFO: 41600 events read in total (2751ms).
[10:45:33.249] INFO: Test took 3978ms.
[10:45:33.286] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:34.006] INFO: Expecting 41600 events.
[10:45:37.277] INFO: 41600 events read in total (2744ms).
[10:45:37.278] INFO: Test took 3973ms.
[10:45:37.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:38.033] INFO: Expecting 41600 events.
[10:45:41.311] INFO: 41600 events read in total (2751ms).
[10:45:41.312] INFO: Test took 3978ms.
[10:45:41.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:42.069] INFO: Expecting 41600 events.
[10:45:45.342] INFO: 41600 events read in total (2746ms).
[10:45:45.343] INFO: Test took 3975ms.
[10:45:45.379] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:46.100] INFO: Expecting 41600 events.
[10:45:49.372] INFO: 41600 events read in total (2746ms).
[10:45:49.373] INFO: Test took 3976ms.
[10:45:49.409] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:50.127] INFO: Expecting 41600 events.
[10:45:53.394] INFO: 41600 events read in total (2740ms).
[10:45:53.395] INFO: Test took 3966ms.
[10:45:53.431] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:54.151] INFO: Expecting 41600 events.
[10:45:57.314] INFO: 41600 events read in total (2636ms).
[10:45:57.315] INFO: Test took 3866ms.
[10:45:57.351] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:57.702] INFO: enter test to run
[10:46:31.908] INFO: test: HighRate no parameter change
[10:46:31.908] INFO: running: highrate
[10:46:31.909] INFO: ----------------------------------------------------------------------
[10:46:31.909] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:46:31.909] INFO: ----------------------------------------------------------------------
[10:46:32.529] INFO: Expecting 208000 events.
[10:46:44.541] INFO: 208000 events read in total (11485ms).
[10:46:44.544] INFO: Test took 12626ms.
[10:46:44.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:44.955] INFO: number of dead pixels (per ROC): 3 0 26 0 2 0 0 1 0 0 0 1 0 0 0 0
[10:46:44.955] INFO: number of red-efficiency pixels: 71 53 114 165 187 145 186 110 102 137 136 104 106 59 26 31
[10:46:44.955] INFO: number of X-ray hits detected: 71336 48241 72907 117669 123464 127356 127880 93785 82503 106111 101231 92150 91517 54565 24813 27687
[10:46:44.955] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:46:44.955] INFO: number of Vcal hits detected: 207733 207945 206610 207835 207711 207850 207810 207838 207897 207860 207863 207847 207892 207938 207974 207968
[10:46:44.955] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[10:46:44.955] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.3 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[10:46:44.955] INFO: X-ray hit rate [MHz/cm2]: 20.9 14.1 21.4 34.5 36.2 37.3 37.5 27.5 24.2 31.1 29.7 27.0 26.8 16.0 7.3 8.1
[10:46:44.955] INFO: PixTestHighRate::doXPixelAlive() done
[10:46:44.003] INFO: PixTest:: pg_setup set to default.
[10:46:45.018] INFO: enter test to run
[10:47:08.844] INFO: test: HighRate no parameter change
[10:47:08.844] INFO: running: highrate
[10:47:08.845] INFO: ----------------------------------------------------------------------
[10:47:08.845] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:47:08.845] INFO: ----------------------------------------------------------------------
[10:47:09.459] INFO: Expecting 208000 events.
[10:47:23.395] INFO: 208000 events read in total (13409ms).
[10:47:23.401] INFO: Test took 14545ms.
[10:47:23.712] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:47:24.019] INFO: number of dead pixels (per ROC): 3 0 26 0 2 0 0 1 0 0 0 1 0 0 0 0
[10:47:24.019] INFO: number of red-efficiency pixels: 263 135 331 578 596 674 662 296 290 479 439 271 253 201 55 70
[10:47:24.019] INFO: number of X-ray hits detected: 145504 98480 147353 239904 250971 259909 260330 190622 169879 216466 207955 187558 185985 112615 50377 56917
[10:47:24.019] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:47:24.019] INFO: number of Vcal hits detected: 207525 207857 206368 207362 207239 207221 207231 207636 207697 207476 207522 207665 207737 207786 207941 207929
[10:47:24.019] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.7 99.7 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[10:47:24.019] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.2 99.7 99.6 99.6 99.6 99.8 99.9 99.7 99.8 99.8 99.9 99.9 100.0 100.0
[10:47:24.019] INFO: X-ray hit rate [MHz/cm2]: 42.6 28.9 43.2 70.3 73.6 76.2 76.3 55.9 49.8 63.4 61.0 55.0 54.5 33.0 14.8 16.7
[10:47:24.019] INFO: PixTestHighRate::doXPixelAlive() done
[10:47:24.066] INFO: PixTest:: pg_setup set to default.
[10:47:24.081] INFO: enter test to run
[10:47:47.844] INFO: test: HighRate no parameter change
[10:47:47.844] INFO: running: highrate
[10:47:47.845] INFO: ----------------------------------------------------------------------
[10:47:47.845] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:47:47.845] INFO: ----------------------------------------------------------------------
[10:47:48.464] INFO: Expecting 208000 events.
[10:48:04.564] INFO: 208000 events read in total (15573ms).
[10:48:04.572] INFO: Test took 16719ms.
[10:48:05.077] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:48:05.440] INFO: number of dead pixels (per ROC): 3 0 26 0 2 0 0 1 0 0 0 1 0 0 0 0
[10:48:05.440] INFO: number of red-efficiency pixels: 600 350 710 1419 1477 1610 1597 734 690 1139 1077 629 633 463 78 95
[10:48:05.440] INFO: number of X-ray hits detected: 223542 151685 226464 368211 385087 398982 401325 294784 261421 333268 318424 289070 286491 173536 78007 88484
[10:48:05.440] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:48:05.440] INFO: number of Vcal hits detected: 207073 207612 205753 206064 205859 205690 205666 207058 207203 206576 206641 207237 207281 207437 207918 207902
[10:48:05.440] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.2 99.1 99.0 99.0 99.6 99.7 99.4 99.4 99.7 99.7 99.8 100.0 100.0
[10:48:05.440] INFO: Vcal hit overall efficiency (%): 99.6 99.8 98.9 99.1 99.0 98.9 98.9 99.5 99.6 99.3 99.3 99.6 99.7 99.7 100.0 100.0
[10:48:05.440] INFO: X-ray hit rate [MHz/cm2]: 65.5 44.5 66.4 107.9 112.9 116.9 117.6 86.4 76.6 97.7 93.3 84.7 84.0 50.9 22.9 25.9
[10:48:05.440] INFO: PixTestHighRate::doXPixelAlive() done
[10:48:05.491] INFO: PixTest:: pg_setup set to default.
[10:48:05.506] INFO: enter test to run
[10:48:15.723] INFO: test: exit no parameter change
[10:48:16.189] QUIET: Connection to board 33 closed.
[10:48:16.190] INFO: pXar: this is the end, my friend