[13:30:43.226] INFO: *** Welcome to pxar ***
[13:30:43.226] INFO: *** Today: 2016/10/17
[13:30:45.725] INFO: *** Version: v1.9.0-818-g96727
[13:30:45.725] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//dacParameters35_C15.dat
[13:30:45.875] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:30:45.875] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//defaultMaskFile.dat
[13:30:45.891] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C15.dat
[13:30:46.374] INFO: clk: 4
[13:30:46.374] INFO: ctr: 4
[13:30:46.374] INFO: sda: 19
[13:30:46.374] INFO: tin: 9
[13:30:46.374] INFO: level: 15
[13:30:46.374] INFO: triggerdelay: 0
[13:30:46.374] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:30:46.374] INFO: Log level: INFO
[13:30:46.423] QUIET: Connection to board DTB_WREKRL opened.
[13:30:46.427] 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:30:46.429] INFO: RPC call hashes of host and DTB match: 398089610
[13:30:47.981] INFO: DUT info:
[13:30:47.981] INFO: The DUT currently contains the following objects:
[13:30:47.981] INFO: 2 TBM Cores tbm08c (2 ON)
[13:30:47.981] INFO: TBM Core alpha (0): 7 registers set
[13:30:47.981] INFO: TBM Core beta (1): 7 registers set
[13:30:47.981] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:30:47.981] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.981] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.981] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.981] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.981] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.981] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.982] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.982] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.982] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.982] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.982] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.982] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.982] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.982] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.982] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:47.982] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:30:48.498] INFO: enter 'restricted' command line mode
[13:30:48.498] INFO: enter test to run
[13:30:58.771] INFO: test: PixelAlive no parameter change
[13:30:58.771] INFO: running: pixelalive
[13:30:58.901] INFO: ----------------------------------------------------------------------
[13:30:58.901] 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:30:58.901] INFO: ----------------------------------------------------------------------
[13:30:59.221] INFO: Expecting 41600 events.
[13:31:03.627] INFO: 41600 events read in total (3688ms).
[13:31:03.795] INFO: Test took 4891ms.
[13:31:03.808] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:31:05.170] INFO: PixTestAlive::aliveTest() done
[13:31:05.170] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:31:05.467] INFO: enter test to run
[13:31:10.811] INFO: test: timing no parameter change
[13:31:10.811] INFO: running: timing
[13:31:10.814] INFO: ######################################################################
[13:31:10.814] INFO: PixTestTiming::doTest()
[13:31:10.814] INFO: ######################################################################
[13:31:10.815] INFO: ----------------------------------------------------------------------
[13:31:10.815] INFO: PixTestTiming::TBMPhaseScan()
[13:31:10.815] INFO: ----------------------------------------------------------------------
[13:36:00.062] INFO: TBM Phase Settings: 232
[13:36:00.062] INFO: 400MHz Phase: 2
[13:36:00.062] INFO: 160MHz Phase: 7
[13:36:00.062] INFO: Functional Phase Area: 3
[13:36:00.082] INFO: Test took 289267 ms.
[13:36:00.082] INFO: PixTestTiming::TBMPhaseScan() done.
[13:36:00.082] INFO: ----------------------------------------------------------------------
[13:36:00.082] INFO: PixTestTiming::ROCDelayScan()
[13:36:00.082] INFO: ----------------------------------------------------------------------
[13:38:05.181] INFO: ROC Delay Settings: 228
[13:38:05.181] INFO: ROC Header-Trailer/Token Delay: 11
[13:38:05.181] INFO: ROC Port 0 Delay: 4
[13:38:05.181] INFO: ROC Port 1 Delay: 4
[13:38:05.181] INFO: Functional ROC Area: 5
[13:38:05.184] INFO: Test took 125102 ms.
[13:38:05.184] INFO: PixTestTiming::ROCDelayScan() done.
[13:38:05.185] INFO: ----------------------------------------------------------------------
[13:38:05.185] INFO: PixTestTiming::TimingTest()
[13:38:05.185] INFO: ----------------------------------------------------------------------
[13:38:21.267] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:36.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:51.187] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:06.256] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:21.268] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:36.307] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:51.342] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:06.354] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:21.426] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:36.557] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:36.937] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:36.954] INFO: ----------------------------------------------------------------------
[13:40:36.954] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[13:40:36.954] INFO: ----------------------------------------------------------------------
[13:40:36.954] INFO: ----------------------------------------------------------------------
[13:40:36.954] INFO: Read back bit status: 1
[13:40:36.954] INFO: ----------------------------------------------------------------------
[13:40:36.954] INFO: ----------------------------------------------------------------------
[13:40:36.954] INFO: Timings are good!
[13:40:36.954] INFO: ----------------------------------------------------------------------
[13:40:36.954] INFO: Test took 151770 ms.
[13:40:36.954] INFO: PixTestTiming::TimingTest() done.
[13:40:36.970] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//tbmParameters_C0a.dat
[13:40:36.970] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:40:36.970] INFO: PixTestTiming::doTest took 566159 ms.
[13:40:36.970] INFO: PixTestTiming::doTest() done
[13:40:36.970] INFO: Write out TBMPhaseScan_0_V0
[13:40:36.970] INFO: Write out TBMPhaseScan_1_V0
[13:40:36.970] INFO: Write out CombinedTBMPhaseScan_V0
[13:40:36.971] INFO: Write out ROCDelayScan3_V0
[13:40:36.972] INFO: enter test to run
[13:44:03.694] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:44:03.694] INFO: running: highrate
[13:44:03.760] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:44:04.034] INFO: ----------------------------------------------------------------------
[13:44:04.034] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:44:04.034] INFO: ----------------------------------------------------------------------
[13:44:04.034] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:44:04.034] INFO: edge/corner pixel THR is adjusted
[13:44:04.034] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:44:04.992] INFO: Collecting data for 5 seconds...
[13:44:10.011] INFO: Done with hot pixel readout
[13:44:21.970] INFO: PixTest:: pg_setup set to default.
[13:44:21.971] INFO: 2 hot pixels found in step 0
[13:44:22.962] INFO: Collecting data for 5 seconds...
[13:44:27.983] INFO: Done with hot pixel readout
[13:44:39.782] INFO: PixTest:: pg_setup set to default.
[13:44:39.782] INFO: 3 hot pixels found in step 1
[13:44:40.774] INFO: Collecting data for 5 seconds...
[13:44:45.796] INFO: Done with hot pixel readout
[13:44:57.342] INFO: PixTest:: pg_setup set to default.
[13:44:57.343] INFO: 3 hot pixels found in step 2
[13:44:58.334] INFO: Collecting data for 5 seconds...
[13:45:03.351] INFO: Done with hot pixel readout
[13:45:15.011] INFO: PixTest:: pg_setup set to default.
[13:45:15.011] INFO: 1 hot pixels found in step 3
[13:45:15.003] INFO: Collecting data for 5 seconds...
[13:45:21.020] INFO: Done with hot pixel readout
[13:45:32.316] INFO: PixTest:: pg_setup set to default.
[13:45:32.317] INFO: 1 hot pixels found in step 4
[13:45:33.307] INFO: Collecting data for 5 seconds...
[13:45:38.324] INFO: Done with hot pixel readout
[13:45:49.765] INFO: PixTest:: pg_setup set to default.
[13:45:49.765] INFO: 5 hot pixels found in step 5
[13:45:50.756] INFO: Collecting data for 5 seconds...
[13:45:55.773] INFO: Done with hot pixel readout
[13:46:07.211] INFO: PixTest:: pg_setup set to default.

[13:46:07.212] INFO: 3 hot pixels found in step 6
[13:46:08.203] INFO: Collecting data for 5 seconds...
[13:46:13.220] INFO: Done with hot pixel readout
[13:46:24.773] INFO: PixTest:: pg_setup set to default.
[13:46:24.774] INFO: 4 hot pixels found in step 7
[13:46:25.764] INFO: Collecting data for 5 seconds...
[13:46:30.780] INFO: Done with hot pixel readout
[13:46:42.297] INFO: PixTest:: pg_setup set to default.
[13:46:42.298] INFO: 2 hot pixels found in step 8
[13:46:43.289] INFO: Collecting data for 5 seconds...
[13:46:48.305] INFO: Done with hot pixel readout
[13:46:59.866] INFO: PixTest:: pg_setup set to default.
[13:46:59.867] INFO: 1 hot pixels found in step 9
[13:47:00.858] INFO: Collecting data for 5 seconds...
[13:47:05.874] INFO: Done with hot pixel readout
[13:47:17.509] INFO: PixTest:: pg_setup set to default.
[13:47:17.510] INFO: 1 hot pixels found in step 10
[13:47:18.503] INFO: Collecting data for 5 seconds...
[13:47:23.520] INFO: Done with hot pixel readout
[13:47:35.111] INFO: PixTest:: pg_setup set to default.
[13:47:35.112] INFO: 1 hot pixels found in step 11
[13:47:36.103] INFO: Collecting data for 5 seconds...
[13:47:41.119] INFO: Done with hot pixel readout
[13:47:52.700] INFO: PixTest:: pg_setup set to default.
[13:47:52.701] INFO: 1 hot pixels found in step 12
[13:47:53.691] INFO: Collecting data for 5 seconds...
[13:47:58.707] INFO: Done with hot pixel readout
[13:48:10.267] INFO: PixTest:: pg_setup set to default.
[13:48:10.268] INFO: 0 hot pixels found in step 13
[13:48:10.302] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:48:10.305] INFO: PixTest::trimHotPixels() done
[13:48:10.305] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C0.dat
[13:48:10.311] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C1.dat
[13:48:10.322] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C2.dat
[13:48:10.327] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C3.dat
[13:48:10.333] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C4.dat
[13:48:10.338] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C5.dat
[13:48:10.343] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C6.dat
[13:48:10.349] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C7.dat
[13:48:10.354] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C8.dat
[13:48:10.359] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C9.dat
[13:48:10.364] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C10.dat
[13:48:10.370] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C11.dat
[13:48:10.375] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C12.dat
[13:48:10.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C13.dat
[13:48:10.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C14.dat
[13:48:10.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C15.dat
[13:48:10.396] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//defaultMaskFile.dat
[13:48:10.405] INFO: enter test to run
[13:49:56.540] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:49:56.540] INFO: running: highrate
[13:49:56.544] INFO: ----------------------------------------------------------------------
[13:49:56.544] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:49:56.544] INFO: ----------------------------------------------------------------------
[13:49:56.544] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:49:56.544] INFO: edge/corner pixel THR is adjusted
[13:49:56.544] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:49:57.502] INFO: Collecting data for 1 seconds...
[13:49:58.506] INFO: Done with hot pixel readout
[13:50:02.520] INFO: PixTest:: pg_setup set to default.
[13:50:02.521] INFO: 0 hot pixels found in step 0
[13:50:02.526] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:50:02.613] INFO: PixTest::trimHotPixels() done
[13:50:02.614] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C0.dat
[13:50:02.621] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C1.dat
[13:50:02.627] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C2.dat
[13:50:02.633] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C3.dat
[13:50:02.638] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C4.dat
[13:50:02.643] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C5.dat
[13:50:02.649] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C6.dat
[13:50:02.654] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C7.dat
[13:50:02.659] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C8.dat
[13:50:02.664] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C9.dat
[13:50:02.669] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C10.dat
[13:50:02.675] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C11.dat
[13:50:02.680] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C12.dat
[13:50:02.685] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C13.dat
[13:50:02.691] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C14.dat
[13:50:02.696] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//trimParameters35_C15.dat
[13:50:02.701] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-28_FPIXTest-17C-FNAL-161014-1405-300V_2016-10-14_14h05m_1476471914/000_FPIXTest_p17//defaultMaskFile.dat
[13:50:02.710] INFO: enter test to run
[13:50:20.147] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:50:20.148] INFO: running: xray
[13:50:20.149] INFO: ----------------------------------------------------------------------
[13:50:20.149] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:50:20.149] INFO: ----------------------------------------------------------------------
[13:50:21.132] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:50:32.833] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:51:02.442] INFO: Resuming triggers.
[13:51:14.144] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:51:43.696] INFO: Resuming triggers.
[13:51:55.398] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:52:24.730] INFO: Resuming triggers.
[13:52:36.428] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:53:06.662] INFO: Resuming triggers.
[13:53:18.361] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:53:48.444] INFO: Resuming triggers.
[13:54:00.143] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:54:29.857] INFO: Resuming triggers.
[13:54:41.556] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:55:11.304] INFO: Resuming triggers.
[13:55:22.006] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:55:52.958] INFO: Resuming triggers.
[13:55:59.706] INFO: data taking finished, elapsed time: 100 seconds.
[13:56:17.058] INFO: PixTest:: pg_setup set to default.
[13:56:17.061] INFO: PixTestXray::doPhRun() done
[13:56:17.407] INFO: enter test to run
[13:58:49.624] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:58:49.624] INFO: running: xray
[13:58:49.625] INFO: ----------------------------------------------------------------------
[13:58:49.625] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:58:49.625] INFO: ----------------------------------------------------------------------
[13:58:50.588] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:58:57.368] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:59:29.210] INFO: Resuming triggers.
[13:59:35.991] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:00:07.287] INFO: Resuming triggers.
[14:00:14.069] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:00:44.427] INFO: Resuming triggers.
[14:00:51.210] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:01:21.576] INFO: Resuming triggers.
[14:01:28.360] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:01:58.674] INFO: Resuming triggers.
[14:02:05.460] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[14:02:35.743] INFO: Resuming triggers.
[14:02:42.530] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:03:12.855] INFO: Resuming triggers.
[14:03:19.641] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[14:03:49.888] INFO: Resuming triggers.
[14:03:56.671] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[14:04:26.004] INFO: Resuming triggers.
[14:04:33.787] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:05:04.027] INFO: Resuming triggers.
[14:05:10.808] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:05:41.141] INFO: Resuming triggers.
[14:05:47.925] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:06:18.411] INFO: Resuming triggers.
[14:06:25.193] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[14:06:55.504] INFO: Resuming triggers.
[14:07:02.287] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:07:33.145] INFO: Resuming triggers.
[14:07:38.518] INFO: data taking finished, elapsed time: 100 seconds.
[14:08:03.583] INFO: PixTest:: pg_setup set to default.
[14:08:03.587] INFO: PixTestXray::doPhRun() done
[14:08:03.738] INFO: enter test to run
[14:08:51.924] INFO: test: HighRate no parameter change
[14:08:51.924] INFO: running: highrate
[14:08:51.947] INFO: ----------------------------------------------------------------------
[14:08:51.947] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:08:51.947] INFO: ----------------------------------------------------------------------
[14:08:52.096] INFO: Expecting 768 events.
[14:08:53.249] INFO: 768 events read in total (437ms).
[14:08:53.249] INFO: Test took 1287ms.
[14:08:54.052] INFO: Expecting 41600 events.
[14:08:57.031] INFO: 41600 events read in total (2452ms).
[14:08:57.032] INFO: Test took 3687ms.
[14:08:57.063] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:57.795] INFO: Expecting 41600 events.
[14:09:00.995] INFO: 41600 events read in total (2674ms).
[14:09:00.996] INFO: Test took 3917ms.
[14:09:01.028] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:01.757] INFO: Expecting 41600 events.
[14:09:05.013] INFO: 41600 events read in total (2729ms).
[14:09:05.014] INFO: Test took 3969ms.
[14:09:05.049] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:05.770] INFO: Expecting 41600 events.
[14:09:09.070] INFO: 41600 events read in total (2773ms).
[14:09:09.071] INFO: Test took 4004ms.
[14:09:09.103] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:09.827] INFO: Expecting 41600 events.
[14:09:13.114] INFO: 41600 events read in total (2760ms).
[14:09:13.115] INFO: Test took 3993ms.
[14:09:13.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:13.874] INFO: Expecting 41600 events.
[14:09:17.121] INFO: 41600 events read in total (2720ms).
[14:09:17.122] INFO: Test took 3956ms.
[14:09:17.154] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:17.878] INFO: Expecting 41600 events.
[14:09:21.129] INFO: 41600 events read in total (2725ms).
[14:09:21.130] INFO: Test took 3958ms.
[14:09:21.163] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:21.887] INFO: Expecting 41600 events.
[14:09:25.142] INFO: 41600 events read in total (2728ms).
[14:09:25.143] INFO: Test took 3963ms.
[14:09:25.176] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:25.898] INFO: Expecting 41600 events.
[14:09:29.145] INFO: 41600 events read in total (2720ms).
[14:09:29.146] INFO: Test took 3953ms.
[14:09:29.178] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:29.902] INFO: Expecting 41600 events.
[14:09:33.156] INFO: 41600 events read in total (2728ms).
[14:09:33.157] INFO: Test took 3962ms.
[14:09:33.190] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:33.917] INFO: Expecting 41600 events.
[14:09:37.168] INFO: 41600 events read in total (2724ms).
[14:09:37.169] INFO: Test took 3962ms.
[14:09:37.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:37.921] INFO: Expecting 41600 events.
[14:09:41.163] INFO: 41600 events read in total (2715ms).
[14:09:41.164] INFO: Test took 3944ms.
[14:09:41.198] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:41.926] INFO: Expecting 41600 events.
[14:09:45.166] INFO: 41600 events read in total (2714ms).
[14:09:45.167] INFO: Test took 3950ms.
[14:09:45.200] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:45.921] INFO: Expecting 41600 events.
[14:09:49.104] INFO: 41600 events read in total (2656ms).
[14:09:49.105] INFO: Test took 3888ms.
[14:09:49.138] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:49.864] INFO: Expecting 41600 events.
[14:09:53.166] INFO: 41600 events read in total (2775ms).
[14:09:53.167] INFO: Test took 4010ms.
[14:09:53.200] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:53.919] INFO: Expecting 41600 events.
[14:09:57.168] INFO: 41600 events read in total (2722ms).
[14:09:57.170] INFO: Test took 3953ms.
[14:09:57.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:57.929] INFO: Expecting 41600 events.
[14:10:01.078] INFO: 41600 events read in total (2622ms).
[14:10:01.079] INFO: Test took 3853ms.
[14:10:01.112] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:01.836] INFO: Expecting 41600 events.
[14:10:05.097] INFO: 41600 events read in total (2734ms).
[14:10:05.098] INFO: Test took 3967ms.
[14:10:05.136] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:05.853] INFO: Expecting 41600 events.
[14:10:09.080] INFO: 41600 events read in total (2700ms).
[14:10:09.081] INFO: Test took 3928ms.
[14:10:09.114] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:09.838] INFO: Expecting 41600 events.
[14:10:12.869] INFO: 41600 events read in total (2504ms).
[14:10:12.870] INFO: Test took 3739ms.
[14:10:12.902] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:13.269] INFO: enter test to run
[14:12:50.730] INFO: test: HighRate no parameter change
[14:12:50.730] INFO: running: highrate
[14:12:50.731] INFO: ----------------------------------------------------------------------
[14:12:50.732] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:12:50.732] INFO: ----------------------------------------------------------------------
[14:12:51.351] INFO: Expecting 208000 events.
[14:13:03.505] INFO: 208000 events read in total (11627ms).
[14:13:03.508] INFO: Test took 12768ms.
[14:13:03.647] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:03.899] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:13:03.911] INFO: number of red-efficiency pixels: 91 55 88 145 295 118 147 100 95 110 122 81 97 52 14 25
[14:13:03.911] INFO: number of X-ray hits detected: 63584 38395 59779 98034 104227 105167 107169 78313 72168 90759 91656 75109 78510 46326 19053 20846
[14:13:03.911] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:13:03.911] INFO: number of Vcal hits detected: 207906 207923 207908 207849 202275 207879 207848 207899 207903 207889 207877 207918 207902 207932 207986 207975
[14:13:03.911] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 98.5 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:13:03.911] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 97.2 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:13:03.911] INFO: X-ray hit rate [MHz/cm2]: 18.6 11.3 17.5 28.7 30.5 30.8 31.4 23.0 21.2 26.6 26.9 22.0 23.0 13.6 5.6 6.1
[14:13:03.911] INFO: PixTestHighRate::doXPixelAlive() done
[14:13:03.958] INFO: PixTest:: pg_setup set to default.
[14:13:03.975] INFO: enter test to run
[14:13:12.682] INFO: test: HighRate no parameter change
[14:13:12.682] INFO: running: highrate
[14:13:12.683] INFO: ----------------------------------------------------------------------
[14:13:12.683] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:13:12.683] INFO: ----------------------------------------------------------------------
[14:13:13.299] INFO: Expecting 208000 events.
[14:13:27.331] INFO: 208000 events read in total (13506ms).
[14:13:27.336] INFO: Test took 14646ms.
[14:13:27.626] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:27.929] INFO: number of dead pixels (per ROC): 0 0 0 0 75 0 0 0 0 0 0 0 0 0 0 0
[14:13:27.929] INFO: number of red-efficiency pixels: 263 121 261 494 589 538 543 357 295 364 439 241 264 165 64 46
[14:13:27.929] INFO: number of X-ray hits detected: 140293 85535 132102 214925 225178 232790 235898 172360 158679 199775 201574 164961 173067 101983 42466 46166
[14:13:27.930] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:13:27.930] INFO: number of Vcal hits detected: 207723 207839 207703 207455 199671 207402 207409 207593 207682 207601 207529 207746 207726 207801 207936 207953
[14:13:27.930] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 98.8 99.7 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:13:27.930] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 96.0 99.7 99.7 99.8 99.8 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:13:27.930] INFO: X-ray hit rate [MHz/cm2]: 41.1 25.1 38.7 63.0 66.0 68.2 69.1 50.5 46.5 58.6 59.1 48.4 50.7 29.9 12.4 13.5
[14:13:27.930] INFO: PixTestHighRate::doXPixelAlive() done
[14:13:27.975] INFO: PixTest:: pg_setup set to default.
[14:13:27.990] INFO: enter test to run
[14:13:39.954] INFO: test: HighRate no parameter change
[14:13:39.954] INFO: running: highrate
[14:13:39.955] INFO: ----------------------------------------------------------------------
[14:13:39.955] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:13:39.955] INFO: ----------------------------------------------------------------------
[14:13:40.572] INFO: Expecting 208000 events.
[14:13:56.383] INFO: 208000 events read in total (15284ms).
[14:13:56.391] INFO: Test took 16427ms.
[14:13:56.823] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:57.173] INFO: number of dead pixels (per ROC): 0 0 0 0 29 0 0 0 0 0 0 0 0 0 0 0
[14:13:57.173] INFO: number of red-efficiency pixels: 572 221 692 1203 1157 1295 1380 890 684 844 1061 528 562 360 100 100
[14:13:57.173] INFO: number of X-ray hits detected: 215796 132487 202810 332355 338983 358556 363673 264444 246221 307799 309853 254514 266084 157027 65616 71133
[14:13:57.174] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:13:57.174] INFO: number of Vcal hits detected: 207266 207730 207083 206443 199035 206276 206139 206792 207200 207009 206664 207412 207370 207561 207900 207896
[14:13:57.174] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.3 97.9 99.3 99.2 99.5 99.6 99.6 99.4 99.7 99.7 99.8 100.0 100.0
[14:13:57.174] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.6 99.3 95.7 99.2 99.1 99.4 99.6 99.5 99.4 99.7 99.7 99.8 100.0 100.0
[14:13:57.174] INFO: X-ray hit rate [MHz/cm2]: 63.3 38.8 59.4 97.4 99.4 105.1 106.6 77.5 72.2 90.2 90.8 74.6 78.0 46.0 19.2 20.8
[14:13:57.174] INFO: PixTestHighRate::doXPixelAlive() done
[14:13:57.221] INFO: PixTest:: pg_setup set to default.
[14:13:57.236] INFO: enter test to run
[14:14:00.482] INFO: test: exit no parameter change
[14:14:03.053] QUIET: Connection to board 33 closed.
[14:14:03.515] INFO: pXar: this is the end, my friend