[17:36:09.975] INFO: *** Welcome to pxar ***
[17:36:09.975] INFO: *** Today: 2016/06/29
[17:36:10.003] INFO: *** Version: v1.9.0-814-g7497
[17:36:10.003] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//dacParameters35_C15.dat
[17:36:10.005] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//tbmParameters_C0b.dat
[17:36:10.005] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//defaultMaskFile.dat
[17:36:10.005] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C15.dat
[17:36:10.082] INFO: clk: 4
[17:36:10.082] INFO: ctr: 4
[17:36:10.082] INFO: sda: 19
[17:36:10.082] INFO: tin: 9
[17:36:10.082] INFO: level: 15
[17:36:10.082] INFO: triggerdelay: 0
[17:36:10.082] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[17:36:10.082] INFO: Log level: INFO
[17:36:10.100] QUIET: Connection to board DTB_WREKRL opened.
[17:36:10.103] 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:
------------------------------------------------------
[17:36:10.106] INFO: RPC call hashes of host and DTB match: 398089610
[17:36:11.631] INFO: DUT info:
[17:36:11.631] INFO: The DUT currently contains the following objects:
[17:36:11.631] INFO: 2 TBM Cores tbm08c (2 ON)
[17:36:11.631] INFO: TBM Core alpha (0): 7 registers set
[17:36:11.631] INFO: TBM Core beta (1): 7 registers set
[17:36:11.631] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[17:36:11.631] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.631] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.631] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.631] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.631] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.632] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.632] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.632] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.632] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.632] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.632] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.632] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.632] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.632] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.632] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:11.632] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:36:12.035] INFO: enter 'restricted' command line mode
[17:36:12.035] INFO: enter test to run
[17:36:14.612] INFO: test: timing no parameter change
[17:36:14.612] INFO: running: timing
[17:36:14.620] INFO: ######################################################################
[17:36:14.621] INFO: PixTestTiming::doTest()
[17:36:14.621] INFO: ######################################################################
[17:36:14.621] INFO: ----------------------------------------------------------------------
[17:36:14.621] INFO: PixTestTiming::TBMPhaseScan()
[17:36:14.621] INFO: ----------------------------------------------------------------------
[17:41:07.874] INFO: TBM Phase Settings: 224
[17:41:07.874] INFO: 400MHz Phase: 0
[17:41:07.874] INFO: 160MHz Phase: 7
[17:41:07.874] INFO: Functional Phase Area: 3
[17:41:07.896] INFO: Test took 293275 ms.
[17:41:07.896] INFO: PixTestTiming::TBMPhaseScan() done.
[17:41:07.896] INFO: ----------------------------------------------------------------------
[17:41:07.896] INFO: PixTestTiming::ROCDelayScan()
[17:41:07.896] INFO: ----------------------------------------------------------------------
[17:43:35.966] INFO: ROC Delay Settings: 228
[17:43:35.966] INFO: ROC Header-Trailer/Token Delay: 11
[17:43:35.966] INFO: ROC Port 0 Delay: 4
[17:43:35.967] INFO: ROC Port 1 Delay: 4
[17:43:35.967] INFO: Functional ROC Area: 4
[17:43:35.970] INFO: Test took 148074 ms.
[17:43:35.970] INFO: PixTestTiming::ROCDelayScan() done.
[17:43:35.970] INFO: ----------------------------------------------------------------------
[17:43:35.970] INFO: PixTestTiming::TimingTest()
[17:43:35.970] INFO: ----------------------------------------------------------------------
[17:43:52.096] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:44:07.050] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:44:22.003] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:44:36.945] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:44:51.891] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:45:06.856] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:45:21.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:45:36.800] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:45:51.762] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:46:06.715] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:46:07.096] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:46:07.114] INFO: ----------------------------------------------------------------------
[17:46:07.114] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[17:46:07.114] INFO: ----------------------------------------------------------------------
[17:46:07.114] INFO: ----------------------------------------------------------------------
[17:46:07.114] INFO: Read back bit status: 1
[17:46:07.114] INFO: ----------------------------------------------------------------------
[17:46:07.114] INFO: ----------------------------------------------------------------------
[17:46:07.114] INFO: Timings are good!
[17:46:07.114] INFO: ----------------------------------------------------------------------
[17:46:07.114] INFO: Test took 151144 ms.
[17:46:07.114] INFO: PixTestTiming::TimingTest() done.
[17:46:07.125] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//tbmParameters_C0a.dat
[17:46:07.126] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//tbmParameters_C0b.dat
[17:46:07.126] INFO: PixTestTiming::doTest took 592510 ms.
[17:46:07.126] INFO: PixTestTiming::doTest() done
[17:46:07.126] INFO: Write out TBMPhaseScan_0_V0
[17:46:07.152] INFO: Write out TBMPhaseScan_1_V0
[17:46:07.152] INFO: Write out CombinedTBMPhaseScan_V0
[17:46:07.174] INFO: Write out ROCDelayScan3_V0
[17:46:07.175] INFO: enter test to run
[17:47:36.047] INFO: test: PixelAlive no parameter change
[17:47:36.047] INFO: running: pixelalive
[17:47:36.052] INFO: ----------------------------------------------------------------------
[17:47:36.052] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:47:36.052] INFO: ----------------------------------------------------------------------
[17:47:36.372] INFO: Expecting 41600 events.
[17:47:40.691] INFO: 41600 events read in total (3604ms).
[17:47:40.692] INFO: Test took 4636ms.
[17:47:40.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:47:41.091] INFO: PixTestAlive::aliveTest() done
[17:47:41.091] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 1 0 0 0
[17:47:41.093] INFO: enter test to run
[17:48:20.847] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[17:48:20.847] INFO: running: highrate
[17:48:20.847] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[17:48:20.999] INFO: ----------------------------------------------------------------------
[17:48:20.999] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[17:48:20.999] INFO: ----------------------------------------------------------------------
[17:48:20.999] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[17:48:20.000] INFO: edge/corner pixel THR is adjusted
[17:48:20.000] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:48:21.958] INFO: Collecting data for 5 seconds...
[17:48:26.974] INFO: Done with hot pixel readout
[17:48:38.823] INFO: PixTest:: pg_setup set to default.

[17:48:38.824] INFO: 16 hot pixels found in step 0
[17:48:39.816] INFO: Collecting data for 5 seconds...
[17:48:44.832] INFO: Done with hot pixel readout
[17:48:56.628] INFO: PixTest:: pg_setup set to default.

[17:48:56.629] INFO: 17 hot pixels found in step 1
[17:48:57.622] INFO: Collecting data for 5 seconds...
[17:49:02.639] INFO: Done with hot pixel readout
[17:49:14.416] INFO: PixTest:: pg_setup set to default.

[17:49:14.417] INFO: 13 hot pixels found in step 2
[17:49:15.409] INFO: Collecting data for 5 seconds...
[17:49:20.426] INFO: Done with hot pixel readout
[17:49:32.235] INFO: PixTest:: pg_setup set to default.


[17:49:32.236] INFO: 14 hot pixels found in step 3
[17:49:33.228] INFO: Collecting data for 5 seconds...
[17:49:38.245] INFO: Done with hot pixel readout
[17:49:50.055] INFO: PixTest:: pg_setup set to default.

[17:49:50.056] INFO: 9 hot pixels found in step 4
[17:49:51.049] INFO: Collecting data for 5 seconds...
[17:49:56.065] INFO: Done with hot pixel readout
[17:50:07.782] INFO: PixTest:: pg_setup set to default.





[17:50:07.783] INFO: 13 hot pixels found in step 5
[17:50:08.777] INFO: Collecting data for 5 seconds...
[17:50:13.793] INFO: Done with hot pixel readout
[17:50:25.577] INFO: PixTest:: pg_setup set to default.

[17:50:25.578] INFO: 15 hot pixels found in step 6
[17:50:26.571] INFO: Collecting data for 5 seconds...
[17:50:31.588] INFO: Done with hot pixel readout
[17:50:43.355] INFO: PixTest:: pg_setup set to default.
[17:50:43.356] INFO: 10 hot pixels found in step 7
[17:50:44.349] INFO: Collecting data for 5 seconds...
[17:50:49.365] INFO: Done with hot pixel readout
[17:51:01.141] INFO: PixTest:: pg_setup set to default.


[17:51:01.142] INFO: 10 hot pixels found in step 8
[17:51:02.135] INFO: Collecting data for 5 seconds...
[17:51:07.151] INFO: Done with hot pixel readout
[17:51:18.977] INFO: PixTest:: pg_setup set to default.


[17:51:18.978] INFO: 10 hot pixels found in step 9
[17:51:19.971] INFO: Collecting data for 5 seconds...
[17:51:24.987] INFO: Done with hot pixel readout
[17:51:37.003] INFO: PixTest:: pg_setup set to default.

[17:51:37.004] INFO: 11 hot pixels found in step 10
[17:51:37.998] INFO: Collecting data for 5 seconds...
[17:51:43.016] INFO: Done with hot pixel readout
[17:51:55.124] INFO: PixTest:: pg_setup set to default.



[17:51:55.125] INFO: 12 hot pixels found in step 11
[17:51:56.119] INFO: Collecting data for 5 seconds...
[17:52:01.135] INFO: Done with hot pixel readout
[17:52:13.135] INFO: PixTest:: pg_setup set to default.



[17:52:13.136] INFO: 7 hot pixels found in step 12
[17:52:14.129] INFO: Collecting data for 5 seconds...
[17:52:19.148] INFO: Done with hot pixel readout
[17:52:30.773] INFO: PixTest:: pg_setup set to default.


[17:52:30.774] INFO: 9 hot pixels found in step 13
[17:52:31.766] INFO: Collecting data for 5 seconds...
[17:52:36.784] INFO: Done with hot pixel readout
[17:52:48.325] INFO: PixTest:: pg_setup set to default.


[17:52:48.326] INFO: 12 hot pixels found in step 14
[17:52:48.364] INFO: 12 hot pixels could not be trimmed and have been masked.
[17:52:48.367] INFO: PixTest::trimHotPixels() done
[17:52:48.367] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C0.dat
[17:52:48.373] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C1.dat
[17:52:48.379] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C2.dat
[17:52:48.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C3.dat
[17:52:48.390] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C4.dat
[17:52:48.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C5.dat
[17:52:48.401] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C6.dat
[17:52:48.407] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C7.dat
[17:52:48.412] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C8.dat
[17:52:48.418] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C9.dat
[17:52:48.423] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C10.dat
[17:52:48.429] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C11.dat
[17:52:48.434] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C12.dat
[17:52:48.440] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C13.dat
[17:52:48.445] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C14.dat
[17:52:48.451] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C15.dat
[17:52:48.456] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//defaultMaskFile.dat
[17:52:48.467] INFO: enter test to run
[17:53:26.045] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[17:53:26.045] INFO: running: highrate
[17:53:26.050] INFO: ----------------------------------------------------------------------
[17:53:26.050] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[17:53:26.050] INFO: ----------------------------------------------------------------------
[17:53:26.050] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[17:53:26.050] INFO: edge/corner pixel THR is adjusted
[17:53:26.050] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:53:27.007] INFO: Collecting data for 1 seconds...
[17:53:28.012] INFO: Done with hot pixel readout
[17:53:32.115] INFO: PixTest:: pg_setup set to default.
[17:53:32.116] INFO: 0 hot pixels found in step 0
[17:53:32.121] INFO: 0 hot pixels could not be trimmed and have been masked.
[17:53:32.209] INFO: PixTest::trimHotPixels() done
[17:53:32.209] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C0.dat
[17:53:32.221] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C1.dat
[17:53:32.227] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C2.dat
[17:53:32.232] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C3.dat
[17:53:32.238] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C4.dat
[17:53:32.243] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C5.dat
[17:53:32.248] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C6.dat
[17:53:32.254] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C7.dat
[17:53:32.259] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C8.dat
[17:53:32.265] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C9.dat
[17:53:32.270] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C10.dat
[17:53:32.276] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C11.dat
[17:53:32.281] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C12.dat
[17:53:32.287] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C13.dat
[17:53:32.292] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C14.dat
[17:53:32.298] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//trimParameters35_C15.dat
[17:53:32.303] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-40_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h38m_1466617096/000_FPIXTest_p17//defaultMaskFile.dat
[17:53:32.313] INFO: enter test to run
[17:54:17.037] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[17:54:17.037] INFO: running: xray
[17:54:17.038] INFO: ----------------------------------------------------------------------
[17:54:17.038] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:54:17.038] INFO: ----------------------------------------------------------------------
[17:54:18.002] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:54:29.396] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[17:54:59.562] INFO: Resuming triggers.
[17:55:10.957] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[17:55:40.869] INFO: Resuming triggers.
[17:55:52.263] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[17:56:21.701] INFO: Resuming triggers.
[17:56:33.099] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[17:57:02.493] INFO: Resuming triggers.
[17:57:13.887] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[17:57:43.332] INFO: Resuming triggers.
[17:57:54.723] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[17:58:24.132] INFO: Resuming triggers.
[17:58:35.531] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[17:59:05.002] INFO: Resuming triggers.
[17:59:16.398] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[17:59:45.869] INFO: Resuming triggers.
[17:59:55.054] INFO: data taking finished, elapsed time: 100 seconds.
[18:00:18.954] INFO: PixTest:: pg_setup set to default.
[18:00:18.958] INFO: PixTestXray::doPhRun() done
[18:00:19.095] INFO: enter test to run
[18:00:41.986] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[18:00:41.986] INFO: running: xray
[18:00:41.987] INFO: ----------------------------------------------------------------------
[18:00:41.987] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:00:41.987] INFO: ----------------------------------------------------------------------
[18:00:42.961] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:00:49.656] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[18:01:19.856] INFO: Resuming triggers.
[18:01:26.555] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[18:01:56.579] INFO: Resuming triggers.
[18:02:03.279] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[18:02:33.466] INFO: Resuming triggers.
[18:02:40.166] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[18:03:10.268] INFO: Resuming triggers.
[18:03:16.963] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[18:03:47.775] INFO: Resuming triggers.
[18:03:54.471] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[18:04:25.335] INFO: Resuming triggers.
[18:04:32.030] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[18:05:02.732] INFO: Resuming triggers.
[18:05:09.427] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[18:05:41.120] INFO: Resuming triggers.
[18:05:47.819] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[18:06:19.155] INFO: Resuming triggers.
[18:06:25.851] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[18:06:57.104] INFO: Resuming triggers.
[18:07:03.804] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[18:07:34.013] INFO: Resuming triggers.
[18:07:40.705] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[18:08:10.854] INFO: Resuming triggers.
[18:08:17.548] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[18:08:47.699] INFO: Resuming triggers.
[18:08:54.394] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[18:09:24.365] INFO: Resuming triggers.
[18:09:30.968] INFO: data taking finished, elapsed time: 100 seconds.
[18:10:00.885] INFO: PixTest:: pg_setup set to default.
[18:10:00.889] INFO: PixTestXray::doPhRun() done
[18:10:01.037] INFO: enter test to run
[18:11:35.342] INFO: test: HighRate no parameter change
[18:11:35.342] INFO: running: highrate
[18:11:35.354] INFO: ----------------------------------------------------------------------
[18:11:35.354] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[18:11:35.354] INFO: ----------------------------------------------------------------------
[18:11:35.510] INFO: Expecting 768 events.
[18:11:36.643] INFO: 768 events read in total (418ms).
[18:11:36.644] INFO: Test took 1269ms.
[18:11:37.447] INFO: Expecting 41600 events.
[18:11:40.570] INFO: 41600 events read in total (2597ms).
[18:11:40.571] INFO: Test took 3920ms.
[18:11:40.605] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:11:41.331] INFO: Expecting 41600 events.
[18:11:44.531] INFO: 41600 events read in total (2673ms).
[18:11:44.532] INFO: Test took 3910ms.
[18:11:44.566] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:11:45.290] INFO: Expecting 41600 events.
[18:11:48.529] INFO: 41600 events read in total (2712ms).
[18:11:48.530] INFO: Test took 3946ms.
[18:11:48.565] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:11:49.288] INFO: Expecting 41600 events.
[18:11:52.524] INFO: 41600 events read in total (2709ms).
[18:11:52.525] INFO: Test took 3943ms.
[18:11:52.559] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:11:53.281] INFO: Expecting 41600 events.
[18:11:56.521] INFO: 41600 events read in total (2713ms).
[18:11:56.522] INFO: Test took 3944ms.
[18:11:56.557] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:11:57.279] INFO: Expecting 41600 events.
[18:12:00.526] INFO: 41600 events read in total (2720ms).
[18:12:00.527] INFO: Test took 3952ms.
[18:12:00.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:01.282] INFO: Expecting 41600 events.
[18:12:04.354] INFO: 41600 events read in total (2545ms).
[18:12:04.355] INFO: Test took 3775ms.
[18:12:04.389] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:05.110] INFO: Expecting 41600 events.
[18:12:08.355] INFO: 41600 events read in total (2718ms).
[18:12:08.356] INFO: Test took 3949ms.
[18:12:08.391] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:09.115] INFO: Expecting 41600 events.
[18:12:12.349] INFO: 41600 events read in total (2707ms).
[18:12:12.350] INFO: Test took 3940ms.
[18:12:12.384] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:13.108] INFO: Expecting 41600 events.
[18:12:16.358] INFO: 41600 events read in total (2723ms).
[18:12:16.359] INFO: Test took 3958ms.
[18:12:16.394] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:17.118] INFO: Expecting 41600 events.
[18:12:20.378] INFO: 41600 events read in total (2733ms).
[18:12:20.379] INFO: Test took 3966ms.
[18:12:20.414] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:21.138] INFO: Expecting 41600 events.
[18:12:24.385] INFO: 41600 events read in total (2720ms).
[18:12:24.386] INFO: Test took 3953ms.
[18:12:24.421] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:25.144] INFO: Expecting 41600 events.
[18:12:28.403] INFO: 41600 events read in total (2732ms).
[18:12:28.404] INFO: Test took 3964ms.
[18:12:28.439] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:29.160] INFO: Expecting 41600 events.
[18:12:32.412] INFO: 41600 events read in total (2725ms).
[18:12:32.413] INFO: Test took 3954ms.
[18:12:32.448] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:33.172] INFO: Expecting 41600 events.
[18:12:36.409] INFO: 41600 events read in total (2710ms).
[18:12:36.410] INFO: Test took 3943ms.
[18:12:36.444] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:37.169] INFO: Expecting 41600 events.
[18:12:40.426] INFO: 41600 events read in total (2730ms).
[18:12:40.427] INFO: Test took 3965ms.
[18:12:40.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:41.183] INFO: Expecting 41600 events.
[18:12:44.425] INFO: 41600 events read in total (2715ms).
[18:12:44.426] INFO: Test took 3945ms.
[18:12:44.461] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:45.185] INFO: Expecting 41600 events.
[18:12:48.421] INFO: 41600 events read in total (2709ms).
[18:12:48.422] INFO: Test took 3943ms.
[18:12:48.457] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:49.180] INFO: Expecting 41600 events.
[18:12:52.368] INFO: 41600 events read in total (2661ms).
[18:12:52.369] INFO: Test took 3893ms.
[18:12:52.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:53.128] INFO: Expecting 41600 events.
[18:12:56.140] INFO: 41600 events read in total (2485ms).
[18:12:56.141] INFO: Test took 3718ms.
[18:12:56.174] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:12:56.533] INFO: enter test to run
[18:13:08.149] INFO: test: HighRate no parameter change
[18:13:08.149] INFO: running: highrate
[18:13:08.150] INFO: ----------------------------------------------------------------------
[18:13:08.150] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:13:08.150] INFO: ----------------------------------------------------------------------
[18:13:08.768] INFO: Expecting 208000 events.
[18:13:20.732] INFO: 208000 events read in total (11437ms).
[18:13:20.736] INFO: Test took 12576ms.
[18:13:20.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:13:21.136] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 2 0 0 0
[18:13:21.136] INFO: number of red-efficiency pixels: 69 57 59 134 131 124 140 65 111 135 116 99 104 38 13 33
[18:13:21.136] INFO: number of X-ray hits detected: 68778 45583 71861 110369 120708 119459 120890 84358 87833 102511 93092 81416 81387 48037 19265 24598
[18:13:21.136] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:13:21.136] INFO: number of Vcal hits detected: 207929 207941 207892 207861 207866 207870 207857 207933 207880 207865 207879 207898 207795 207961 207987 207967
[18:13:21.136] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[18:13:21.136] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[18:13:21.136] INFO: X-ray hit rate [MHz/cm2]: 20.2 13.4 21.1 32.3 35.4 35.0 35.4 24.7 25.7 30.0 27.3 23.9 23.9 14.1 5.6 7.2
[18:13:21.136] INFO: PixTestHighRate::doXPixelAlive() done
[18:13:21.183] INFO: PixTest:: pg_setup set to default.
[18:13:21.197] INFO: enter test to run
[18:14:32.180] INFO: test: HighRate no parameter change
[18:14:32.180] INFO: running: highrate
[18:14:32.182] INFO: ----------------------------------------------------------------------
[18:14:32.182] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:14:32.182] INFO: ----------------------------------------------------------------------
[18:14:32.802] INFO: Expecting 208000 events.
[18:14:46.456] INFO: 208000 events read in total (13127ms).
[18:14:46.461] INFO: Test took 14271ms.
[18:14:46.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:14:47.056] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 1 0 0 0
[18:14:47.056] INFO: number of red-efficiency pixels: 209 139 207 460 469 452 585 270 324 448 349 286 297 131 50 43
[18:14:47.056] INFO: number of X-ray hits detected: 139127 91647 146965 222686 244950 242143 245890 170966 177494 209020 189719 165774 164331 97978 39003 49784
[18:14:47.056] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:14:47.056] INFO: number of Vcal hits detected: 207780 207858 207732 207501 207491 207514 207338 207708 207641 207528 207631 207698 207596 207861 207949 207957
[18:14:47.056] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.9 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[18:14:47.056] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.9 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[18:14:47.056] INFO: X-ray hit rate [MHz/cm2]: 40.8 26.9 43.1 65.3 71.8 71.0 72.1 50.1 52.0 61.3 55.6 48.6 48.2 28.7 11.4 14.6
[18:14:47.056] INFO: PixTestHighRate::doXPixelAlive() done
[18:14:47.103] INFO: PixTest:: pg_setup set to default.
[18:14:47.117] INFO: enter test to run
[18:15:07.308] INFO: test: HighRate no parameter change
[18:15:07.308] INFO: running: highrate
[18:15:07.310] INFO: ----------------------------------------------------------------------
[18:15:07.310] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:15:07.310] INFO: ----------------------------------------------------------------------
[18:15:07.931] INFO: Expecting 208000 events.
[18:15:23.690] INFO: 208000 events read in total (15232ms).
[18:15:23.698] INFO: Test took 16378ms.
[18:15:24.149] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:15:24.502] INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 0 0 0 0 0 0 2 0 0 0
[18:15:24.502] INFO: number of red-efficiency pixels: 382 290 510 1061 974 969 1299 541 779 1005 781 621 570 300 68 93
[18:15:24.502] INFO: number of X-ray hits detected: 209691 140062 221346 334585 368049 364609 369924 258021 268419 316236 285293 249323 247633 147613 59548 75226
[18:15:24.502] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:15:24.502] INFO: number of Vcal hits detected: 207572 207668 207341 206649 206826 206798 206244 207368 207014 206752 207077 207288 207279 207669 207930 207902
[18:15:24.502] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.5 99.5 99.2 99.7 99.6 99.5 99.6 99.7 99.7 99.9 100.0 100.0
[18:15:24.502] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.7 99.4 99.4 99.4 99.2 99.7 99.5 99.4 99.6 99.7 99.7 99.8 100.0 100.0
[18:15:24.502] INFO: X-ray hit rate [MHz/cm2]: 61.5 41.1 64.9 98.1 107.9 106.9 108.4 75.6 78.7 92.7 83.6 73.1 72.6 43.3 17.5 22.0
[18:15:24.502] INFO: PixTestHighRate::doXPixelAlive() done
[18:15:24.549] INFO: PixTest:: pg_setup set to default.
[18:15:24.563] INFO: enter test to run
[18:15:30.204] INFO: test: exit no parameter change
[18:15:30.589] QUIET: Connection to board 33 closed.
[18:15:30.600] INFO: pXar: this is the end, my friend