[16:11:08.006] INFO: *** Welcome to pxar ***
[16:11:08.006] INFO: *** Today: 2016/06/29
[16:11:08.025] INFO: *** Version: v1.9.0-814-g7497
[16:11:08.025] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//dacParameters35_C15.dat
[16:11:08.026] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:11:08.026] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//defaultMaskFile.dat
[16:11:08.026] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C15.dat
[16:11:08.102] INFO: clk: 4
[16:11:08.102] INFO: ctr: 4
[16:11:08.102] INFO: sda: 19
[16:11:08.102] INFO: tin: 9
[16:11:08.102] INFO: level: 15
[16:11:08.103] INFO: triggerdelay: 0
[16:11:08.103] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:11:08.103] INFO: Log level: INFO
[16:11:08.120] QUIET: Connection to board DTB_WREKRL opened.
[16:11:08.124] 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:
------------------------------------------------------
[16:11:08.127] INFO: RPC call hashes of host and DTB match: 398089610
[16:11:09.662] INFO: DUT info:
[16:11:09.662] INFO: The DUT currently contains the following objects:
[16:11:09.662] INFO: 2 TBM Cores tbm08c (2 ON)
[16:11:09.662] INFO: TBM Core alpha (0): 7 registers set
[16:11:09.662] INFO: TBM Core beta (1): 7 registers set
[16:11:09.662] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:11:09.662] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.662] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:09.663] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:11:10.066] INFO: enter 'restricted' command line mode
[16:11:10.066] INFO: enter test to run
[16:11:11.270] INFO: test: timing no parameter change
[16:11:11.270] INFO: running: timing
[16:11:11.293] INFO: ######################################################################
[16:11:11.295] INFO: PixTestTiming::doTest()
[16:11:11.295] INFO: ######################################################################
[16:11:11.295] INFO: ----------------------------------------------------------------------
[16:11:11.295] INFO: PixTestTiming::TBMPhaseScan()
[16:11:11.295] INFO: ----------------------------------------------------------------------
[16:20:34.663] INFO: TBM Phase Settings: 232
[16:20:34.663] INFO: 400MHz Phase: 2
[16:20:34.663] INFO: 160MHz Phase: 7
[16:20:34.663] INFO: Functional Phase Area: 3
[16:20:34.666] INFO: Test took 563371 ms.
[16:20:34.666] INFO: PixTestTiming::TBMPhaseScan() done.
[16:20:34.666] INFO: ----------------------------------------------------------------------
[16:20:34.666] INFO: PixTestTiming::ROCDelayScan()
[16:20:34.666] INFO: ----------------------------------------------------------------------
[16:22:41.633] INFO: ROC Delay Settings: 228
[16:22:41.633] INFO: ROC Header-Trailer/Token Delay: 11
[16:22:41.633] INFO: ROC Port 0 Delay: 4
[16:22:41.633] INFO: ROC Port 1 Delay: 4
[16:22:41.633] INFO: Functional ROC Area: 4
[16:22:41.636] INFO: Test took 126970 ms.
[16:22:41.636] INFO: PixTestTiming::ROCDelayScan() done.
[16:22:41.636] INFO: ----------------------------------------------------------------------
[16:22:41.636] INFO: PixTestTiming::TimingTest()
[16:22:41.637] INFO: ----------------------------------------------------------------------
[16:22:57.769] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:12.748] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:27.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:42.688] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:57.634] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:12.606] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:27.570] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:42.498] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:57.453] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:25:12.393] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:25:12.776] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:25:12.793] INFO: ----------------------------------------------------------------------
[16:25:12.793] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[16:25:12.793] INFO: ----------------------------------------------------------------------
[16:25:12.793] INFO: ----------------------------------------------------------------------
[16:25:12.793] INFO: Read back bit status: 1
[16:25:12.793] INFO: ----------------------------------------------------------------------
[16:25:12.793] INFO: ----------------------------------------------------------------------
[16:25:12.793] INFO: Timings are good!
[16:25:12.793] INFO: ----------------------------------------------------------------------
[16:25:12.793] INFO: Test took 151157 ms.
[16:25:12.793] INFO: PixTestTiming::TimingTest() done.
[16:25:12.793] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//tbmParameters_C0a.dat
[16:25:12.793] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:25:12.794] INFO: PixTestTiming::doTest took 841506 ms.
[16:25:12.794] INFO: PixTestTiming::doTest() done
[16:25:12.794] INFO: Write out TBMPhaseScan_0_V0
[16:25:12.818] INFO: Write out TBMPhaseScan_1_V0
[16:25:12.818] INFO: Write out CombinedTBMPhaseScan_V0
[16:25:12.842] INFO: Write out ROCDelayScan3_V0
[16:25:12.844] INFO: enter test to run
[16:25:26.848] INFO: test: PixelAlive no parameter change
[16:25:26.848] INFO: running: pixelalive
[16:25:26.853] INFO: ----------------------------------------------------------------------
[16:25:26.853] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:25:26.853] INFO: ----------------------------------------------------------------------
[16:25:27.173] INFO: Expecting 41600 events.
[16:25:31.511] INFO: 41600 events read in total (3622ms).
[16:25:31.512] INFO: Test took 4656ms.
[16:25:31.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:25:31.911] INFO: PixTestAlive::aliveTest() done
[16:25:31.911] INFO: number of dead pixels (per ROC): 0 0 0 0 3 0 0 0 0 0 0 0 1 0 0 0
[16:25:31.915] INFO: enter test to run
[16:26:00.192] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:26:00.192] INFO: running: highrate
[16:26:00.192] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:26:00.346] INFO: ----------------------------------------------------------------------
[16:26:00.346] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:26:00.346] INFO: ----------------------------------------------------------------------
[16:26:00.346] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:26:00.346] INFO: edge/corner pixel THR is adjusted
[16:26:00.346] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:26:01.305] INFO: Collecting data for 5 seconds...
[16:26:06.320] INFO: Done with hot pixel readout
[16:26:18.010] INFO: PixTest:: pg_setup set to default.
[16:26:18.010] INFO: 5 hot pixels found in step 0
[16:26:19.004] INFO: Collecting data for 5 seconds...
[16:26:24.021] INFO: Done with hot pixel readout
[16:26:35.732] INFO: PixTest:: pg_setup set to default.
[16:26:35.733] INFO: 6 hot pixels found in step 1
[16:26:36.725] INFO: Collecting data for 5 seconds...
[16:26:41.741] INFO: Done with hot pixel readout
[16:26:53.445] INFO: PixTest:: pg_setup set to default.
[16:26:53.446] INFO: 4 hot pixels found in step 2
[16:26:54.438] INFO: Collecting data for 5 seconds...
[16:26:59.454] INFO: Done with hot pixel readout
[16:27:11.167] INFO: PixTest:: pg_setup set to default.
[16:27:11.168] INFO: 3 hot pixels found in step 3
[16:27:12.161] INFO: Collecting data for 5 seconds...
[16:27:17.177] INFO: Done with hot pixel readout
[16:27:28.901] INFO: PixTest:: pg_setup set to default.

[16:27:28.902] INFO: 6 hot pixels found in step 4
[16:27:29.895] INFO: Collecting data for 5 seconds...
[16:27:34.912] INFO: Done with hot pixel readout
[16:27:46.603] INFO: PixTest:: pg_setup set to default.
[16:27:46.604] INFO: 4 hot pixels found in step 5
[16:27:47.597] INFO: Collecting data for 5 seconds...
[16:27:52.615] INFO: Done with hot pixel readout
[16:28:04.390] INFO: PixTest:: pg_setup set to default.
[16:28:04.390] INFO: 4 hot pixels found in step 6
[16:28:05.383] INFO: Collecting data for 5 seconds...
[16:28:10.402] INFO: Done with hot pixel readout
[16:28:22.187] INFO: PixTest:: pg_setup set to default.
[16:28:22.188] INFO: 3 hot pixels found in step 7
[16:28:23.181] INFO: Collecting data for 5 seconds...
[16:28:28.201] INFO: Done with hot pixel readout
[16:28:39.675] INFO: PixTest:: pg_setup set to default.
[16:28:39.676] INFO: 5 hot pixels found in step 8
[16:28:40.669] INFO: Collecting data for 5 seconds...
[16:28:45.689] INFO: Done with hot pixel readout
[16:28:57.271] INFO: PixTest:: pg_setup set to default.
[16:28:57.272] INFO: 6 hot pixels found in step 9
[16:28:58.265] INFO: Collecting data for 5 seconds...
[16:29:03.283] INFO: Done with hot pixel readout
[16:29:14.676] INFO: PixTest:: pg_setup set to default.
[16:29:14.677] INFO: 8 hot pixels found in step 10
[16:29:15.671] INFO: Collecting data for 5 seconds...
[16:29:20.689] INFO: Done with hot pixel readout
[16:29:32.148] INFO: PixTest:: pg_setup set to default.
[16:29:32.149] INFO: 2 hot pixels found in step 11
[16:29:33.142] INFO: Collecting data for 5 seconds...
[16:29:38.161] INFO: Done with hot pixel readout
[16:29:49.491] INFO: PixTest:: pg_setup set to default.
[16:29:49.492] INFO: 5 hot pixels found in step 12
[16:29:50.486] INFO: Collecting data for 5 seconds...
[16:29:55.504] INFO: Done with hot pixel readout
[16:30:07.133] INFO: PixTest:: pg_setup set to default.
[16:30:07.134] INFO: 5 hot pixels found in step 13
[16:30:08.127] INFO: Collecting data for 5 seconds...
[16:30:13.145] INFO: Done with hot pixel readout
[16:30:24.878] INFO: PixTest:: pg_setup set to default.
[16:30:24.879] INFO: 4 hot pixels found in step 14
[16:30:24.924] INFO: 4 hot pixels could not be trimmed and have been masked.
[16:30:24.927] INFO: PixTest::trimHotPixels() done
[16:30:24.928] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C0.dat
[16:30:24.933] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C1.dat
[16:30:24.940] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C2.dat
[16:30:24.945] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C3.dat
[16:30:24.951] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C4.dat
[16:30:24.956] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C5.dat
[16:30:24.962] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C6.dat
[16:30:24.967] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C7.dat
[16:30:24.973] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C8.dat
[16:30:24.979] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C9.dat
[16:30:24.984] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C10.dat
[16:30:24.989] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C11.dat
[16:30:24.995] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C12.dat
[16:30:24.001] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C13.dat
[16:30:25.007] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C14.dat
[16:30:25.012] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C15.dat
[16:30:25.018] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//defaultMaskFile.dat
[16:30:25.028] INFO: enter test to run
[16:30:52.206] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:30:52.206] INFO: running: highrate
[16:30:52.211] INFO: ----------------------------------------------------------------------
[16:30:52.211] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:30:52.211] INFO: ----------------------------------------------------------------------
[16:30:52.211] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:30:52.211] INFO: edge/corner pixel THR is adjusted
[16:30:52.211] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:30:53.169] INFO: Collecting data for 1 seconds...
[16:30:54.172] INFO: Done with hot pixel readout
[16:30:58.095] INFO: PixTest:: pg_setup set to default.
[16:30:58.096] INFO: 0 hot pixels found in step 0
[16:30:58.102] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:30:58.191] INFO: PixTest::trimHotPixels() done
[16:30:58.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C0.dat
[16:30:58.200] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C1.dat
[16:30:58.207] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C2.dat
[16:30:58.212] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C3.dat
[16:30:58.218] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C4.dat
[16:30:58.224] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C5.dat
[16:30:58.229] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C6.dat
[16:30:58.234] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C7.dat
[16:30:58.240] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C8.dat
[16:30:58.245] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C9.dat
[16:30:58.251] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C10.dat
[16:30:58.257] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C11.dat
[16:30:58.262] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C12.dat
[16:30:58.268] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C13.dat
[16:30:58.273] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C14.dat
[16:30:58.278] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//trimParameters35_C15.dat
[16:30:58.285] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-08_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17//defaultMaskFile.dat
[16:30:58.294] INFO: enter test to run
[16:31:20.334] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:31:20.334] INFO: running: xray
[16:31:20.335] INFO: ----------------------------------------------------------------------
[16:31:20.335] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:31:20.335] INFO: ----------------------------------------------------------------------
[16:31:21.299] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:31:32.844] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:32:02.482] INFO: Resuming triggers.
[16:32:14.027] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[16:32:43.543] INFO: Resuming triggers.
[16:32:55.094] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[16:33:24.501] INFO: Resuming triggers.
[16:33:36.046] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[16:34:05.470] INFO: Resuming triggers.
[16:34:17.017] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[16:34:46.433] INFO: Resuming triggers.
[16:34:57.979] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[16:35:27.364] INFO: Resuming triggers.
[16:35:38.911] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[16:36:08.342] INFO: Resuming triggers.
[16:36:19.886] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[16:36:49.317] INFO: Resuming triggers.
[16:36:57.277] INFO: data taking finished, elapsed time: 100 seconds.
[16:37:17.701] INFO: PixTest:: pg_setup set to default.
[16:37:17.704] INFO: PixTestXray::doPhRun() done
[16:37:17.839] INFO: enter test to run
[16:37:50.667] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:37:50.667] INFO: running: xray
[16:37:50.668] INFO: ----------------------------------------------------------------------
[16:37:50.668] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:37:50.668] INFO: ----------------------------------------------------------------------
[16:37:51.632] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:37:58.486] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:38:28.628] INFO: Resuming triggers.
[16:38:35.481] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[16:39:05.456] INFO: Resuming triggers.
[16:39:12.310] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[16:39:42.348] INFO: Resuming triggers.
[16:39:49.202] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[16:40:20.060] INFO: Resuming triggers.
[16:40:26.914] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[16:40:57.323] INFO: Resuming triggers.
[16:41:04.176] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[16:41:35.432] INFO: Resuming triggers.
[16:41:42.289] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[16:42:13.600] INFO: Resuming triggers.
[16:42:20.456] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[16:42:51.903] INFO: Resuming triggers.
[16:42:58.757] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[16:43:29.500] INFO: Resuming triggers.
[16:43:36.357] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[16:44:06.497] INFO: Resuming triggers.
[16:44:13.351] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[16:44:43.457] INFO: Resuming triggers.
[16:44:50.310] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[16:45:20.468] INFO: Resuming triggers.
[16:45:27.326] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[16:45:57.449] INFO: Resuming triggers.
[16:46:04.305] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[16:46:34.393] INFO: Resuming triggers.
[16:46:38.767] INFO: data taking finished, elapsed time: 100 seconds.
[16:46:58.332] INFO: PixTest:: pg_setup set to default.
[16:46:58.336] INFO: PixTestXray::doPhRun() done
[16:46:58.482] INFO: enter test to run
[16:47:31.728] INFO: test: HighRate no parameter change
[16:47:31.728] INFO: running: highrate
[16:47:31.738] INFO: ----------------------------------------------------------------------
[16:47:31.738] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:47:31.738] INFO: ----------------------------------------------------------------------
[16:47:31.894] INFO: Expecting 768 events.
[16:47:33.028] INFO: 768 events read in total (418ms).
[16:47:33.029] INFO: Test took 1269ms.
[16:47:33.832] INFO: Expecting 41600 events.
[16:47:36.875] INFO: 41600 events read in total (2516ms).
[16:47:36.876] INFO: Test took 3840ms.
[16:47:36.909] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:47:37.640] INFO: Expecting 41600 events.
[16:47:40.833] INFO: 41600 events read in total (2666ms).
[16:47:40.834] INFO: Test took 3908ms.
[16:47:40.867] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:47:41.594] INFO: Expecting 41600 events.
[16:47:44.817] INFO: 41600 events read in total (2697ms).
[16:47:44.818] INFO: Test took 3934ms.
[16:47:44.853] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:47:45.574] INFO: Expecting 41600 events.
[16:47:48.805] INFO: 41600 events read in total (2704ms).
[16:47:48.806] INFO: Test took 3935ms.
[16:47:48.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:47:49.566] INFO: Expecting 41600 events.
[16:47:52.790] INFO: 41600 events read in total (2697ms).
[16:47:52.791] INFO: Test took 3933ms.
[16:47:52.825] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:47:53.551] INFO: Expecting 41600 events.
[16:47:56.808] INFO: 41600 events read in total (2730ms).
[16:47:56.809] INFO: Test took 3965ms.
[16:47:56.843] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:47:57.567] INFO: Expecting 41600 events.
[16:48:00.825] INFO: 41600 events read in total (2731ms).
[16:48:00.826] INFO: Test took 3965ms.
[16:48:00.860] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:01.581] INFO: Expecting 41600 events.
[16:48:04.835] INFO: 41600 events read in total (2727ms).
[16:48:04.835] INFO: Test took 3958ms.
[16:48:04.869] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:05.593] INFO: Expecting 41600 events.
[16:48:08.843] INFO: 41600 events read in total (2723ms).
[16:48:08.844] INFO: Test took 3958ms.
[16:48:08.878] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:09.602] INFO: Expecting 41600 events.
[16:48:12.840] INFO: 41600 events read in total (2711ms).
[16:48:12.841] INFO: Test took 3945ms.
[16:48:12.875] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:13.599] INFO: Expecting 41600 events.
[16:48:16.822] INFO: 41600 events read in total (2696ms).
[16:48:16.823] INFO: Test took 3931ms.
[16:48:16.856] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:17.579] INFO: Expecting 41600 events.
[16:48:20.818] INFO: 41600 events read in total (2712ms).
[16:48:20.819] INFO: Test took 3944ms.
[16:48:20.853] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:21.575] INFO: Expecting 41600 events.
[16:48:24.826] INFO: 41600 events read in total (2724ms).
[16:48:24.827] INFO: Test took 3955ms.
[16:48:24.862] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:25.583] INFO: Expecting 41600 events.
[16:48:28.824] INFO: 41600 events read in total (2713ms).
[16:48:28.825] INFO: Test took 3945ms.
[16:48:28.859] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:29.583] INFO: Expecting 41600 events.
[16:48:32.820] INFO: 41600 events read in total (2710ms).
[16:48:32.821] INFO: Test took 3944ms.
[16:48:32.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:33.579] INFO: Expecting 41600 events.
[16:48:36.815] INFO: 41600 events read in total (2709ms).
[16:48:36.816] INFO: Test took 3944ms.
[16:48:36.849] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:37.574] INFO: Expecting 41600 events.
[16:48:40.799] INFO: 41600 events read in total (2699ms).
[16:48:40.799] INFO: Test took 3931ms.
[16:48:40.833] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:41.556] INFO: Expecting 41600 events.
[16:48:44.785] INFO: 41600 events read in total (2702ms).
[16:48:44.786] INFO: Test took 3935ms.
[16:48:44.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:45.544] INFO: Expecting 41600 events.
[16:48:48.789] INFO: 41600 events read in total (2718ms).
[16:48:48.790] INFO: Test took 3951ms.
[16:48:48.824] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:49.546] INFO: Expecting 41600 events.
[16:48:52.678] INFO: 41600 events read in total (2605ms).
[16:48:52.679] INFO: Test took 3836ms.
[16:48:52.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:53.075] INFO: enter test to run
[16:52:39.893] INFO: test: HighRate no parameter change
[16:52:39.893] INFO: running: highrate
[16:52:39.895] INFO: ----------------------------------------------------------------------
[16:52:39.895] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:52:39.895] INFO: ----------------------------------------------------------------------
[16:52:40.511] INFO: Expecting 208000 events.
[16:52:52.323] INFO: 208000 events read in total (11285ms).
[16:52:52.326] INFO: Test took 12422ms.
[16:52:52.473] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:52:52.727] INFO: number of dead pixels (per ROC): 0 0 0 0 3 0 0 0 0 0 0 0 1 0 0 0
[16:52:52.727] INFO: number of red-efficiency pixels: 69 46 72 118 157 118 159 117 75 141 129 81 89 75 19 22
[16:52:52.727] INFO: number of X-ray hits detected: 64850 42393 65734 102213 113614 117644 117037 90837 73310 94251 93112 76864 81215 58986 22163 24506
[16:52:52.727] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:52:52.727] INFO: number of Vcal hits detected: 207929 207953 207927 207880 207694 207878 207840 207879 207922 207853 207868 207916 207862 207923 207981 207978
[16:52:52.727] 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
[16:52:52.727] INFO: Vcal hit overall 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 99.9 100.0 100.0 100.0
[16:52:52.727] INFO: X-ray hit rate [MHz/cm2]: 19.0 12.4 19.3 30.0 33.3 34.5 34.3 26.6 21.5 27.6 27.3 22.5 23.8 17.3 6.5 7.2
[16:52:52.727] INFO: PixTestHighRate::doXPixelAlive() done
[16:52:52.771] INFO: PixTest:: pg_setup set to default.
[16:52:52.783] INFO: enter test to run
[16:53:07.229] INFO: test: HighRate no parameter change
[16:53:07.229] INFO: running: highrate
[16:53:07.231] INFO: ----------------------------------------------------------------------
[16:53:07.231] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:53:07.231] INFO: ----------------------------------------------------------------------
[16:53:07.857] INFO: Expecting 208000 events.
[16:53:21.489] INFO: 208000 events read in total (13105ms).
[16:53:21.494] INFO: Test took 14252ms.
[16:53:21.784] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:53:22.084] INFO: number of dead pixels (per ROC): 0 0 0 0 3 0 0 0 0 0 0 0 1 0 0 0
[16:53:22.085] INFO: number of red-efficiency pixels: 242 111 187 421 475 383 547 343 178 332 302 280 276 210 49 45
[16:53:22.085] INFO: number of X-ray hits detected: 128973 84693 128844 202807 224582 233844 232046 179883 145295 186777 183049 151894 160035 117786 43628 47803
[16:53:22.085] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:53:22.085] INFO: number of Vcal hits detected: 207741 207882 207805 207555 207344 207587 207410 207634 207818 207649 207681 207711 207660 207774 207951 207953
[16:53:22.085] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[16:53:22.085] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[16:53:22.085] INFO: X-ray hit rate [MHz/cm2]: 37.8 24.8 37.8 59.4 65.8 68.5 68.0 52.7 42.6 54.7 53.7 44.5 46.9 34.5 12.8 14.0
[16:53:22.085] INFO: PixTestHighRate::doXPixelAlive() done
[16:53:22.132] INFO: PixTest:: pg_setup set to default.
[16:53:22.146] INFO: enter test to run
[16:54:04.621] INFO: test: HighRate no parameter change
[16:54:04.621] INFO: running: highrate
[16:54:04.622] INFO: ----------------------------------------------------------------------
[16:54:04.622] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:54:04.622] INFO: ----------------------------------------------------------------------
[16:54:05.243] INFO: Expecting 208000 events.
[16:54:21.047] INFO: 208000 events read in total (15277ms).
[16:54:21.055] INFO: Test took 16422ms.
[16:54:21.487] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:54:21.834] INFO: number of dead pixels (per ROC): 0 0 0 0 3 0 0 0 0 0 0 0 1 0 0 0
[16:54:21.834] INFO: number of red-efficiency pixels: 506 215 410 983 1083 899 1226 799 453 839 761 575 601 515 92 88
[16:54:21.834] INFO: number of X-ray hits detected: 197152 129811 198016 311011 343304 358597 355034 275765 223049 287033 282054 232980 246201 179865 67373 73998
[16:54:21.834] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:54:21.834] INFO: number of Vcal hits detected: 207392 207767 207527 206821 206498 206902 206417 206974 207510 207038 207114 207342 207279 207381 207904 207911
[16:54:21.834] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.8 99.5 99.4 99.5 99.3 99.6 99.8 99.6 99.6 99.7 99.7 99.7 100.0 100.0
[16:54:21.834] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.8 99.4 99.3 99.5 99.2 99.5 99.8 99.5 99.6 99.7 99.7 99.7 100.0 100.0
[16:54:21.835] INFO: X-ray hit rate [MHz/cm2]: 57.8 38.0 58.0 91.2 100.6 105.1 104.1 80.8 65.4 84.1 82.7 68.3 72.2 52.7 19.7 21.7
[16:54:21.835] INFO: PixTestHighRate::doXPixelAlive() done
[16:54:21.880] INFO: PixTest:: pg_setup set to default.
[16:54:21.902] INFO: enter test to run
[16:54:49.428] INFO: test: exit no parameter change
[16:54:49.790] QUIET: Connection to board 33 closed.
[16:54:49.798] INFO: pXar: this is the end, my friend