[11:53:12.642] INFO: *** Welcome to pxar ***
[11:53:12.642] INFO: *** Today: 2016/07/07
[11:53:13.583] INFO: *** Version: v1.9.0-814-g7497
[11:53:13.606] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//dacParameters35_C15.dat
[11:53:13.688] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:53:13.688] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//defaultMaskFile.dat
[11:53:13.688] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C15.dat
[11:53:13.813] INFO: clk: 4
[11:53:13.813] INFO: ctr: 4
[11:53:13.813] INFO: sda: 19
[11:53:13.813] INFO: tin: 9
[11:53:13.813] INFO: level: 15
[11:53:13.813] INFO: triggerdelay: 0
[11:53:13.813] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:53:13.813] INFO: Log level: INFO
[11:53:13.829] QUIET: Connection to board DTB_WREKRL opened.
[11:53:13.832] 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:
------------------------------------------------------
[11:53:13.835] INFO: RPC call hashes of host and DTB match: 398089610
[11:53:15.383] INFO: DUT info:
[11:53:15.383] INFO: The DUT currently contains the following objects:
[11:53:15.383] INFO: 2 TBM Cores tbm08c (2 ON)
[11:53:15.383] INFO: TBM Core alpha (0): 7 registers set
[11:53:15.383] INFO: TBM Core beta (1): 7 registers set
[11:53:15.383] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:53:15.383] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.383] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.383] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.383] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.383] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.383] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.383] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.383] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.384] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.384] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.384] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.384] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.384] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.384] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.384] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.384] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:53:15.849] INFO: enter 'restricted' command line mode
[11:53:15.850] INFO: enter test to run
[11:53:21.812] INFO: test: PixelAlive no parameter change
[11:53:21.812] INFO: running: pixelalive
[11:53:21.878] INFO: ----------------------------------------------------------------------
[11:53:21.878] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:53:21.878] INFO: ----------------------------------------------------------------------
[11:53:22.202] INFO: Expecting 41600 events.









[11:53:26.559] INFO: 41600 events read in total (3639ms).
[11:53:26.725] INFO: Test took 4844ms.
[11:53:26.736] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:27.272] INFO: PixTestAlive::aliveTest() done with 3 decoding errors
[11:53:27.272] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:53:27.431] INFO: enter test to run
[11:53:41.668] INFO: test: timing no parameter change
[11:53:41.668] INFO: running: timing
[11:53:41.671] INFO: ######################################################################
[11:53:41.671] INFO: PixTestTiming::doTest()
[11:53:41.671] INFO: ######################################################################
[11:53:41.671] INFO: ----------------------------------------------------------------------
[11:53:41.671] INFO: PixTestTiming::TBMPhaseScan()
[11:53:41.671] INFO: ----------------------------------------------------------------------
[11:58:08.966] INFO: TBM Phase Settings: 236
[11:58:08.966] INFO: 400MHz Phase: 3
[11:58:08.966] INFO: 160MHz Phase: 7
[11:58:08.966] INFO: Functional Phase Area: 4
[11:58:08.984] INFO: Test took 267313 ms.
[11:58:08.984] INFO: PixTestTiming::TBMPhaseScan() done.
[11:58:08.984] INFO: ----------------------------------------------------------------------
[11:58:08.984] INFO: PixTestTiming::ROCDelayScan()
[11:58:08.984] INFO: ----------------------------------------------------------------------
[12:00:11.628] INFO: ROC Delay Settings: 228
[12:00:11.628] INFO: ROC Header-Trailer/Token Delay: 11
[12:00:11.628] INFO: ROC Port 0 Delay: 4
[12:00:11.628] INFO: ROC Port 1 Delay: 4
[12:00:11.628] INFO: Functional ROC Area: 5
[12:00:11.632] INFO: Test took 122648 ms.
[12:00:11.632] INFO: PixTestTiming::ROCDelayScan() done.
[12:00:11.632] INFO: ----------------------------------------------------------------------
[12:00:11.632] INFO: PixTestTiming::TimingTest()
[12:00:11.632] INFO: ----------------------------------------------------------------------
[12:00:27.781] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:42.775] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:57.763] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:12.761] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:27.798] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:42.802] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:57.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:12.797] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:27.788] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:42.766] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:43.147] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:43.166] INFO: ----------------------------------------------------------------------
[12:02:43.166] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:02:43.166] INFO: ----------------------------------------------------------------------
[12:02:43.166] INFO: ----------------------------------------------------------------------
[12:02:43.166] INFO: Read back bit status: 1
[12:02:43.166] INFO: ----------------------------------------------------------------------
[12:02:43.166] INFO: ----------------------------------------------------------------------
[12:02:43.166] INFO: Timings are good!
[12:02:43.166] INFO: ----------------------------------------------------------------------
[12:02:43.166] INFO: Test took 151534 ms.
[12:02:43.166] INFO: PixTestTiming::TimingTest() done.
[12:02:43.166] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:02:43.166] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:02:43.166] INFO: PixTestTiming::doTest took 541498 ms.
[12:02:43.166] INFO: PixTestTiming::doTest() done
[12:02:43.166] INFO: Write out TBMPhaseScan_0_V0
[12:02:43.167] INFO: Write out TBMPhaseScan_1_V0
[12:02:43.167] INFO: Write out CombinedTBMPhaseScan_V0
[12:02:43.168] INFO: Write out ROCDelayScan3_V0
[12:02:43.168] INFO: enter test to run
[12:03:18.784] INFO: test: PixelAlive no parameter change
[12:03:18.784] INFO: running: pixelalive
[12:03:18.788] INFO: ----------------------------------------------------------------------
[12:03:18.788] 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:03:18.788] INFO: ----------------------------------------------------------------------
[12:03:19.108] INFO: Expecting 41600 events.
[12:03:23.453] INFO: 41600 events read in total (3630ms).
[12:03:23.453] INFO: Test took 4661ms.
[12:03:23.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:23.863] INFO: PixTestAlive::aliveTest() done
[12:03:23.863] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:03:23.866] INFO: enter test to run
[12:03:54.712] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:03:54.712] INFO: running: highrate
[12:03:54.723] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:03:55.409] INFO: ----------------------------------------------------------------------
[12:03:55.409] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:03:55.409] INFO: ----------------------------------------------------------------------
[12:03:55.409] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:03:55.409] INFO: edge/corner pixel THR is adjusted
[12:03:55.409] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:03:56.367] INFO: Collecting data for 5 seconds...
[12:04:01.386] INFO: Done with hot pixel readout
[12:04:12.952] INFO: PixTest:: pg_setup set to default.

[12:04:12.953] INFO: 23 hot pixels found in step 0
[12:04:13.947] INFO: Collecting data for 5 seconds...
[12:04:18.964] INFO: Done with hot pixel readout
[12:04:30.463] INFO: PixTest:: pg_setup set to default.
[12:04:30.464] INFO: 26 hot pixels found in step 1
[12:04:31.457] INFO: Collecting data for 5 seconds...
[12:04:36.474] INFO: Done with hot pixel readout
[12:04:47.642] INFO: PixTest:: pg_setup set to default.

[12:04:47.643] INFO: 24 hot pixels found in step 2
[12:04:48.637] INFO: Collecting data for 5 seconds...
[12:04:53.655] INFO: Done with hot pixel readout
[12:05:05.493] INFO: PixTest:: pg_setup set to default.
[12:05:05.494] INFO: 22 hot pixels found in step 3
[12:05:06.488] INFO: Collecting data for 5 seconds...
[12:05:11.506] INFO: Done with hot pixel readout
[12:05:23.191] INFO: PixTest:: pg_setup set to default.
[12:05:23.192] INFO: 12 hot pixels found in step 4
[12:05:24.187] INFO: Collecting data for 5 seconds...
[12:05:29.207] INFO: Done with hot pixel readout
[12:05:40.817] INFO: PixTest:: pg_setup set to default.



[12:05:40.818] INFO: 20 hot pixels found in step 5
[12:05:41.814] INFO: Collecting data for 5 seconds...
[12:05:46.835] INFO: Done with hot pixel readout
[12:05:58.668] INFO: PixTest:: pg_setup set to default.


[12:05:58.669] INFO: 4 hot pixels found in step 6
[12:05:59.665] INFO: Collecting data for 5 seconds...
[12:06:04.682] INFO: Done with hot pixel readout
[12:06:16.349] INFO: PixTest:: pg_setup set to default.


[12:06:16.350] INFO: 18 hot pixels found in step 7
[12:06:17.347] INFO: Collecting data for 5 seconds...
[12:06:22.365] INFO: Done with hot pixel readout
[12:06:33.892] INFO: PixTest:: pg_setup set to default.



[12:06:33.893] INFO: 12 hot pixels found in step 8
[12:06:34.888] INFO: Collecting data for 5 seconds...
[12:06:39.906] INFO: Done with hot pixel readout
[12:06:51.442] INFO: PixTest:: pg_setup set to default.


[12:06:51.443] INFO: 12 hot pixels found in step 9
[12:06:52.438] INFO: Collecting data for 5 seconds...
[12:06:57.456] INFO: Done with hot pixel readout
[12:07:09.163] INFO: PixTest:: pg_setup set to default.


[12:07:09.164] INFO: 18 hot pixels found in step 10
[12:07:10.160] INFO: Collecting data for 5 seconds...
[12:07:15.180] INFO: Done with hot pixel readout
[12:07:27.364] INFO: PixTest:: pg_setup set to default.


[12:07:27.365] INFO: 17 hot pixels found in step 11
[12:07:28.358] INFO: Collecting data for 5 seconds...
[12:07:33.377] INFO: Done with hot pixel readout
[12:07:44.697] INFO: PixTest:: pg_setup set to default.


[12:07:44.698] INFO: 15 hot pixels found in step 12
[12:07:45.693] INFO: Collecting data for 5 seconds...
[12:07:50.712] INFO: Done with hot pixel readout
[12:08:02.817] INFO: PixTest:: pg_setup set to default.


[12:08:02.817] INFO: 11 hot pixels found in step 13
[12:08:03.815] INFO: Collecting data for 5 seconds...
[12:08:08.836] INFO: Done with hot pixel readout
[12:08:20.850] INFO: PixTest:: pg_setup set to default.


[12:08:20.851] INFO: 15 hot pixels found in step 14
[12:08:20.892] INFO: 15 hot pixels could not be trimmed and have been masked.
[12:08:20.895] INFO: PixTest::trimHotPixels() done
[12:08:20.908] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C0.dat
[12:08:20.918] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C1.dat
[12:08:20.924] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C2.dat
[12:08:20.929] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C3.dat
[12:08:20.935] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C4.dat
[12:08:20.940] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C5.dat
[12:08:20.946] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C6.dat
[12:08:20.951] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C7.dat
[12:08:20.957] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C8.dat
[12:08:20.962] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C9.dat
[12:08:20.968] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C10.dat
[12:08:20.973] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C11.dat
[12:08:20.979] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C12.dat
[12:08:20.984] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C13.dat
[12:08:20.989] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C14.dat
[12:08:20.995] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C15.dat
[12:08:20.000] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//defaultMaskFile.dat
[12:08:21.018] INFO: enter test to run
[12:09:20.686] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:09:20.686] INFO: running: highrate
[12:09:20.690] INFO: ----------------------------------------------------------------------
[12:09:20.690] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:09:20.690] INFO: ----------------------------------------------------------------------
[12:09:20.690] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:09:20.690] INFO: edge/corner pixel THR is adjusted
[12:09:20.690] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:09:21.647] INFO: Collecting data for 1 seconds...
[12:09:22.651] INFO: Done with hot pixel readout
[12:09:26.746] INFO: PixTest:: pg_setup set to default.
[12:09:26.747] INFO: 0 hot pixels found in step 0
[12:09:26.753] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:09:26.840] INFO: PixTest::trimHotPixels() done
[12:09:26.841] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C0.dat
[12:09:26.849] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C1.dat
[12:09:26.855] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C2.dat
[12:09:26.860] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C3.dat
[12:09:26.866] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C4.dat
[12:09:26.871] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C5.dat
[12:09:26.876] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C6.dat
[12:09:26.882] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C7.dat
[12:09:26.887] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C8.dat
[12:09:26.892] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C9.dat
[12:09:26.898] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C10.dat
[12:09:26.903] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C11.dat
[12:09:26.909] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C12.dat
[12:09:26.914] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C13.dat
[12:09:26.919] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C14.dat
[12:09:26.924] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C15.dat
[12:09:26.930] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-32_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//defaultMaskFile.dat
[12:09:26.943] INFO: enter test to run
[12:10:54.445] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:10:54.445] INFO: running: xray
[12:10:54.458] INFO: ----------------------------------------------------------------------
[12:10:54.458] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:10:54.458] INFO: ----------------------------------------------------------------------
[12:10:55.454] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:11:06.894] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:11:36.421] INFO: Resuming triggers.
[12:11:47.860] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:12:17.397] INFO: Resuming triggers.
[12:12:28.836] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:12:58.352] INFO: Resuming triggers.
[12:13:09.791] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:13:39.168] INFO: Resuming triggers.
[12:13:50.611] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:14:20.033] INFO: Resuming triggers.
[12:14:31.474] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[12:15:00.833] INFO: Resuming triggers.
[12:15:12.274] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:15:41.753] INFO: Resuming triggers.
[12:15:53.189] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[12:16:22.581] INFO: Resuming triggers.
[12:16:31.401] INFO: data taking finished, elapsed time: 100 seconds.
[12:16:54.268] INFO: PixTest:: pg_setup set to default.
[12:16:54.271] INFO: PixTestXray::doPhRun() done
[12:16:54.490] INFO: enter test to run
[12:17:33.962] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:17:33.962] INFO: running: xray
[12:17:33.964] INFO: ----------------------------------------------------------------------
[12:17:33.964] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:17:33.964] INFO: ----------------------------------------------------------------------
[12:17:34.939] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:17:41.620] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:18:12.567] INFO: Resuming triggers.
[12:18:19.247] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:18:50.067] INFO: Resuming triggers.
[12:18:56.748] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[12:19:28.272] INFO: Resuming triggers.
[12:19:34.955] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:20:06.857] INFO: Resuming triggers.
[12:20:13.540] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:20:44.703] INFO: Resuming triggers.
[12:20:51.385] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[12:21:21.746] INFO: Resuming triggers.
[12:21:28.429] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:21:58.709] INFO: Resuming triggers.
[12:22:05.393] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[12:22:35.624] INFO: Resuming triggers.
[12:22:42.311] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[12:23:12.544] INFO: Resuming triggers.
[12:23:19.228] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[12:23:49.516] INFO: Resuming triggers.
[12:23:56.198] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:24:26.452] INFO: Resuming triggers.
[12:24:33.137] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[12:25:03.519] INFO: Resuming triggers.
[12:25:10.204] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[12:25:40.454] INFO: Resuming triggers.
[12:25:47.134] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:26:17.410] INFO: Resuming triggers.
[12:26:24.090] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[12:26:54.354] INFO: Resuming triggers.
[12:26:54.465] INFO: data taking finished, elapsed time: 100 seconds.
[12:26:55.429] INFO: PixTest:: pg_setup set to default.
[12:26:55.432] INFO: PixTestXray::doPhRun() done
[12:26:55.730] INFO: enter test to run
[12:27:36.396] INFO: test: HighRate no parameter change
[12:27:36.396] INFO: running: highrate
[12:27:36.415] INFO: ----------------------------------------------------------------------
[12:27:36.415] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:27:36.415] INFO: ----------------------------------------------------------------------
[12:27:36.581] INFO: Expecting 768 events.
[12:27:37.717] INFO: 768 events read in total (421ms).
[12:27:37.718] INFO: Test took 1271ms.
[12:27:38.521] INFO: Expecting 41600 events.
[12:27:41.650] INFO: 41600 events read in total (2602ms).
[12:27:41.651] INFO: Test took 3912ms.
[12:27:41.685] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:42.412] INFO: Expecting 41600 events.
[12:27:45.636] INFO: 41600 events read in total (2697ms).
[12:27:45.637] INFO: Test took 3934ms.
[12:27:45.671] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:46.394] INFO: Expecting 41600 events.
[12:27:49.635] INFO: 41600 events read in total (2714ms).
[12:27:49.636] INFO: Test took 3946ms.
[12:27:49.670] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:50.395] INFO: Expecting 41600 events.
[12:27:53.616] INFO: 41600 events read in total (2694ms).
[12:27:53.617] INFO: Test took 3929ms.
[12:27:53.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:54.374] INFO: Expecting 41600 events.
[12:27:57.615] INFO: 41600 events read in total (2714ms).
[12:27:57.616] INFO: Test took 3945ms.
[12:27:57.650] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:58.376] INFO: Expecting 41600 events.
[12:28:01.621] INFO: 41600 events read in total (2718ms).
[12:28:01.622] INFO: Test took 3954ms.
[12:28:01.656] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:02.381] INFO: Expecting 41600 events.
[12:28:05.626] INFO: 41600 events read in total (2718ms).
[12:28:05.627] INFO: Test took 3954ms.
[12:28:05.662] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:06.381] INFO: Expecting 41600 events.
[12:28:09.626] INFO: 41600 events read in total (2718ms).
[12:28:09.627] INFO: Test took 3947ms.
[12:28:09.662] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:10.387] INFO: Expecting 41600 events.
[12:28:13.644] INFO: 41600 events read in total (2730ms).
[12:28:13.645] INFO: Test took 3964ms.
[12:28:13.679] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:14.401] INFO: Expecting 41600 events.
[12:28:17.642] INFO: 41600 events read in total (2715ms).
[12:28:17.643] INFO: Test took 3946ms.
[12:28:17.677] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:18.403] INFO: Expecting 41600 events.
[12:28:21.635] INFO: 41600 events read in total (2705ms).
[12:28:21.636] INFO: Test took 3939ms.
[12:28:21.671] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:22.394] INFO: Expecting 41600 events.
[12:28:25.644] INFO: 41600 events read in total (2723ms).
[12:28:25.645] INFO: Test took 3956ms.
[12:28:25.679] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:26.400] INFO: Expecting 41600 events.
[12:28:29.642] INFO: 41600 events read in total (2715ms).
[12:28:29.643] INFO: Test took 3946ms.
[12:28:29.677] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:30.403] INFO: Expecting 41600 events.
[12:28:33.647] INFO: 41600 events read in total (2718ms).
[12:28:33.648] INFO: Test took 3952ms.
[12:28:33.683] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:34.406] INFO: Expecting 41600 events.
[12:28:37.659] INFO: 41600 events read in total (2726ms).
[12:28:37.660] INFO: Test took 3960ms.
[12:28:37.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:38.419] INFO: Expecting 41600 events.
[12:28:41.665] INFO: 41600 events read in total (2720ms).
[12:28:41.666] INFO: Test took 3953ms.
[12:28:41.700] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:42.423] INFO: Expecting 41600 events.
[12:28:45.671] INFO: 41600 events read in total (2721ms).
[12:28:45.672] INFO: Test took 3954ms.
[12:28:45.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:46.427] INFO: Expecting 41600 events.
[12:28:49.671] INFO: 41600 events read in total (2717ms).
[12:28:49.672] INFO: Test took 3947ms.
[12:28:49.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:50.432] INFO: Expecting 41600 events.
[12:28:53.678] INFO: 41600 events read in total (2719ms).
[12:28:53.679] INFO: Test took 3953ms.
[12:28:53.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:54.439] INFO: Expecting 41600 events.
[12:28:57.553] INFO: 41600 events read in total (2588ms).
[12:28:57.553] INFO: Test took 3820ms.
[12:28:57.587] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:57.950] INFO: enter test to run
[12:29:12.861] INFO: test: HighRate no parameter change
[12:29:12.862] INFO: running: highrate
[12:29:12.863] INFO: ----------------------------------------------------------------------
[12:29:12.863] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:29:12.863] INFO: ----------------------------------------------------------------------
[12:29:13.480] INFO: Expecting 208000 events.
[12:29:25.359] INFO: 208000 events read in total (11352ms).
[12:29:25.362] INFO: Test took 12489ms.
[12:29:25.511] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:25.766] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:29:25.766] INFO: number of red-efficiency pixels: 75 61 89 126 166 143 160 108 99 114 109 97 75 59 23 34
[12:29:25.766] INFO: number of X-ray hits detected: 66479 42317 69980 107534 117874 120316 118638 84409 87940 96275 91123 80366 84232 49605 19497 24584
[12:29:25.766] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:29:25.766] INFO: number of Vcal hits detected: 207823 207939 207907 207869 207832 207853 207835 207862 207900 207885 207887 207902 207923 207938 207977 207966
[12:29:25.766] 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
[12:29:25.766] INFO: Vcal hit overall efficiency (%): 99.9 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
[12:29:25.766] INFO: X-ray hit rate [MHz/cm2]: 19.5 12.4 20.5 31.5 34.5 35.3 34.8 24.7 25.8 28.2 26.7 23.6 24.7 14.5 5.7 7.2
[12:29:25.766] INFO: PixTestHighRate::doXPixelAlive() done
[12:29:25.812] INFO: PixTest:: pg_setup set to default.
[12:29:25.827] INFO: enter test to run
[12:29:57.565] INFO: test: HighRate no parameter change
[12:29:57.565] INFO: running: highrate
[12:29:57.566] INFO: ----------------------------------------------------------------------
[12:29:57.566] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:29:57.566] INFO: ----------------------------------------------------------------------
[12:29:58.187] INFO: Expecting 208000 events.
[12:30:11.877] INFO: 208000 events read in total (13163ms).
[12:30:11.882] INFO: Test took 14307ms.
[12:30:12.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:12.485] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:30:12.485] INFO: number of red-efficiency pixels: 223 107 274 508 554 521 605 285 291 425 345 297 261 174 54 68
[12:30:12.485] INFO: number of X-ray hits detected: 136260 87959 144038 220944 240781 246918 243652 174027 181250 198632 187722 166146 173356 101734 40994 51008
[12:30:12.485] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:30:12.485] INFO: number of Vcal hits detected: 207665 207885 207696 207448 207394 207423 207334 207666 207686 207535 207637 207682 207727 207818 207946 207930
[12:30:12.485] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[12:30:12.485] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.9 99.7 99.7 99.7 99.7 99.8 99.8 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[12:30:12.485] INFO: X-ray hit rate [MHz/cm2]: 39.9 25.8 42.2 64.8 70.6 72.4 71.4 51.0 53.1 58.2 55.0 48.7 50.8 29.8 12.0 15.0
[12:30:12.485] INFO: PixTestHighRate::doXPixelAlive() done
[12:30:12.533] INFO: PixTest:: pg_setup set to default.
[12:30:12.553] INFO: enter test to run
[12:30:44.853] INFO: test: HighRate no parameter change
[12:30:44.853] INFO: running: highrate
[12:30:44.854] INFO: ----------------------------------------------------------------------
[12:30:44.854] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:30:44.854] INFO: ----------------------------------------------------------------------
[12:30:45.470] INFO: Expecting 208000 events.
[12:31:00.281] INFO: 208000 events read in total (14284ms).
[12:31:00.288] INFO: Test took 15424ms.
[12:31:00.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:01.077] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:31:01.077] INFO: number of red-efficiency pixels: 446 212 602 1169 1404 1113 1463 642 614 950 803 709 555 359 85 98
[12:31:01.077] INFO: number of X-ray hits detected: 206381 132553 217153 331836 363441 371843 367949 262018 273298 300466 285011 251050 262376 154515 61603 77434
[12:31:01.077] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:31:01.077] INFO: number of Vcal hits detected: 207393 207774 207192 206504 206152 206563 205978 207203 207277 206843 207048 207183 207381 207585 207914 207900
[12:31:01.077] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.2 99.4 99.1 99.6 99.7 99.5 99.6 99.6 99.7 99.8 100.0 100.0
[12:31:01.077] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.3 99.1 99.3 99.0 99.6 99.7 99.4 99.5 99.6 99.7 99.8 100.0 100.0
[12:31:01.077] INFO: X-ray hit rate [MHz/cm2]: 60.5 38.9 63.6 97.3 106.5 109.0 107.8 76.8 80.1 88.1 83.5 73.6 76.9 45.3 18.1 22.7
[12:31:01.078] INFO: PixTestHighRate::doXPixelAlive() done
[12:31:01.123] INFO: PixTest:: pg_setup set to default.
[12:31:01.136] INFO: enter test to run
[12:31:26.780] INFO: test: exit no parameter change
[12:31:27.344] QUIET: Connection to board 33 closed.
[12:31:27.428] INFO: pXar: this is the end, my friend