[13:07:47.023] INFO: *** Welcome to pxar ***
[13:07:47.023] INFO: *** Today: 2016/05/25
[13:07:47.045] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:07:47.045] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//dacParameters35_C15.dat
[13:07:47.046] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:07:47.046] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//defaultMaskFile.dat
[13:07:47.046] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C15.dat
[13:07:47.117] INFO: clk: 4
[13:07:47.117] INFO: ctr: 4
[13:07:47.117] INFO: sda: 19
[13:07:47.117] INFO: tin: 9
[13:07:47.117] INFO: level: 15
[13:07:47.117] INFO: triggerdelay: 0
[13:07:47.117] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:07:47.117] INFO: Log level: INFO
[13:07:47.134] QUIET: Connection to board DTB_WREKRL opened.
[13:07:47.138] 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:
------------------------------------------------------
[13:07:47.141] INFO: RPC call hashes of host and DTB match: 398089610
[13:07:48.672] INFO: DUT info:
[13:07:48.672] INFO: The DUT currently contains the following objects:
[13:07:48.672] INFO: 2 TBM Cores tbm08c (2 ON)
[13:07:48.672] INFO: TBM Core alpha (0): 7 registers set
[13:07:48.672] INFO: TBM Core beta (1): 7 registers set
[13:07:48.672] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:07:48.672] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.672] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.673] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:48.673] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:49.076] INFO: enter 'restricted' command line mode
[13:07:49.076] INFO: enter test to run
[13:07:50.360] INFO: test: timing no parameter change
[13:07:50.360] INFO: running: timing
[13:07:50.369] INFO: ######################################################################
[13:07:50.369] INFO: PixTestTiming::doTest()
[13:07:50.369] INFO: ######################################################################
[13:07:50.369] INFO: ----------------------------------------------------------------------
[13:07:50.370] INFO: PixTestTiming::TBMPhaseScan()
[13:07:50.370] INFO: ----------------------------------------------------------------------
[13:12:14.982] INFO: TBM Phase Settings: 244
[13:12:14.982] INFO: 400MHz Phase: 5
[13:12:14.982] INFO: 160MHz Phase: 7
[13:12:14.982] INFO: Functional Phase Area: 5
[13:12:14.986] INFO: Test took 264617 ms.
[13:12:14.986] INFO: PixTestTiming::TBMPhaseScan() done.
[13:12:14.986] INFO: ----------------------------------------------------------------------
[13:12:14.986] INFO: PixTestTiming::ROCDelayScan()
[13:12:14.986] INFO: ----------------------------------------------------------------------
[13:14:19.112] INFO: ROC Delay Settings: 228
[13:14:19.112] INFO: ROC Header-Trailer/Token Delay: 11
[13:14:19.112] INFO: ROC Port 0 Delay: 4
[13:14:19.112] INFO: ROC Port 1 Delay: 4
[13:14:19.113] INFO: Functional ROC Area: 5
[13:14:19.116] INFO: Test took 124130 ms.
[13:14:19.116] INFO: PixTestTiming::ROCDelayScan() done.
[13:14:19.116] INFO: ----------------------------------------------------------------------
[13:14:19.116] INFO: PixTestTiming::TimingTest()
[13:14:19.116] INFO: ----------------------------------------------------------------------
[13:14:34.863] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:14:49.712] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:04.648] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:19.508] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:34.428] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:49.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:04.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:19.206] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:34.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:48.945] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:49.327] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:49.344] INFO: ----------------------------------------------------------------------
[13:16:49.344] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[13:16:49.344] INFO: ----------------------------------------------------------------------
[13:16:49.344] INFO: ----------------------------------------------------------------------
[13:16:49.344] INFO: Read back bit status: 1
[13:16:49.344] INFO: ----------------------------------------------------------------------
[13:16:49.344] INFO: ----------------------------------------------------------------------
[13:16:49.344] INFO: Timings are good!
[13:16:49.344] INFO: ----------------------------------------------------------------------
[13:16:49.344] INFO: Test took 150228 ms.
[13:16:49.344] INFO: PixTestTiming::TimingTest() done.
[13:16:49.345] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//tbmParameters_C0a.dat
[13:16:49.345] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:16:49.345] INFO: PixTestTiming::doTest took 538980 ms.
[13:16:49.345] INFO: PixTestTiming::doTest() done
[13:16:49.345] INFO: Write out TBMPhaseScan_0_V0
[13:16:49.371] INFO: Write out TBMPhaseScan_1_V0
[13:16:49.371] INFO: Write out CombinedTBMPhaseScan_V0
[13:16:49.371] INFO: Write out ROCDelayScan3_V0
[13:16:49.372] INFO: enter test to run
[13:17:07.261] INFO: test: PixelAlive no parameter change
[13:17:07.261] INFO: running: pixelalive
[13:17:07.265] INFO: ----------------------------------------------------------------------
[13:17:07.265] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:17:07.265] INFO: ----------------------------------------------------------------------
[13:17:07.582] INFO: Expecting 41600 events.
[13:17:11.775] INFO: 41600 events read in total (3477ms).
[13:17:11.776] INFO: Test took 4509ms.
[13:17:11.782] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:17:12.180] INFO: PixTestAlive::aliveTest() done
[13:17:12.180] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0 0
[13:17:12.182] INFO: enter test to run
[13:17:39.285] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:17:39.285] INFO: running: highrate
[13:17:39.285] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:17:39.434] INFO: ----------------------------------------------------------------------
[13:17:39.434] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:17:39.434] INFO: ----------------------------------------------------------------------
[13:17:39.434] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:17:39.434] INFO: edge/corner pixel THR is adjusted
[13:17:39.434] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:17:40.392] INFO: Collecting data for 5 seconds...
[13:17:45.408] INFO: Done with hot pixel readout
[13:17:57.487] INFO: PixTest:: pg_setup set to default.


















[13:17:57.488] INFO: 80 hot pixels found in step 0
[13:17:58.487] INFO: Collecting data for 5 seconds...
[13:18:03.503] INFO: Done with hot pixel readout
[13:18:16.107] INFO: PixTest:: pg_setup set to default.















[13:18:16.108] INFO: 58 hot pixels found in step 1
[13:18:17.107] INFO: Collecting data for 5 seconds...
[13:18:22.123] INFO: Done with hot pixel readout
[13:18:34.681] INFO: PixTest:: pg_setup set to default.




















[13:18:34.682] INFO: 67 hot pixels found in step 2
[13:18:35.683] INFO: Collecting data for 5 seconds...
[13:18:40.700] INFO: Done with hot pixel readout
[13:18:52.963] INFO: PixTest:: pg_setup set to default.














[13:18:52.965] INFO: 66 hot pixels found in step 3
[13:18:53.964] INFO: Collecting data for 5 seconds...
[13:18:58.980] INFO: Done with hot pixel readout
[13:19:11.214] INFO: PixTest:: pg_setup set to default.


















[13:19:11.215] INFO: 61 hot pixels found in step 4
[13:19:12.214] INFO: Collecting data for 5 seconds...
[13:19:17.230] INFO: Done with hot pixel readout
[13:19:29.541] INFO: PixTest:: pg_setup set to default.













[13:19:29.542] INFO: 56 hot pixels found in step 5
[13:19:30.543] INFO: Collecting data for 5 seconds...
[13:19:35.558] INFO: Done with hot pixel readout
[13:19:47.923] INFO: PixTest:: pg_setup set to default.

















[13:19:47.924] INFO: 60 hot pixels found in step 6
[13:19:48.923] INFO: Collecting data for 5 seconds...
[13:19:53.938] INFO: Done with hot pixel readout
[13:20:06.491] INFO: PixTest:: pg_setup set to default.















[13:20:06.492] INFO: 46 hot pixels found in step 7
[13:20:07.494] INFO: Collecting data for 5 seconds...
[13:20:12.509] INFO: Done with hot pixel readout
[13:20:25.109] INFO: PixTest:: pg_setup set to default.














[13:20:25.111] INFO: 59 hot pixels found in step 8
[13:20:26.110] INFO: Collecting data for 5 seconds...
[13:20:31.126] INFO: Done with hot pixel readout
[13:20:43.416] INFO: PixTest:: pg_setup set to default.

















[13:20:43.418] INFO: 52 hot pixels found in step 9
[13:20:44.418] INFO: Collecting data for 5 seconds...
[13:20:49.434] INFO: Done with hot pixel readout
[13:21:01.522] INFO: PixTest:: pg_setup set to default.













[13:21:01.523] INFO: 51 hot pixels found in step 10
[13:21:02.523] INFO: Collecting data for 5 seconds...
[13:21:07.539] INFO: Done with hot pixel readout
[13:21:19.399] INFO: PixTest:: pg_setup set to default.
















[13:21:19.400] INFO: 40 hot pixels found in step 11
[13:21:20.399] INFO: Collecting data for 5 seconds...
[13:21:25.416] INFO: Done with hot pixel readout
[13:21:36.800] INFO: PixTest:: pg_setup set to default.


















[13:21:36.801] INFO: 45 hot pixels found in step 12
[13:21:37.804] INFO: Collecting data for 5 seconds...
[13:21:42.821] INFO: Done with hot pixel readout
[13:21:55.231] INFO: PixTest:: pg_setup set to default.













[13:21:55.232] INFO: 42 hot pixels found in step 13
[13:21:56.231] INFO: Collecting data for 5 seconds...
[13:22:01.246] INFO: Done with hot pixel readout
[13:22:13.341] INFO: PixTest:: pg_setup set to default.












[13:22:13.342] INFO: 39 hot pixels found in step 14
[13:22:13.387] INFO: 39 hot pixels could not be trimmed and have been masked.
[13:22:13.390] INFO: PixTest::trimHotPixels() done
[13:22:13.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C0.dat
[13:22:13.397] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C1.dat
[13:22:13.403] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C2.dat
[13:22:13.409] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C3.dat
[13:22:13.414] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C4.dat
[13:22:13.419] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C5.dat
[13:22:13.425] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C6.dat
[13:22:13.431] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C7.dat
[13:22:13.436] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C8.dat
[13:22:13.442] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C9.dat
[13:22:13.447] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C10.dat
[13:22:13.453] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C11.dat
[13:22:13.458] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C12.dat
[13:22:13.464] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C13.dat
[13:22:13.469] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C14.dat
[13:22:13.475] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C15.dat
[13:22:13.480] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//defaultMaskFile.dat
[13:22:13.491] INFO: enter test to run
[13:22:35.338] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:22:35.338] INFO: running: highrate
[13:22:35.343] INFO: ----------------------------------------------------------------------
[13:22:35.343] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:22:35.343] INFO: ----------------------------------------------------------------------
[13:22:35.343] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:22:35.343] INFO: edge/corner pixel THR is adjusted
[13:22:35.343] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:22:36.300] INFO: Collecting data for 1 seconds...
[13:22:37.304] INFO: Done with hot pixel readout
[13:22:41.656] INFO: PixTest:: pg_setup set to default.
[13:22:41.657] INFO: 0 hot pixels found in step 0
[13:22:41.662] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:22:41.729] INFO: PixTest::trimHotPixels() done
[13:22:41.730] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C0.dat
[13:22:41.741] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C1.dat
[13:22:41.751] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C2.dat
[13:22:41.756] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C3.dat
[13:22:41.762] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C4.dat
[13:22:41.767] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C5.dat
[13:22:41.773] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C6.dat
[13:22:41.778] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C7.dat
[13:22:41.784] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C8.dat
[13:22:41.789] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C9.dat
[13:22:41.795] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C10.dat
[13:22:41.800] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C11.dat
[13:22:41.806] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C12.dat
[13:22:41.811] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C13.dat
[13:22:41.817] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C14.dat
[13:22:41.822] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//trimParameters35_C15.dat
[13:22:41.828] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-B-NY_FPIXTest-17C-FNAL-160519-0937_2016-05-19_09h38m_1463668705/000_FPIXTest_p17//defaultMaskFile.dat
[13:22:41.837] INFO: enter test to run
[13:23:02.170] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:23:02.170] INFO: running: xray
[13:23:02.171] INFO: ----------------------------------------------------------------------
[13:23:02.171] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:23:02.171] INFO: ----------------------------------------------------------------------
[13:23:03.134] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:23:13.442] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[13:23:42.645] INFO: Resuming triggers.
[13:23:52.958] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:24:21.855] INFO: Resuming triggers.
[13:24:32.167] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[13:25:01.207] INFO: Resuming triggers.
[13:25:11.519] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[13:25:40.512] INFO: Resuming triggers.
[13:25:50.825] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[13:26:19.788] INFO: Resuming triggers.
[13:26:30.103] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:26:59.040] INFO: Resuming triggers.
[13:27:09.354] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:27:38.463] INFO: Resuming triggers.
[13:27:48.782] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:28:17.694] INFO: Resuming triggers.
[13:28:28.008] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[13:28:57.016] INFO: Resuming triggers.
[13:29:04.509] INFO: data taking finished, elapsed time: 100 seconds.
[13:29:26.026] INFO: PixTest:: pg_setup set to default.
[13:29:26.029] INFO: PixTestXray::doPhRun() done
[13:29:26.186] INFO: enter test to run
[13:30:03.807] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:30:03.807] INFO: running: xray
[13:30:03.808] INFO: ----------------------------------------------------------------------
[13:30:03.808] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:30:03.808] INFO: ----------------------------------------------------------------------
[13:30:04.772] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:30:10.419] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[13:30:40.186] INFO: Resuming triggers.
[13:30:45.836] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:31:15.483] INFO: Resuming triggers.
[13:31:21.133] INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[13:31:50.830] INFO: Resuming triggers.
[13:31:56.478] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:32:26.219] INFO: Resuming triggers.
[13:32:31.867] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[13:33:01.442] INFO: Resuming triggers.
[13:33:07.090] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:33:36.807] INFO: Resuming triggers.
[13:33:42.457] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[13:34:12.267] INFO: Resuming triggers.
[13:34:17.914] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:34:48.331] INFO: Resuming triggers.
[13:34:53.978] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[13:35:22.894] INFO: Resuming triggers.
[13:35:28.542] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:35:58.176] INFO: Resuming triggers.
[13:36:03.824] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:36:33.454] INFO: Resuming triggers.
[13:36:39.107] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:37:08.608] INFO: Resuming triggers.
[13:37:14.263] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[13:37:43.884] INFO: Resuming triggers.
[13:37:49.537] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[13:38:19.184] INFO: Resuming triggers.
[13:38:24.835] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[13:38:53.746] INFO: Resuming triggers.
[13:38:59.400] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[13:39:29.086] INFO: Resuming triggers.
[13:39:34.740] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[13:40:04.396] INFO: Resuming triggers.
[13:40:08.660] INFO: data taking finished, elapsed time: 100 seconds.
[13:40:31.190] INFO: PixTest:: pg_setup set to default.
[13:40:31.193] INFO: PixTestXray::doPhRun() done
[13:40:31.343] INFO: enter test to run
[13:41:26.946] INFO: test: HighRate no parameter change
[13:41:26.946] INFO: running: highrate
[13:41:26.963] INFO: ----------------------------------------------------------------------
[13:41:26.963] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:41:26.963] INFO: ----------------------------------------------------------------------
[13:41:27.127] INFO: Expecting 768 events.
[13:41:28.259] INFO: 768 events read in total (417ms).
[13:41:28.260] INFO: Test took 1268ms.
[13:41:29.063] INFO: Expecting 41600 events.
[13:41:32.283] INFO: 41600 events read in total (2693ms).
[13:41:32.284] INFO: Test took 4016ms.
[13:41:32.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:33.032] INFO: Expecting 41600 events.
[13:41:36.354] INFO: 41600 events read in total (2796ms).
[13:41:36.355] INFO: Test took 4004ms.
[13:41:36.399] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:37.101] INFO: Expecting 41600 events.
[13:41:40.391] INFO: 41600 events read in total (2765ms).
[13:41:40.393] INFO: Test took 3973ms.
[13:41:40.438] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:41.144] INFO: Expecting 41600 events.
[13:41:44.455] INFO: 41600 events read in total (2784ms).
[13:41:44.456] INFO: Test took 3995ms.
[13:41:44.500] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:45.205] INFO: Expecting 41600 events.
[13:41:48.524] INFO: 41600 events read in total (2793ms).
[13:41:48.526] INFO: Test took 4006ms.
[13:41:48.570] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:49.274] INFO: Expecting 41600 events.
[13:41:52.506] INFO: 41600 events read in total (2705ms).
[13:41:52.507] INFO: Test took 3915ms.
[13:41:52.551] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:53.253] INFO: Expecting 41600 events.
[13:41:56.152] INFO: 41600 events read in total (2373ms).
[13:41:56.153] INFO: Test took 3580ms.
[13:41:56.198] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:56.905] INFO: Expecting 41600 events.
[13:42:00.198] INFO: 41600 events read in total (2766ms).
[13:42:00.199] INFO: Test took 3980ms.
[13:42:00.244] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:00.952] INFO: Expecting 41600 events.
[13:42:04.256] INFO: 41600 events read in total (2777ms).
[13:42:04.257] INFO: Test took 3992ms.
[13:42:04.302] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:05.006] INFO: Expecting 41600 events.
[13:42:08.333] INFO: 41600 events read in total (2800ms).
[13:42:08.335] INFO: Test took 4013ms.
[13:42:08.379] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:09.080] INFO: Expecting 41600 events.
[13:42:12.211] INFO: 41600 events read in total (2604ms).
[13:42:12.212] INFO: Test took 3811ms.
[13:42:12.257] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:12.961] INFO: Expecting 41600 events.
[13:42:16.184] INFO: 41600 events read in total (2696ms).
[13:42:16.186] INFO: Test took 3908ms.
[13:42:16.229] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:16.933] INFO: Expecting 41600 events.
[13:42:20.229] INFO: 41600 events read in total (2769ms).
[13:42:20.230] INFO: Test took 3979ms.
[13:42:20.275] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:20.980] INFO: Expecting 41600 events.
[13:42:24.322] INFO: 41600 events read in total (2815ms).
[13:42:24.323] INFO: Test took 4025ms.
[13:42:24.368] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:25.073] INFO: Expecting 41600 events.
[13:42:28.391] INFO: 41600 events read in total (2791ms).
[13:42:28.392] INFO: Test took 4003ms.
[13:42:28.437] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:29.141] INFO: Expecting 41600 events.
[13:42:32.457] INFO: 41600 events read in total (2789ms).
[13:42:32.458] INFO: Test took 3998ms.
[13:42:32.503] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:33.206] INFO: Expecting 41600 events.
[13:42:36.354] INFO: 41600 events read in total (2621ms).
[13:42:36.355] INFO: Test took 3830ms.
[13:42:36.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:37.101] INFO: Expecting 41600 events.
[13:42:40.404] INFO: 41600 events read in total (2777ms).
[13:42:40.405] INFO: Test took 3982ms.
[13:42:40.449] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:41.156] INFO: Expecting 41600 events.
[13:42:44.456] INFO: 41600 events read in total (2773ms).
[13:42:44.458] INFO: Test took 3987ms.
[13:42:44.502] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:45.205] INFO: Expecting 41600 events.
[13:42:48.307] INFO: 41600 events read in total (2575ms).
[13:42:48.309] INFO: Test took 3784ms.
[13:42:48.351] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:48.696] INFO: enter test to run
[13:43:12.609] INFO: test: HighRate no parameter change
[13:43:12.609] INFO: running: highrate
[13:43:12.610] INFO: ----------------------------------------------------------------------
[13:43:12.610] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:43:12.610] INFO: ----------------------------------------------------------------------
[13:43:13.223] INFO: Expecting 208000 events.
[13:43:25.198] INFO: 208000 events read in total (11448ms).
[13:43:25.202] INFO: Test took 12583ms.
[13:43:25.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:25.676] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0 0
[13:43:25.676] INFO: number of red-efficiency pixels: 127 60 156 217 245 180 205 173 113 146 186 165 130 96 37 45
[13:43:25.676] INFO: number of X-ray hits detected: 88973 61396 95037 153542 166097 155893 160785 117116 98688 129769 136465 118668 118754 73574 29662 36664
[13:43:25.676] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:43:25.676] INFO: number of Vcal hits detected: 207871 207938 207839 207775 207739 207813 207788 207824 207885 207852 207811 207833 207865 207706 207963 207955
[13:43:25.676] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[13:43:25.676] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[13:43:25.676] INFO: X-ray hit rate [MHz/cm2]: 26.1 18.0 27.9 45.0 48.7 45.7 47.1 34.3 28.9 38.0 40.0 34.8 34.8 21.6 8.7 10.7
[13:43:25.676] INFO: PixTestHighRate::doXPixelAlive() done
[13:43:25.726] INFO: PixTest:: pg_setup set to default.
[13:43:25.742] INFO: enter test to run
[13:44:07.505] INFO: test: HighRate no parameter change
[13:44:07.505] INFO: running: highrate
[13:44:07.506] INFO: ----------------------------------------------------------------------
[13:44:07.506] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:44:07.506] INFO: ----------------------------------------------------------------------
[13:44:08.126] INFO: Expecting 208000 events.
[13:44:22.539] INFO: 208000 events read in total (13887ms).
[13:44:22.546] INFO: Test took 15031ms.
[13:44:22.929] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:44:23.255] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0 0
[13:44:23.255] INFO: number of red-efficiency pixels: 356 202 473 731 735 688 715 562 289 441 469 515 354 212 64 88
[13:44:23.255] INFO: number of X-ray hits detected: 168155 116951 180178 291273 314148 294568 304652 220693 188694 244712 260228 225159 225185 139474 57164 70138
[13:44:23.255] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:44:23.256] INFO: number of Vcal hits detected: 207604 207785 207438 207145 207112 207216 207181 207333 207693 207523 207499 207430 207623 207582 207934 207909
[13:44:23.256] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.6 99.7 99.6 99.7 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[13:44:23.256] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.7 99.6 99.6 99.6 99.6 99.7 99.9 99.8 99.8 99.7 99.8 99.8 100.0 100.0
[13:44:23.256] INFO: X-ray hit rate [MHz/cm2]: 49.3 34.3 52.8 85.4 92.1 86.3 89.3 64.7 55.3 71.7 76.3 66.0 66.0 40.9 16.8 20.6
[13:44:23.256] INFO: PixTestHighRate::doXPixelAlive() done
[13:44:23.301] INFO: PixTest:: pg_setup set to default.
[13:44:23.313] INFO: enter test to run
[13:45:15.761] INFO: test: HighRate no parameter change
[13:45:15.761] INFO: running: highrate
[13:45:15.762] INFO: ----------------------------------------------------------------------
[13:45:15.762] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:45:15.762] INFO: ----------------------------------------------------------------------
[13:45:16.381] INFO: Expecting 208000 events.
[13:45:33.369] INFO: 208000 events read in total (16461ms).
[13:45:33.378] INFO: Test took 17607ms.
[13:45:33.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:34.375] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 4 0 0
[13:45:34.376] INFO: number of red-efficiency pixels: 760 390 1080 1791 1838 1724 1742 1371 675 1096 1290 1287 919 577 132 172
[13:45:34.376] INFO: number of X-ray hits detected: 261699 182893 280066 453498 489814 457672 473789 345324 293580 380203 404476 349670 351020 216304 89379 109932
[13:45:34.376] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:45:34.376] INFO: number of Vcal hits detected: 206949 207554 206119 205259 205135 205500 205337 205844 207199 206637 206321 206317 206883 207085 207861 207820
[13:45:34.376] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.2 98.8 98.8 98.9 98.9 99.1 99.6 99.4 99.2 99.3 99.5 99.7 99.9 99.9
[13:45:34.376] INFO: Vcal hit overall efficiency (%): 99.5 99.8 99.1 98.7 98.6 98.8 98.7 99.0 99.6 99.3 99.2 99.2 99.5 99.6 99.9 99.9
[13:45:34.376] INFO: X-ray hit rate [MHz/cm2]: 76.7 53.6 82.1 132.9 143.6 134.1 138.9 101.2 86.1 111.4 118.6 102.5 102.9 63.4 26.2 32.2
[13:45:34.376] INFO: PixTestHighRate::doXPixelAlive() done
[13:45:34.422] INFO: PixTest:: pg_setup set to default.
[13:45:34.443] INFO: enter test to run
[13:45:44.744] INFO: test: exit no parameter change
[13:45:45.134] QUIET: Connection to board 33 closed.
[13:45:45.149] INFO: pXar: this is the end, my friend