[18:42:34.948] INFO: *** Welcome to pxar ***
[18:42:34.948] INFO: *** Today: 2016/08/31
[18:42:39.943] INFO: *** Version: v1.9.0-818-g96727
[18:42:39.943] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//dacParameters35_C15.dat
[18:42:40.207] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//tbmParameters_C0b.dat
[18:42:40.228] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//defaultMaskFile.dat
[18:42:40.312] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C15.dat
[18:42:41.754] INFO: clk: 4
[18:42:41.754] INFO: ctr: 4
[18:42:41.754] INFO: sda: 19
[18:42:41.754] INFO: tin: 9
[18:42:41.754] INFO: level: 15
[18:42:41.754] INFO: triggerdelay: 0
[18:42:41.779] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[18:42:41.779] INFO: Log level: INFO
[18:42:41.872] QUIET: Connection to board DTB_WREK4U opened.
[18:42:41.875] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[18:42:41.878] INFO: RPC call hashes of host and DTB match: 398089610
[18:42:43.431] INFO: DUT info:
[18:42:43.432] INFO: The DUT currently contains the following objects:
[18:42:43.432] INFO: 2 TBM Cores tbm08c (2 ON)
[18:42:43.432] INFO: TBM Core alpha (0): 7 registers set
[18:42:43.432] INFO: TBM Core beta (1): 7 registers set
[18:42:43.432] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[18:42:43.432] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.432] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:42:43.850] INFO: enter 'restricted' command line mode
[18:42:43.850] INFO: enter test to run
[18:42:48.470] INFO: test: PixelAlive no parameter change
[18:42:48.470] INFO: running: pixelalive
[18:42:48.592] INFO: ----------------------------------------------------------------------
[18:42:48.592] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:42:48.592] INFO: ----------------------------------------------------------------------
[18:42:48.911] INFO: Expecting 41600 events.
[18:42:53.200] INFO: 41600 events read in total (3571ms).
[18:42:53.369] INFO: Test took 4774ms.
[18:42:53.380] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:42:53.684] INFO: PixTestAlive::aliveTest() done
[18:42:53.684] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[18:42:53.712] INFO: enter test to run
[18:43:00.174] INFO: test: timing no parameter change
[18:43:00.174] INFO: running: timing
[18:43:00.177] INFO: ######################################################################
[18:43:00.178] INFO: PixTestTiming::doTest()
[18:43:00.178] INFO: ######################################################################
[18:43:00.178] INFO: ----------------------------------------------------------------------
[18:43:00.178] INFO: PixTestTiming::TBMPhaseScan()
[18:43:00.178] INFO: ----------------------------------------------------------------------
[18:47:29.994] INFO: TBM Phase Settings: 240
[18:47:30.016] INFO: 400MHz Phase: 4
[18:47:30.016] INFO: 160MHz Phase: 7
[18:47:30.016] INFO: Functional Phase Area: 5
[18:47:30.063] INFO: Test took 269885 ms.
[18:47:30.063] INFO: PixTestTiming::TBMPhaseScan() done.
[18:47:30.063] INFO: ----------------------------------------------------------------------
[18:47:30.063] INFO: PixTestTiming::ROCDelayScan()
[18:47:30.063] INFO: ----------------------------------------------------------------------
[18:49:41.837] INFO: ROC Delay Settings: 228
[18:49:41.837] INFO: ROC Header-Trailer/Token Delay: 11
[18:49:41.837] INFO: ROC Port 0 Delay: 4
[18:49:41.837] INFO: ROC Port 1 Delay: 4
[18:49:41.837] INFO: Functional ROC Area: 6
[18:49:41.840] INFO: Test took 131777 ms.
[18:49:41.840] INFO: PixTestTiming::ROCDelayScan() done.
[18:49:41.840] INFO: ----------------------------------------------------------------------
[18:49:41.840] INFO: PixTestTiming::TimingTest()
[18:49:41.841] INFO: ----------------------------------------------------------------------
[18:49:58.088] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:13.152] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:27.646] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:42.837] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:50:58.029] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:13.066] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:28.102] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:43.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:58.342] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:13.474] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:13.856] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:13.876] INFO: ----------------------------------------------------------------------
[18:52:13.876] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[18:52:13.876] INFO: ----------------------------------------------------------------------
[18:52:13.876] INFO: ----------------------------------------------------------------------
[18:52:13.876] INFO: Read back bit status: 1
[18:52:13.876] INFO: ----------------------------------------------------------------------
[18:52:13.876] INFO: ----------------------------------------------------------------------
[18:52:13.876] INFO: Timings are good!
[18:52:13.876] INFO: ----------------------------------------------------------------------
[18:52:13.876] INFO: Test took 152036 ms.
[18:52:13.876] INFO: PixTestTiming::TimingTest() done.
[18:52:14.284] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//tbmParameters_C0a.dat
[18:52:14.391] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//tbmParameters_C0b.dat
[18:52:14.391] INFO: PixTestTiming::doTest took 554217 ms.
[18:52:14.391] INFO: PixTestTiming::doTest() done
[18:52:14.486] INFO: Write out TBMPhaseScan_0_V0
[18:52:15.312] INFO: Write out TBMPhaseScan_1_V0
[18:52:15.312] INFO: Write out CombinedTBMPhaseScan_V0
[18:52:16.385] INFO: Write out ROCDelayScan3_V0
[18:52:16.451] INFO: enter test to run
[18:52:55.379] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[18:52:55.379] INFO: running: highrate
[18:52:55.529] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[18:52:57.800] INFO: ----------------------------------------------------------------------
[18:52:57.800] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[18:52:57.800] INFO: ----------------------------------------------------------------------
[18:52:57.800] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[18:52:57.801] INFO: edge/corner pixel THR is adjusted
[18:52:57.801] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:52:58.972] INFO: Collecting data for 5 seconds...
[18:53:03.990] INFO: Done with hot pixel readout
[18:53:17.339] INFO: PixTest:: pg_setup set to default.





























































[18:53:17.404] INFO: 238 hot pixels found in step 0
[18:53:18.426] INFO: Collecting data for 5 seconds...
[18:53:23.445] INFO: Done with hot pixel readout
[18:53:36.852] INFO: PixTest:: pg_setup set to default.












































































[18:53:36.855] INFO: 245 hot pixels found in step 1
[18:53:37.854] INFO: Collecting data for 5 seconds...
[18:53:42.873] INFO: Done with hot pixel readout
[18:53:55.943] INFO: PixTest:: pg_setup set to default.
































































[18:53:55.946] INFO: 218 hot pixels found in step 2
[18:53:56.946] INFO: Collecting data for 5 seconds...
[18:54:01.963] INFO: Done with hot pixel readout
[18:54:14.956] INFO: PixTest:: pg_setup set to default.









































































[18:54:14.959] INFO: 194 hot pixels found in step 3
[18:54:15.959] INFO: Collecting data for 5 seconds...
[18:54:20.977] INFO: Done with hot pixel readout
[18:54:33.952] INFO: PixTest:: pg_setup set to default.









































































[18:54:33.955] INFO: 192 hot pixels found in step 4
[18:54:34.955] INFO: Collecting data for 5 seconds...
[18:54:39.972] INFO: Done with hot pixel readout
[18:54:52.884] INFO: PixTest:: pg_setup set to default.





































































[18:54:52.887] INFO: 186 hot pixels found in step 5
[18:54:53.888] INFO: Collecting data for 5 seconds...
[18:54:58.904] INFO: Done with hot pixel readout
[18:55:11.365] INFO: PixTest:: pg_setup set to default.











































































[18:55:11.367] INFO: 169 hot pixels found in step 6
[18:55:12.368] INFO: Collecting data for 5 seconds...
[18:55:17.385] INFO: Done with hot pixel readout
[18:55:30.038] INFO: PixTest:: pg_setup set to default.


















































































[18:55:30.041] INFO: 177 hot pixels found in step 7
[18:55:31.043] INFO: Collecting data for 5 seconds...
[18:55:36.057] INFO: Done with hot pixel readout
[18:55:48.450] INFO: PixTest:: pg_setup set to default.


































































[18:55:48.452] INFO: 155 hot pixels found in step 8
[18:55:49.455] INFO: Collecting data for 5 seconds...
[18:55:54.471] INFO: Done with hot pixel readout
[18:56:07.029] INFO: PixTest:: pg_setup set to default.










































































[18:56:07.031] INFO: 164 hot pixels found in step 9
[18:56:08.033] INFO: Collecting data for 5 seconds...
[18:56:13.049] INFO: Done with hot pixel readout
[18:56:26.046] INFO: PixTest:: pg_setup set to default.


























































































[18:56:26.048] INFO: 181 hot pixels found in step 10
[18:56:27.049] INFO: Collecting data for 5 seconds...
[18:56:32.067] INFO: Done with hot pixel readout
[18:56:44.622] INFO: PixTest:: pg_setup set to default.











































































[18:56:44.625] INFO: 150 hot pixels found in step 11
[18:56:45.625] INFO: Collecting data for 5 seconds...
[18:56:50.643] INFO: Done with hot pixel readout
[18:57:03.334] INFO: PixTest:: pg_setup set to default.


















































































[18:57:03.336] INFO: 161 hot pixels found in step 12
[18:57:04.337] INFO: Collecting data for 5 seconds...
[18:57:09.354] INFO: Done with hot pixel readout
[18:57:22.387] INFO: PixTest:: pg_setup set to default.
















































































[18:57:22.390] INFO: 148 hot pixels found in step 13
[18:57:23.392] INFO: Collecting data for 5 seconds...
[18:57:28.408] INFO: Done with hot pixel readout
[18:57:41.039] INFO: PixTest:: pg_setup set to default.











































































[18:57:41.042] INFO: 163 hot pixels found in step 14
[18:57:41.087] INFO: 163 hot pixels could not be trimmed and have been masked.
[18:57:41.164] INFO: PixTest::trimHotPixels() done
[18:57:41.216] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C0.dat
[18:57:41.239] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C1.dat
[18:57:41.248] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C2.dat
[18:57:41.254] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C3.dat
[18:57:41.259] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C4.dat
[18:57:41.283] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C5.dat
[18:57:41.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C6.dat
[18:57:41.294] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C7.dat
[18:57:41.300] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C8.dat
[18:57:41.305] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C9.dat
[18:57:41.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C10.dat
[18:57:41.315] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C11.dat
[18:57:41.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C12.dat
[18:57:41.356] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C13.dat
[18:57:41.361] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C14.dat
[18:57:41.367] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C15.dat
[18:57:41.405] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//defaultMaskFile.dat
[18:57:41.424] INFO: enter test to run
[18:58:39.400] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[18:58:39.400] INFO: running: highrate
[18:58:39.404] INFO: ----------------------------------------------------------------------
[18:58:39.404] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[18:58:39.404] INFO: ----------------------------------------------------------------------
[18:58:39.405] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[18:58:39.405] INFO: edge/corner pixel THR is adjusted
[18:58:39.405] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:58:40.363] INFO: Collecting data for 1 seconds...
[18:58:41.367] INFO: Done with hot pixel readout
[18:58:46.150] INFO: PixTest:: pg_setup set to default.
[18:58:46.151] INFO: 0 hot pixels found in step 0
[18:58:46.157] INFO: 0 hot pixels could not be trimmed and have been masked.
[18:58:46.218] INFO: PixTest::trimHotPixels() done
[18:58:46.218] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C0.dat
[18:58:46.245] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C1.dat
[18:58:46.258] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C2.dat
[18:58:46.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C3.dat
[18:58:46.271] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C4.dat
[18:58:46.276] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C5.dat
[18:58:46.282] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C6.dat
[18:58:46.287] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C7.dat
[18:58:46.313] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C8.dat
[18:58:46.319] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C9.dat
[18:58:46.324] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C10.dat
[18:58:46.330] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C11.dat
[18:58:46.335] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C12.dat
[18:58:46.341] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C13.dat
[18:58:46.346] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C14.dat
[18:58:46.352] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//trimParameters35_C15.dat
[18:58:46.357] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-N-NZ_FPIXTest-17C-FNAL-160815-1223-150V_2016-08-15_12h23m_1471281805/000_FPIXTest_p17//defaultMaskFile.dat
[18:58:46.372] INFO: enter test to run
[18:59:08.520] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[18:59:08.520] INFO: running: xray
[18:59:08.521] INFO: ----------------------------------------------------------------------
[18:59:08.521] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:59:08.521] INFO: ----------------------------------------------------------------------
[18:59:09.530] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:59:19.800] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[18:59:48.237] INFO: Resuming triggers.
[18:59:58.630] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[19:00:27.755] INFO: Resuming triggers.
[19:00:38.034] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[19:01:08.184] INFO: Resuming triggers.
[19:01:18.462] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[19:01:47.311] INFO: Resuming triggers.
[19:01:57.591] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[19:02:25.607] INFO: Resuming triggers.
[19:02:36.312] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[19:03:05.115] INFO: Resuming triggers.
[19:03:15.391] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[19:03:44.303] INFO: Resuming triggers.
[19:03:54.584] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[19:04:23.418] INFO: Resuming triggers.
[19:04:33.694] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[19:05:02.525] INFO: Resuming triggers.
[19:05:10.327] INFO: data taking finished, elapsed time: 100 seconds.
[19:05:33.038] INFO: PixTest:: pg_setup set to default.
[19:05:33.059] INFO: PixTestXray::doPhRun() done
[19:05:37.919] INFO: enter test to run
[19:05:50.243] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[19:05:50.243] INFO: running: xray
[19:05:50.282] INFO: ----------------------------------------------------------------------
[19:05:50.282] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[19:05:50.283] INFO: ----------------------------------------------------------------------
[19:05:51.301] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[19:05:56.711] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[19:06:27.177] INFO: Resuming triggers.
[19:06:32.592] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[19:07:03.234] INFO: Resuming triggers.
[19:07:08.646] INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[19:07:38.626] INFO: Resuming triggers.
[19:07:44.042] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[19:08:12.581] INFO: Resuming triggers.
[19:08:17.996] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[19:08:50.342] INFO: Resuming triggers.
[19:08:55.995] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[19:09:26.200] INFO: Resuming triggers.
[19:09:31.610] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[19:10:01.551] INFO: Resuming triggers.
[19:10:06.966] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[19:10:37.347] INFO: Resuming triggers.
[19:10:42.760] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[19:11:12.288] INFO: Resuming triggers.
[19:11:17.702] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[19:11:48.463] INFO: Resuming triggers.
[19:11:53.873] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[19:12:24.840] INFO: Resuming triggers.
[19:12:30.253] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[19:13:00.886] INFO: Resuming triggers.
[19:13:06.296] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[19:13:35.813] INFO: Resuming triggers.
[19:13:41.223] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[19:14:11.368] INFO: Resuming triggers.
[19:14:16.781] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[19:14:46.898] INFO: Resuming triggers.
[19:14:52.310] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[19:15:23.101] INFO: Resuming triggers.
[19:15:28.530] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[19:15:59.282] INFO: Resuming triggers.
[19:16:04.694] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[19:16:35.172] INFO: Resuming triggers.
[19:16:38.058] INFO: data taking finished, elapsed time: 100 seconds.
[19:16:54.720] INFO: PixTest:: pg_setup set to default.
[19:16:54.723] INFO: PixTestXray::doPhRun() done
[19:16:55.333] INFO: enter test to run
[19:17:17.264] INFO: test: HighRate no parameter change
[19:17:17.264] INFO: running: highrate
[19:17:17.501] INFO: ----------------------------------------------------------------------
[19:17:17.501] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[19:17:17.501] INFO: ----------------------------------------------------------------------
[19:17:17.673] INFO: Expecting 768 events.
[19:17:18.816] INFO: 768 events read in total (428ms).
[19:17:18.817] INFO: Test took 1291ms.
[19:17:19.645] INFO: Expecting 41600 events.
[19:17:22.720] INFO: 41600 events read in total (2548ms).
[19:17:22.722] INFO: Test took 3683ms.
[19:17:22.764] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:23.470] INFO: Expecting 41600 events.
[19:17:26.379] INFO: 41600 events read in total (2382ms).
[19:17:26.380] INFO: Test took 3557ms.
[19:17:26.424] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:27.129] INFO: Expecting 41600 events.
[19:17:30.371] INFO: 41600 events read in total (2715ms).
[19:17:30.372] INFO: Test took 3927ms.
[19:17:30.414] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:31.118] INFO: Expecting 41600 events.
[19:17:34.257] INFO: 41600 events read in total (2612ms).
[19:17:34.258] INFO: Test took 3824ms.
[19:17:34.302] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:35.008] INFO: Expecting 41600 events.
[19:17:38.249] INFO: 41600 events read in total (2714ms).
[19:17:38.251] INFO: Test took 3928ms.
[19:17:38.292] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:38.999] INFO: Expecting 41600 events.
[19:17:42.256] INFO: 41600 events read in total (2730ms).
[19:17:42.257] INFO: Test took 3944ms.
[19:17:42.299] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:42.001] INFO: Expecting 41600 events.
[19:17:46.325] INFO: 41600 events read in total (2798ms).
[19:17:46.326] INFO: Test took 4006ms.
[19:17:46.369] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:47.074] INFO: Expecting 41600 events.
[19:17:50.361] INFO: 41600 events read in total (2760ms).
[19:17:50.362] INFO: Test took 3973ms.
[19:17:50.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:51.113] INFO: Expecting 41600 events.
[19:17:54.374] INFO: 41600 events read in total (2734ms).
[19:17:54.375] INFO: Test took 3951ms.
[19:17:54.417] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:55.126] INFO: Expecting 41600 events.
[19:17:58.495] INFO: 41600 events read in total (2842ms).
[19:17:58.496] INFO: Test took 4059ms.
[19:17:58.537] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:17:59.248] INFO: Expecting 41600 events.
[19:18:02.575] INFO: 41600 events read in total (2801ms).
[19:18:02.576] INFO: Test took 4019ms.
[19:18:02.618] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:03.326] INFO: Expecting 41600 events.
[19:18:06.659] INFO: 41600 events read in total (2806ms).
[19:18:06.660] INFO: Test took 4021ms.
[19:18:06.702] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:07.408] INFO: Expecting 41600 events.
[19:18:10.678] INFO: 41600 events read in total (2743ms).
[19:18:10.679] INFO: Test took 3955ms.
[19:18:10.721] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:11.430] INFO: Expecting 41600 events.
[19:18:14.674] INFO: 41600 events read in total (2717ms).
[19:18:14.675] INFO: Test took 3934ms.
[19:18:14.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:15.427] INFO: Expecting 41600 events.
[19:18:18.729] INFO: 41600 events read in total (2775ms).
[19:18:18.730] INFO: Test took 3992ms.
[19:18:18.772] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:19.476] INFO: Expecting 41600 events.
[19:18:22.802] INFO: 41600 events read in total (2800ms).
[19:18:22.803] INFO: Test took 4010ms.
[19:18:22.845] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:23.556] INFO: Expecting 41600 events.
[19:18:26.944] INFO: 41600 events read in total (2861ms).
[19:18:26.945] INFO: Test took 4079ms.
[19:18:26.987] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:27.692] INFO: Expecting 41600 events.
[19:18:31.067] INFO: 41600 events read in total (2848ms).
[19:18:31.068] INFO: Test took 4059ms.
[19:18:31.113] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:31.812] INFO: Expecting 41600 events.
[19:18:35.125] INFO: 41600 events read in total (2786ms).
[19:18:35.127] INFO: Test took 3993ms.
[19:18:35.174] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:35.868] INFO: Expecting 41600 events.
[19:18:39.051] INFO: 41600 events read in total (2656ms).
[19:18:39.052] INFO: Test took 3857ms.
[19:18:39.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:18:39.442] INFO: enter test to run
[19:18:48.408] INFO: test: HighRate no parameter change
[19:18:48.408] INFO: running: highrate
[19:18:48.409] INFO: ----------------------------------------------------------------------
[19:18:48.409] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:18:48.409] INFO: ----------------------------------------------------------------------
[19:18:49.051] INFO: Expecting 208000 events.
[19:19:01.506] INFO: 208000 events read in total (11928ms).
[19:19:01.510] INFO: Test took 13069ms.
[19:19:01.692] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:19:01.957] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[19:19:01.974] INFO: number of red-efficiency pixels: 90 68 139 190 249 196 246 124 100 200 190 110 117 94 30 43
[19:19:01.974] INFO: number of X-ray hits detected: 79332 54183 81939 139401 149304 147111 143111 100876 89248 126074 126039 109510 108800 66383 27317 30443
[19:19:01.974] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:19:01.974] INFO: number of Vcal hits detected: 207809 207931 207858 207805 207747 207800 207745 207872 207899 207795 207803 207885 207878 207905 207969 207853
[19:19:01.974] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[19:19:01.974] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9
[19:19:01.974] INFO: X-ray hit rate [MHz/cm2]: 23.3 15.9 24.0 40.9 43.8 43.1 41.9 29.6 26.2 37.0 36.9 32.1 31.9 19.5 8.0 8.9
[19:19:01.974] INFO: PixTestHighRate::doXPixelAlive() done
[19:19:02.023] INFO: PixTest:: pg_setup set to default.
[19:19:02.035] INFO: enter test to run
[19:19:17.215] INFO: test: HighRate no parameter change
[19:19:17.215] INFO: running: highrate
[19:19:17.217] INFO: ----------------------------------------------------------------------
[19:19:17.217] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:19:17.217] INFO: ----------------------------------------------------------------------
[19:19:17.842] INFO: Expecting 208000 events.
[19:19:33.361] INFO: 208000 events read in total (14992ms).
[19:19:33.368] INFO: Test took 16142ms.
[19:19:33.784] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:19:34.127] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[19:19:34.127] INFO: number of red-efficiency pixels: 409 226 518 825 1187 856 1100 498 352 874 889 462 477 391 74 100
[19:19:34.127] INFO: number of X-ray hits detected: 182824 124341 187924 319864 341621 336921 327014 232938 204435 288987 289934 249526 250389 152112 63064 69998
[19:19:34.127] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:19:34.127] INFO: number of Vcal hits detected: 207443 207756 207368 207040 206499 207000 206612 207426 207618 206991 206962 207478 207451 207525 207924 207795
[19:19:34.128] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.3 99.6 99.4 99.7 99.8 99.6 99.5 99.8 99.8 99.8 100.0 100.0
[19:19:34.128] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.5 99.3 99.5 99.3 99.7 99.8 99.5 99.5 99.7 99.7 99.8 100.0 99.9
[19:19:34.128] INFO: X-ray hit rate [MHz/cm2]: 53.6 36.4 55.1 93.8 100.1 98.8 95.9 68.3 59.9 84.7 85.0 73.1 73.4 44.6 18.5 20.5
[19:19:34.128] INFO: PixTestHighRate::doXPixelAlive() done
[19:19:34.173] INFO: PixTest:: pg_setup set to default.
[19:19:34.192] INFO: enter test to run
[19:19:54.167] INFO: test: HighRate no parameter change
[19:19:54.167] INFO: running: highrate
[19:19:54.168] INFO: ----------------------------------------------------------------------
[19:19:54.168] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:19:54.168] INFO: ----------------------------------------------------------------------
[19:19:54.798] INFO: Expecting 208000 events.
[19:20:13.295] INFO: 208000 events read in total (17971ms).
[19:20:13.305] INFO: Test took 19126ms.
[19:20:13.955] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:20:14.367] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[19:20:14.367] INFO: number of red-efficiency pixels: 902 563 1132 1987 2635 1997 2455 1204 765 1946 2072 1121 1138 887 123 142
[19:20:14.367] INFO: number of X-ray hits detected: 278514 189342 286681 487684 520007 512573 498693 356253 312667 440772 441209 382496 381100 232468 95990 107197
[19:20:14.367] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:20:14.367] INFO: number of Vcal hits detected: 206650 207314 206056 204836 202920 204722 203611 206115 207029 204941 204676 206556 206537 206687 207873 207749
[19:20:14.367] INFO: Vcal hit fiducial efficiency (%): 99.5 99.7 99.2 98.7 97.8 98.6 98.1 99.2 99.6 98.7 98.5 99.4 99.4 99.4 99.9 99.9
[19:20:14.367] INFO: Vcal hit overall efficiency (%): 99.4 99.7 99.1 98.5 97.6 98.4 97.9 99.1 99.5 98.5 98.4 99.3 99.3 99.4 99.9 99.9
[19:20:14.367] INFO: X-ray hit rate [MHz/cm2]: 81.6 55.5 84.0 142.9 152.4 150.2 146.2 104.4 91.6 129.2 129.3 112.1 111.7 68.1 28.1 31.4
[19:20:14.367] INFO: PixTestHighRate::doXPixelAlive() done
[19:20:14.414] INFO: PixTest:: pg_setup set to default.
[19:20:14.431] INFO: enter test to run
[19:20:18.167] INFO: test: exit no parameter change
[19:20:19.317] QUIET: Connection to board 32 closed.
[19:20:19.544] INFO: pXar: this is the end, my friend