[18:14:37.613] INFO: *** Welcome to pxar ***
[18:14:37.613] INFO: *** Today: 2016/07/27
[18:14:37.631] INFO: *** Version: v1.9.0-818-g96727
[18:14:37.631] INFO: readRocDacs: /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//dacParameters35_C15.dat
[18:14:37.654] INFO: readTbmDacs: /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//tbmParameters_C0b.dat
[18:14:37.654] INFO: readMaskFile: /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//defaultMaskFile.dat
[18:14:37.654] INFO: readTrimFile: /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C15.dat
[18:14:37.793] INFO: clk: 4
[18:14:37.793] INFO: ctr: 4
[18:14:37.793] INFO: sda: 19
[18:14:37.793] INFO: tin: 9
[18:14:37.793] INFO: level: 15
[18:14:37.793] INFO: triggerdelay: 0
[18:14:37.793] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[18:14:37.793] INFO: Log level: INFO
[18:14:37.809] QUIET: Connection to board DTB_WREKRL opened.
[18:14:37.812] 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:
------------------------------------------------------
[18:14:37.815] INFO: RPC call hashes of host and DTB match: 398089610
[18:14:39.346] INFO: DUT info:
[18:14:39.346] INFO: The DUT currently contains the following objects:
[18:14:39.346] INFO: 2 TBM Cores tbm08c (2 ON)
[18:14:39.346] INFO: TBM Core alpha (0): 7 registers set
[18:14:39.346] INFO: TBM Core beta (1): 7 registers set
[18:14:39.346] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[18:14:39.346] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.346] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.346] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.346] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.346] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.346] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.347] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.347] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.347] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.347] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.347] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.347] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.347] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.347] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.347] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.347] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:14:39.749] INFO: enter 'restricted' command line mode
[18:14:39.750] INFO: enter test to run
[18:14:44.644] INFO: test: PixelAlive no parameter change
[18:14:44.644] INFO: running: pixelalive
[18:14:44.654] INFO: ----------------------------------------------------------------------
[18:14:44.654] 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:14:44.654] INFO: ----------------------------------------------------------------------
[18:14:44.990] INFO: Expecting 41600 events.
[18:14:49.293] INFO: 41600 events read in total (3585ms).
[18:14:49.455] INFO: Test took 4799ms.
[18:14:49.469] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:14:49.738] INFO: PixTestAlive::aliveTest() done
[18:14:49.738] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 1 49 6 0 0 0 0 0 0
[18:14:49.773] INFO: enter test to run
[18:14:57.364] INFO: test: timing no parameter change
[18:14:57.364] INFO: running: timing
[18:14:57.367] INFO: ######################################################################
[18:14:57.367] INFO: PixTestTiming::doTest()
[18:14:57.367] INFO: ######################################################################
[18:14:57.367] INFO: ----------------------------------------------------------------------
[18:14:57.368] INFO: PixTestTiming::TBMPhaseScan()
[18:14:57.368] INFO: ----------------------------------------------------------------------
[18:19:00.623] INFO: TBM Phase Settings: 204
[18:19:00.623] INFO: 400MHz Phase: 3
[18:19:00.623] INFO: 160MHz Phase: 6
[18:19:00.623] INFO: Functional Phase Area: 4
[18:19:00.627] INFO: Test took 243260 ms.
[18:19:00.627] INFO: PixTestTiming::TBMPhaseScan() done.
[18:19:00.627] INFO: ----------------------------------------------------------------------
[18:19:00.627] INFO: PixTestTiming::ROCDelayScan()
[18:19:00.627] INFO: ----------------------------------------------------------------------
[18:20:49.453] INFO: ROC Delay Settings: 219
[18:20:49.453] INFO: ROC Header-Trailer/Token Delay: 11
[18:20:49.453] INFO: ROC Port 0 Delay: 3
[18:20:49.453] INFO: ROC Port 1 Delay: 3
[18:20:49.453] INFO: Functional ROC Area: 3
[18:20:49.456] INFO: Test took 108829 ms.
[18:20:49.456] INFO: PixTestTiming::ROCDelayScan() done.
[18:20:49.457] INFO: ----------------------------------------------------------------------
[18:20:49.457] INFO: PixTestTiming::TimingTest()
[18:20:49.457] INFO: ----------------------------------------------------------------------
[18:21:05.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:21:20.601] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:21:35.575] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:21:50.506] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:22:05.492] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:22:20.478] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:22:35.456] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:22:50.418] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:05.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:20.374] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:20.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:23:20.775] INFO: ----------------------------------------------------------------------
[18:23:20.775] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[18:23:20.775] INFO: ----------------------------------------------------------------------
[18:23:20.775] INFO: ----------------------------------------------------------------------
[18:23:20.775] INFO: Read back bit status: 1
[18:23:20.775] INFO: ----------------------------------------------------------------------
[18:23:20.775] INFO: ----------------------------------------------------------------------
[18:23:20.775] INFO: Timings are good!
[18:23:20.775] INFO: ----------------------------------------------------------------------
[18:23:20.775] INFO: Test took 151318 ms.
[18:23:20.775] INFO: PixTestTiming::TimingTest() done.
[18:23:20.775] INFO: write tbm parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//tbmParameters_C0a.dat
[18:23:20.775] INFO: write tbm parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//tbmParameters_C0b.dat
[18:23:20.776] INFO: PixTestTiming::doTest took 503412 ms.
[18:23:20.776] INFO: PixTestTiming::doTest() done
[18:23:20.776] INFO: Write out TBMPhaseScan_0_V0
[18:23:20.776] INFO: Write out TBMPhaseScan_1_V0
[18:23:20.776] INFO: Write out CombinedTBMPhaseScan_V0
[18:23:20.777] INFO: Write out ROCDelayScan3_V0
[18:23:20.777] INFO: enter test to run
[18:23:58.336] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[18:23:58.336] INFO: running: highrate
[18:23:58.337] INFO: readGainPedestalParameters /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[18:23:58.569] INFO: ----------------------------------------------------------------------
[18:23:58.569] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[18:23:58.569] INFO: ----------------------------------------------------------------------
[18:23:58.569] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[18:23:58.569] INFO: edge/corner pixel THR is adjusted
[18:23:58.569] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:23:59.528] INFO: Collecting data for 5 seconds...
[18:24:04.545] INFO: Done with hot pixel readout
[18:24:16.229] INFO: PixTest:: pg_setup set to default.
[18:24:16.230] INFO: 11 hot pixels found in step 0
[18:24:17.222] INFO: Collecting data for 5 seconds...
[18:24:22.238] INFO: Done with hot pixel readout
[18:24:33.897] INFO: PixTest:: pg_setup set to default.
[18:24:33.898] INFO: 6 hot pixels found in step 1
[18:24:34.890] INFO: Collecting data for 5 seconds...
[18:24:39.907] INFO: Done with hot pixel readout
[18:24:51.577] INFO: PixTest:: pg_setup set to default.
[18:24:51.578] INFO: 6 hot pixels found in step 2
[18:24:52.569] INFO: Collecting data for 5 seconds...
[18:24:57.585] INFO: Done with hot pixel readout
[18:25:09.244] INFO: PixTest:: pg_setup set to default.
[18:25:09.245] INFO: 4 hot pixels found in step 3
[18:25:10.237] INFO: Collecting data for 5 seconds...
[18:25:15.253] INFO: Done with hot pixel readout
[18:25:26.944] INFO: PixTest:: pg_setup set to default.
[18:25:26.945] INFO: 6 hot pixels found in step 4
[18:25:27.937] INFO: Collecting data for 5 seconds...
[18:25:32.953] INFO: Done with hot pixel readout
[18:25:44.607] INFO: PixTest:: pg_setup set to default.
[18:25:44.608] INFO: 9 hot pixels found in step 5
[18:25:45.600] INFO: Collecting data for 5 seconds...
[18:25:50.616] INFO: Done with hot pixel readout
[18:26:02.312] INFO: PixTest:: pg_setup set to default.
[18:26:02.312] INFO: 4 hot pixels found in step 6
[18:26:03.305] INFO: Collecting data for 5 seconds...
[18:26:08.323] INFO: Done with hot pixel readout
[18:26:20.038] INFO: PixTest:: pg_setup set to default.
[18:26:20.039] INFO: 5 hot pixels found in step 7
[18:26:21.030] INFO: Collecting data for 5 seconds...
[18:26:26.048] INFO: Done with hot pixel readout
[18:26:37.940] INFO: PixTest:: pg_setup set to default.
[18:26:37.940] INFO: 2 hot pixels found in step 8
[18:26:38.932] INFO: Collecting data for 5 seconds...
[18:26:43.952] INFO: Done with hot pixel readout
[18:26:55.477] INFO: PixTest:: pg_setup set to default.

[18:26:55.478] INFO: 10 hot pixels found in step 9
[18:26:56.471] INFO: Collecting data for 5 seconds...
[18:27:01.490] INFO: Done with hot pixel readout
[18:27:13.267] INFO: PixTest:: pg_setup set to default.


[18:27:13.268] INFO: 6 hot pixels found in step 10
[18:27:14.260] INFO: Collecting data for 5 seconds...
[18:27:19.279] INFO: Done with hot pixel readout
[18:27:30.887] INFO: PixTest:: pg_setup set to default.


[18:27:30.888] INFO: 3 hot pixels found in step 11
[18:27:31.879] INFO: Collecting data for 5 seconds...
[18:27:36.900] INFO: Done with hot pixel readout
[18:27:48.574] INFO: PixTest:: pg_setup set to default.

[18:27:48.575] INFO: 4 hot pixels found in step 12
[18:27:49.567] INFO: Collecting data for 5 seconds...
[18:27:54.585] INFO: Done with hot pixel readout
[18:28:06.382] INFO: PixTest:: pg_setup set to default.

[18:28:06.382] INFO: 3 hot pixels found in step 13
[18:28:07.375] INFO: Collecting data for 5 seconds...
[18:28:12.393] INFO: Done with hot pixel readout
[18:28:24.205] INFO: PixTest:: pg_setup set to default.


[18:28:24.206] INFO: 3 hot pixels found in step 14
[18:28:24.242] INFO: 3 hot pixels could not be trimmed and have been masked.
[18:28:24.245] INFO: PixTest::trimHotPixels() done
[18:28:24.246] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C0.dat
[18:28:24.251] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C1.dat
[18:28:24.257] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C2.dat
[18:28:24.263] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C3.dat
[18:28:24.286] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C4.dat
[18:28:24.291] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C5.dat
[18:28:24.297] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C6.dat
[18:28:24.302] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C7.dat
[18:28:24.308] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C8.dat
[18:28:24.313] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C9.dat
[18:28:24.318] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C10.dat
[18:28:24.324] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C11.dat
[18:28:24.329] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C12.dat
[18:28:24.335] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C13.dat
[18:28:24.340] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C14.dat
[18:28:24.345] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C15.dat
[18:28:24.351] INFO: write masked pixels into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//defaultMaskFile.dat
[18:28:24.361] INFO: enter test to run
[18:30:15.550] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[18:30:15.550] INFO: running: highrate
[18:30:15.554] INFO: ----------------------------------------------------------------------
[18:30:15.554] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[18:30:15.554] INFO: ----------------------------------------------------------------------
[18:30:15.555] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[18:30:15.555] INFO: edge/corner pixel THR is adjusted
[18:30:15.555] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:30:16.512] INFO: Collecting data for 1 seconds...
[18:30:17.515] INFO: Done with hot pixel readout
[18:30:21.479] INFO: PixTest:: pg_setup set to default.
[18:30:21.480] INFO: 0 hot pixels found in step 0
[18:30:21.485] INFO: 0 hot pixels could not be trimmed and have been masked.
[18:30:21.579] INFO: PixTest::trimHotPixels() done
[18:30:21.579] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C0.dat
[18:30:21.591] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C1.dat
[18:30:21.596] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C2.dat
[18:30:21.601] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C3.dat
[18:30:21.607] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C4.dat
[18:30:21.612] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C5.dat
[18:30:21.617] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C6.dat
[18:30:21.623] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C7.dat
[18:30:21.628] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C8.dat
[18:30:21.633] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C9.dat
[18:30:21.638] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C10.dat
[18:30:21.644] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C11.dat
[18:30:21.649] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C12.dat
[18:30:21.654] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C13.dat
[18:30:21.659] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C14.dat
[18:30:21.665] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//trimParameters35_C15.dat
[18:30:21.670] INFO: write masked pixels into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-K-2-02_FPIXTest-17C-Nebraska-160713-1322_2016-07-13_13h22m_1468434178/000_FPIXTest_p17//defaultMaskFile.dat
[18:30:21.680] INFO: enter test to run
[18:33:14.621] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[18:33:14.621] INFO: running: xray
[18:33:14.622] INFO: ----------------------------------------------------------------------
[18:33:14.622] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:33:14.622] INFO: ----------------------------------------------------------------------
[18:33:15.585] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:33:27.107] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[18:33:56.410] INFO: Resuming triggers.
[18:34:08.025] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[18:34:37.435] INFO: Resuming triggers.
[18:34:48.953] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[18:35:18.287] INFO: Resuming triggers.
[18:35:29.806] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[18:35:59.168] INFO: Resuming triggers.
[18:36:10.686] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[18:36:40.054] INFO: Resuming triggers.
[18:36:51.575] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[18:37:20.886] INFO: Resuming triggers.
[18:37:32.405] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[18:38:01.668] INFO: Resuming triggers.
[18:38:13.188] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[18:38:42.960] INFO: Resuming triggers.
[18:38:51.134] INFO: data taking finished, elapsed time: 100 seconds.
[18:39:12.533] INFO: PixTest:: pg_setup set to default.
[18:39:12.536] INFO: PixTestXray::doPhRun() done
[18:39:12.673] INFO: enter test to run
[18:40:34.034] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[18:40:34.034] INFO: running: xray
[18:40:34.035] INFO: ----------------------------------------------------------------------
[18:40:34.035] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:40:34.035] INFO: ----------------------------------------------------------------------
[18:40:34.999] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:40:41.856] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[18:41:13.094] INFO: Resuming triggers.
[18:41:19.952] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[18:41:50.005] INFO: Resuming triggers.
[18:41:57.861] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[18:42:28.060] INFO: Resuming triggers.
[18:42:34.916] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[18:43:04.859] INFO: Resuming triggers.
[18:43:11.711] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[18:43:41.719] INFO: Resuming triggers.
[18:43:48.573] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[18:44:18.554] INFO: Resuming triggers.
[18:44:25.406] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[18:44:55.396] INFO: Resuming triggers.
[18:45:02.251] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[18:45:32.379] INFO: Resuming triggers.
[18:45:39.238] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[18:46:09.241] INFO: Resuming triggers.
[18:46:16.096] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[18:46:46.146] INFO: Resuming triggers.
[18:46:52.003] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[18:47:23.028] INFO: Resuming triggers.
[18:47:29.885] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[18:47:59.977] INFO: Resuming triggers.
[18:48:06.831] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[18:48:36.894] INFO: Resuming triggers.
[18:48:43.752] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[18:49:13.697] INFO: Resuming triggers.
[18:49:18.055] INFO: data taking finished, elapsed time: 100 seconds.
[18:49:37.360] INFO: PixTest:: pg_setup set to default.
[18:49:37.363] INFO: PixTestXray::doPhRun() done
[18:49:37.511] INFO: enter test to run
[18:51:11.677] INFO: test: HighRate no parameter change
[18:51:11.677] INFO: running: highrate
[18:51:11.678] INFO: ----------------------------------------------------------------------
[18:51:11.679] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[18:51:11.679] INFO: ----------------------------------------------------------------------
[18:51:11.819] INFO: Expecting 768 events.
[18:51:12.953] INFO: 768 events read in total (419ms).
[18:51:12.953] INFO: Test took 1268ms.
[18:51:13.757] INFO: Expecting 41600 events.
[18:51:16.884] INFO: 41600 events read in total (2601ms).
[18:51:16.885] INFO: Test took 3924ms.
[18:51:16.919] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:17.645] INFO: Expecting 41600 events.
[18:51:20.841] INFO: 41600 events read in total (2669ms).
[18:51:20.842] INFO: Test took 3907ms.
[18:51:20.876] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:21.601] INFO: Expecting 41600 events.
[18:51:24.889] INFO: 41600 events read in total (2761ms).
[18:51:24.890] INFO: Test took 3997ms.
[18:51:24.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:25.648] INFO: Expecting 41600 events.
[18:51:28.968] INFO: 41600 events read in total (2793ms).
[18:51:28.969] INFO: Test took 4028ms.
[18:51:28.003] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:29.725] INFO: Expecting 41600 events.
[18:51:32.976] INFO: 41600 events read in total (2725ms).
[18:51:32.977] INFO: Test took 3957ms.
[18:51:33.011] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:33.734] INFO: Expecting 41600 events.
[18:51:36.990] INFO: 41600 events read in total (2729ms).
[18:51:36.991] INFO: Test took 3962ms.
[18:51:37.025] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:37.746] INFO: Expecting 41600 events.
[18:51:40.960] INFO: 41600 events read in total (2687ms).
[18:51:40.961] INFO: Test took 3917ms.
[18:51:40.995] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:41.715] INFO: Expecting 41600 events.
[18:51:44.903] INFO: 41600 events read in total (2661ms).
[18:51:44.904] INFO: Test took 3891ms.
[18:51:44.939] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:45.660] INFO: Expecting 41600 events.
[18:51:48.946] INFO: 41600 events read in total (2759ms).
[18:51:48.947] INFO: Test took 3990ms.
[18:51:48.981] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:49.702] INFO: Expecting 41600 events.
[18:51:52.880] INFO: 41600 events read in total (2651ms).
[18:51:52.881] INFO: Test took 3882ms.
[18:51:52.915] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:53.638] INFO: Expecting 41600 events.
[18:51:56.867] INFO: 41600 events read in total (2702ms).
[18:51:56.868] INFO: Test took 3935ms.
[18:51:56.903] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:51:57.622] INFO: Expecting 41600 events.
[18:52:00.858] INFO: 41600 events read in total (2709ms).
[18:52:00.859] INFO: Test took 3939ms.
[18:52:00.893] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:01.620] INFO: Expecting 41600 events.
[18:52:04.958] INFO: 41600 events read in total (2812ms).
[18:52:04.959] INFO: Test took 4048ms.
[18:52:04.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:05.717] INFO: Expecting 41600 events.
[18:52:08.998] INFO: 41600 events read in total (2754ms).
[18:52:08.999] INFO: Test took 3988ms.
[18:52:09.034] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:09.749] INFO: Expecting 41600 events.
[18:52:12.973] INFO: 41600 events read in total (2697ms).
[18:52:12.974] INFO: Test took 3922ms.
[18:52:13.009] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:13.733] INFO: Expecting 41600 events.
[18:52:16.909] INFO: 41600 events read in total (2650ms).
[18:52:16.910] INFO: Test took 3882ms.
[18:52:16.945] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:17.668] INFO: Expecting 41600 events.
[18:52:20.931] INFO: 41600 events read in total (2736ms).
[18:52:20.932] INFO: Test took 3970ms.
[18:52:20.966] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:21.673] INFO: Expecting 41600 events.
[18:52:24.816] INFO: 41600 events read in total (2616ms).
[18:52:24.817] INFO: Test took 3833ms.
[18:52:24.851] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:25.574] INFO: Expecting 41600 events.
[18:52:28.887] INFO: 41600 events read in total (2786ms).
[18:52:28.888] INFO: Test took 4019ms.
[18:52:28.923] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:29.638] INFO: Expecting 41600 events.
[18:52:32.758] INFO: 41600 events read in total (2593ms).
[18:52:32.759] INFO: Test took 3816ms.
[18:52:32.793] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:52:33.155] INFO: enter test to run
[18:53:26.788] INFO: test: HighRate no parameter change
[18:53:26.788] INFO: running: highrate
[18:53:26.789] INFO: ----------------------------------------------------------------------
[18:53:26.789] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:53:26.789] INFO: ----------------------------------------------------------------------
[18:53:27.409] INFO: Expecting 208000 events.
[18:53:39.543] INFO: 208000 events read in total (11607ms).
[18:53:39.546] INFO: Test took 12748ms.
[18:53:39.690] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:53:39.944] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 1 49 4 0 0 0 0 0 0
[18:53:39.944] INFO: number of red-efficiency pixels: 92 48 76 163 135 171 136 100 125 126 118 93 94 66 27 26
[18:53:39.944] INFO: number of X-ray hits detected: 71666 45256 65334 110349 105648 114154 108869 79934 73940 94833 91989 81196 82188 50300 21933 25784
[18:53:39.944] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:53:39.944] INFO: number of Vcal hits detected: 207808 207952 207923 207831 207863 207825 207864 207849 205455 207638 207878 207907 207904 207933 207973 207974
[18:53:39.944] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[18:53:39.944] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 98.8 99.8 99.9 100.0 100.0 100.0 100.0 100.0
[18:53:39.944] INFO: X-ray hit rate [MHz/cm2]: 21.0 13.3 19.1 32.3 31.0 33.5 31.9 23.4 21.7 27.8 27.0 23.8 24.1 14.7 6.4 7.6
[18:53:39.944] INFO: PixTestHighRate::doXPixelAlive() done
[18:53:39.991] INFO: PixTest:: pg_setup set to default.
[18:53:39.004] INFO: enter test to run
[18:55:00.884] INFO: test: HighRate no parameter change
[18:55:00.884] INFO: running: highrate
[18:55:00.885] INFO: ----------------------------------------------------------------------
[18:55:00.885] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:55:00.885] INFO: ----------------------------------------------------------------------
[18:55:01.505] INFO: Expecting 208000 events.
[18:55:15.031] INFO: 208000 events read in total (12999ms).
[18:55:15.036] INFO: Test took 14141ms.
[18:55:15.319] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:55:15.617] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 1 49 4 0 0 0 0 0 0
[18:55:15.617] INFO: number of red-efficiency pixels: 262 142 274 514 444 548 328 267 275 326 335 240 292 200 41 60
[18:55:15.617] INFO: number of X-ray hits detected: 146460 92817 133338 225077 217047 235085 222589 164043 151924 194509 188069 166701 170081 104478 46006 53231
[18:55:15.617] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:55:15.617] INFO: number of Vcal hits detected: 207618 207854 207696 207443 207515 207388 207652 207664 205306 207409 207642 207749 207692 207788 207956 207939
[18:55:15.617] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.7 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[18:55:15.617] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.9 99.7 99.8 99.7 99.8 99.8 98.7 99.7 99.8 99.9 99.9 99.9 100.0 100.0
[18:55:15.618] INFO: X-ray hit rate [MHz/cm2]: 42.9 27.2 39.1 66.0 63.6 68.9 65.2 48.1 44.5 57.0 55.1 48.9 49.9 30.6 13.5 15.6
[18:55:15.618] INFO: PixTestHighRate::doXPixelAlive() done
[18:55:15.667] INFO: PixTest:: pg_setup set to default.
[18:55:15.679] INFO: enter test to run
[18:56:28.179] INFO: test: HighRate no parameter change
[18:56:28.179] INFO: running: highrate
[18:56:28.180] INFO: ----------------------------------------------------------------------
[18:56:28.180] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[18:56:28.180] INFO: ----------------------------------------------------------------------
[18:56:28.798] INFO: Expecting 208000 events.
[18:56:44.078] INFO: 208000 events read in total (14753ms).
[18:56:44.086] INFO: Test took 15895ms.
[18:56:44.508] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:56:44.855] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 1 49 4 0 0 0 0 0 0
[18:56:44.856] INFO: number of red-efficiency pixels: 594 292 613 1095 1135 1315 850 483 470 900 744 490 654 421 83 98
[18:56:44.856] INFO: number of X-ray hits detected: 219802 139665 201053 337910 326034 351542 333931 245475 227519 291144 283106 249521 254275 156332 69304 80159
[18:56:44.856] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[18:56:44.856] INFO: number of Vcal hits detected: 207201 207688 207200 206582 206577 206281 207031 207411 205089 206701 207124 207464 207265 207514 207911 207902
[18:56:44.856] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.4 99.4 99.2 99.6 99.8 99.8 99.5 99.6 99.8 99.7 99.8 100.0 100.0
[18:56:44.856] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.6 99.3 99.3 99.2 99.5 99.7 98.6 99.4 99.6 99.7 99.6 99.8 100.0 100.0
[18:56:44.856] INFO: X-ray hit rate [MHz/cm2]: 64.4 40.9 58.9 99.0 95.6 103.0 97.9 72.0 66.7 85.3 83.0 73.1 74.5 45.8 20.3 23.5
[18:56:44.856] INFO: PixTestHighRate::doXPixelAlive() done
[18:56:44.908] INFO: PixTest:: pg_setup set to default.
[18:56:44.928] INFO: enter test to run
[18:57:21.123] INFO: test: exit no parameter change
[18:57:21.490] QUIET: Connection to board 33 closed.
[18:57:21.491] INFO: pXar: this is the end, my friend