[10:06:50.560] INFO: *** Welcome to pxar ***
[10:06:50.560] INFO: *** Today: 2016/10/10
[10:06:51.810] INFO: *** Version: v1.9.0-818-g96727
[10:06:51.810] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//dacParameters35_C15.dat
[10:06:51.866] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:06:51.866] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//defaultMaskFile.dat
[10:06:51.870] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C15.dat
[10:06:51.993] INFO: clk: 4
[10:06:51.993] INFO: ctr: 4
[10:06:51.993] INFO: sda: 19
[10:06:51.993] INFO: tin: 9
[10:06:51.993] INFO: level: 15
[10:06:51.993] INFO: triggerdelay: 0
[10:06:51.993] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[10:06:51.993] INFO: Log level: INFO
[10:06:52.011] QUIET: Connection to board DTB_WREKRL opened.
[10:06:52.014] 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:
------------------------------------------------------
[10:06:52.017] INFO: RPC call hashes of host and DTB match: 398089610
[10:06:53.572] INFO: DUT info:
[10:06:53.572] INFO: The DUT currently contains the following objects:
[10:06:53.572] INFO: 2 TBM Cores tbm08c (2 ON)
[10:06:53.572] INFO: TBM Core alpha (0): 7 registers set
[10:06:53.572] INFO: TBM Core beta (1): 7 registers set
[10:06:53.572] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:06:53.572] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.572] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:53.573] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:06:54.013] INFO: enter 'restricted' command line mode
[10:06:54.013] INFO: enter test to run
[10:07:01.259] INFO: test: PixelAlive no parameter change
[10:07:01.260] INFO: running: pixelalive
[10:07:01.324] INFO: ----------------------------------------------------------------------
[10:07:01.324] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:07:01.324] INFO: ----------------------------------------------------------------------
[10:07:01.640] INFO: Expecting 41600 events.
[10:07:06.026] INFO: 41600 events read in total (3667ms).
[10:07:06.192] INFO: Test took 4864ms.
[10:07:06.205] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:07:06.752] INFO: PixTestAlive::aliveTest() done
[10:07:06.752] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 166
[10:07:06.922] INFO: enter test to run
[10:07:08.771] INFO: test: timing no parameter change
[10:07:08.771] INFO: running: timing
[10:07:08.775] INFO: ######################################################################
[10:07:08.775] INFO: PixTestTiming::doTest()
[10:07:08.775] INFO: ######################################################################
[10:07:08.775] INFO: ----------------------------------------------------------------------
[10:07:08.775] INFO: PixTestTiming::TBMPhaseScan()
[10:07:08.775] INFO: ----------------------------------------------------------------------
[10:13:10.272] INFO: TBM Phase Settings: 16
[10:13:10.272] INFO: 400MHz Phase: 4
[10:13:10.272] INFO: 160MHz Phase: 0
[10:13:10.272] INFO: Functional Phase Area: 3
[10:13:10.296] INFO: Test took 361521 ms.
[10:13:10.296] INFO: PixTestTiming::TBMPhaseScan() done.
[10:13:10.296] INFO: ----------------------------------------------------------------------
[10:13:10.296] INFO: PixTestTiming::ROCDelayScan()
[10:13:10.296] INFO: ----------------------------------------------------------------------
[10:15:21.567] INFO: ROC Delay Settings: 228
[10:15:21.567] INFO: ROC Header-Trailer/Token Delay: 11
[10:15:21.567] INFO: ROC Port 0 Delay: 4
[10:15:21.567] INFO: ROC Port 1 Delay: 4
[10:15:21.567] INFO: Functional ROC Area: 5
[10:15:21.570] INFO: Test took 131274 ms.
[10:15:21.570] INFO: PixTestTiming::ROCDelayScan() done.
[10:15:21.570] INFO: ----------------------------------------------------------------------
[10:15:21.570] INFO: PixTestTiming::TimingTest()
[10:15:21.570] INFO: ----------------------------------------------------------------------
[10:15:37.792] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:15:52.882] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:07.913] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:23.024] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:37.987] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:53.237] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:08.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:23.637] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:38.824] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:54.104] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:54.485] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:54.503] INFO: ----------------------------------------------------------------------
[10:17:54.503] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[10:17:54.503] INFO: ----------------------------------------------------------------------
[10:17:54.503] INFO: ----------------------------------------------------------------------
[10:17:54.503] INFO: Read back bit status: 1
[10:17:54.503] INFO: ----------------------------------------------------------------------
[10:17:54.503] INFO: ----------------------------------------------------------------------
[10:17:54.503] INFO: Timings are good!
[10:17:54.503] INFO: ----------------------------------------------------------------------
[10:17:54.503] INFO: Test took 152933 ms.
[10:17:54.503] INFO: PixTestTiming::TimingTest() done.
[10:17:54.503] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//tbmParameters_C0a.dat
[10:17:54.503] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:17:54.503] INFO: PixTestTiming::doTest took 645731 ms.
[10:17:54.503] INFO: PixTestTiming::doTest() done
[10:17:54.503] INFO: Write out TBMPhaseScan_0_V0
[10:17:54.504] INFO: Write out TBMPhaseScan_1_V0
[10:17:54.504] INFO: Write out CombinedTBMPhaseScan_V0
[10:17:54.505] INFO: Write out ROCDelayScan3_V0
[10:17:54.505] INFO: enter test to run
[10:19:56.862] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:19:56.862] INFO: running: highrate
[10:19:56.876] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:19:57.130] INFO: ----------------------------------------------------------------------
[10:19:57.130] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:19:57.130] INFO: ----------------------------------------------------------------------
[10:19:57.130] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:19:57.130] INFO: edge/corner pixel THR is adjusted
[10:19:57.130] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:19:58.090] INFO: Collecting data for 5 seconds...
[10:20:03.107] INFO: Done with hot pixel readout
[10:20:15.049] INFO: PixTest:: pg_setup set to default.
[10:20:15.050] INFO: 31 hot pixels found in step 0
[10:20:16.044] INFO: Collecting data for 5 seconds...
[10:20:21.061] INFO: Done with hot pixel readout
[10:20:32.922] INFO: PixTest:: pg_setup set to default.
[10:20:32.923] INFO: 27 hot pixels found in step 1
[10:20:33.917] INFO: Collecting data for 5 seconds...
[10:20:38.934] INFO: Done with hot pixel readout
[10:20:50.800] INFO: PixTest:: pg_setup set to default.
[10:20:50.801] INFO: 25 hot pixels found in step 2
[10:20:51.795] INFO: Collecting data for 5 seconds...
[10:20:56.811] INFO: Done with hot pixel readout
[10:21:08.778] INFO: PixTest:: pg_setup set to default.
[10:21:08.779] INFO: 23 hot pixels found in step 3
[10:21:09.773] INFO: Collecting data for 5 seconds...
[10:21:14.790] INFO: Done with hot pixel readout
[10:21:26.702] INFO: PixTest:: pg_setup set to default.

[10:21:26.703] INFO: 28 hot pixels found in step 4
[10:21:27.697] INFO: Collecting data for 5 seconds...
[10:21:32.715] INFO: Done with hot pixel readout
[10:21:44.631] INFO: PixTest:: pg_setup set to default.

[10:21:44.632] INFO: 23 hot pixels found in step 5
[10:21:45.626] INFO: Collecting data for 5 seconds...
[10:21:50.643] INFO: Done with hot pixel readout
[10:22:02.502] INFO: PixTest:: pg_setup set to default.
[10:22:02.503] INFO: 22 hot pixels found in step 6
[10:22:03.499] INFO: Collecting data for 5 seconds...
[10:22:08.515] INFO: Done with hot pixel readout
[10:22:20.417] INFO: PixTest:: pg_setup set to default.

[10:22:20.418] INFO: 13 hot pixels found in step 7
[10:22:21.413] INFO: Collecting data for 5 seconds...
[10:22:26.429] INFO: Done with hot pixel readout
[10:22:38.401] INFO: PixTest:: pg_setup set to default.

[10:22:38.402] INFO: 11 hot pixels found in step 8
[10:22:39.396] INFO: Collecting data for 5 seconds...
[10:22:44.413] INFO: Done with hot pixel readout
[10:22:56.344] INFO: PixTest:: pg_setup set to default.

[10:22:56.345] INFO: 14 hot pixels found in step 9
[10:22:57.338] INFO: Collecting data for 5 seconds...
[10:23:02.355] INFO: Done with hot pixel readout
[10:23:14.309] INFO: PixTest:: pg_setup set to default.
[10:23:14.310] INFO: 11 hot pixels found in step 10
[10:23:15.306] INFO: Collecting data for 5 seconds...
[10:23:20.321] INFO: Done with hot pixel readout
[10:23:32.293] INFO: PixTest:: pg_setup set to default.


[10:23:32.294] INFO: 11 hot pixels found in step 11
[10:23:33.288] INFO: Collecting data for 5 seconds...
[10:23:38.305] INFO: Done with hot pixel readout
[10:23:50.209] INFO: PixTest:: pg_setup set to default.

[10:23:50.210] INFO: 15 hot pixels found in step 12
[10:23:51.205] INFO: Collecting data for 5 seconds...
[10:23:56.221] INFO: Done with hot pixel readout
[10:24:08.103] INFO: PixTest:: pg_setup set to default.

[10:24:08.104] INFO: 16 hot pixels found in step 13
[10:24:09.097] INFO: Collecting data for 5 seconds...
[10:24:14.113] INFO: Done with hot pixel readout
[10:24:26.112] INFO: PixTest:: pg_setup set to default.
[10:24:26.112] INFO: 11 hot pixels found in step 14
[10:24:26.150] INFO: 11 hot pixels could not be trimmed and have been masked.
[10:24:26.154] INFO: PixTest::trimHotPixels() done
[10:24:26.170] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C0.dat
[10:24:26.178] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C1.dat
[10:24:26.183] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C2.dat
[10:24:26.188] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C3.dat
[10:24:26.194] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C4.dat
[10:24:26.199] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C5.dat
[10:24:26.204] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C6.dat
[10:24:26.210] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C7.dat
[10:24:26.215] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C8.dat
[10:24:26.220] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C9.dat
[10:24:26.226] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C10.dat
[10:24:26.231] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C11.dat
[10:24:26.236] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C12.dat
[10:24:26.242] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C13.dat
[10:24:26.247] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C14.dat
[10:24:26.252] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C15.dat
[10:24:26.258] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//defaultMaskFile.dat
[10:24:26.273] INFO: enter test to run
[10:24:48.804] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:24:48.804] INFO: running: highrate
[10:24:48.809] INFO: ----------------------------------------------------------------------
[10:24:48.809] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:24:48.809] INFO: ----------------------------------------------------------------------
[10:24:48.809] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:24:48.809] INFO: edge/corner pixel THR is adjusted
[10:24:48.809] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:24:49.766] INFO: Collecting data for 1 seconds...
[10:24:50.769] INFO: Done with hot pixel readout
[10:24:54.758] INFO: PixTest:: pg_setup set to default.
[10:24:54.759] INFO: 0 hot pixels found in step 0
[10:24:54.764] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:24:54.850] INFO: PixTest::trimHotPixels() done
[10:24:54.851] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C0.dat
[10:24:54.863] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C1.dat
[10:24:54.870] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C2.dat
[10:24:54.875] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C3.dat
[10:24:54.881] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C4.dat
[10:24:54.886] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C5.dat
[10:24:54.892] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C6.dat
[10:24:54.897] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C7.dat
[10:24:54.903] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C8.dat
[10:24:54.908] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C9.dat
[10:24:54.914] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C10.dat
[10:24:54.919] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C11.dat
[10:24:54.925] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C12.dat
[10:24:54.930] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C13.dat
[10:24:54.935] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C14.dat
[10:24:54.941] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//trimParameters35_C15.dat
[10:24:54.947] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-A-29_FPIXTest-17C-Nebraska-160913-1359-150V_2016-09-13_13h59m_1473793198/000_FPIXTest_p17//defaultMaskFile.dat
[10:24:54.957] INFO: enter test to run
[10:25:39.620] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:25:39.620] INFO: running: xray
[10:25:39.621] INFO: ----------------------------------------------------------------------
[10:25:39.621] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:25:39.621] INFO: ----------------------------------------------------------------------
[10:25:40.598] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:25:52.231] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:26:21.827] INFO: Resuming triggers.
[10:26:33.463] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:27:03.701] INFO: Resuming triggers.
[10:27:15.339] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:27:45.065] INFO: Resuming triggers.
[10:27:56.701] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:28:26.277] INFO: Resuming triggers.
[10:28:37.914] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[10:29:07.708] INFO: Resuming triggers.
[10:29:19.347] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:29:49.428] INFO: Resuming triggers.
[10:30:01.068] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[10:30:31.892] INFO: Resuming triggers.
[10:30:43.528] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[10:31:13.698] INFO: Resuming triggers.
[10:31:20.965] INFO: data taking finished, elapsed time: 100 seconds.
[10:31:39.708] INFO: PixTest:: pg_setup set to default.
[10:31:39.712] INFO: PixTestXray::doPhRun() done
[10:31:39.900] INFO: enter test to run
[10:33:27.689] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:33:27.689] INFO: running: xray
[10:33:27.690] INFO: ----------------------------------------------------------------------
[10:33:27.690] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:33:27.690] INFO: ----------------------------------------------------------------------
[10:33:28.654] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:33:35.400] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:34:05.953] INFO: Resuming triggers.
[10:34:12.700] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:34:43.189] INFO: Resuming triggers.
[10:34:49.942] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[10:35:20.426] INFO: Resuming triggers.
[10:35:27.176] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[10:35:57.468] INFO: Resuming triggers.
[10:36:04.214] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[10:36:34.745] INFO: Resuming triggers.
[10:36:41.494] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[10:37:11.918] INFO: Resuming triggers.
[10:37:18.668] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[10:37:49.162] INFO: Resuming triggers.
[10:37:55.907] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[10:38:26.226] INFO: Resuming triggers.
[10:38:32.972] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[10:39:03.373] INFO: Resuming triggers.
[10:39:10.120] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[10:39:41.180] INFO: Resuming triggers.
[10:39:47.926] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[10:40:18.553] INFO: Resuming triggers.
[10:40:25.306] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[10:40:56.459] INFO: Resuming triggers.
[10:41:03.211] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[10:41:34.257] INFO: Resuming triggers.
[10:41:40.004] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[10:42:12.549] INFO: Resuming triggers.
[10:42:18.409] INFO: data taking finished, elapsed time: 100 seconds.
[10:42:46.600] INFO: PixTest:: pg_setup set to default.
[10:42:46.603] INFO: PixTestXray::doPhRun() done
[10:42:46.780] INFO: enter test to run
[10:43:33.756] INFO: test: HighRate no parameter change
[10:43:33.756] INFO: running: highrate
[10:43:33.779] INFO: ----------------------------------------------------------------------
[10:43:33.779] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:43:33.779] INFO: ----------------------------------------------------------------------
[10:43:33.962] INFO: Expecting 768 events.
[10:43:35.114] INFO: 768 events read in total (436ms).
[10:43:35.115] INFO: Test took 1307ms.
[10:43:35.917] INFO: Expecting 41600 events.
[10:43:39.035] INFO: 41600 events read in total (2591ms).
[10:43:39.036] INFO: Test took 3914ms.
[10:43:39.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:39.795] INFO: Expecting 41600 events.
[10:43:43.028] INFO: 41600 events read in total (2707ms).
[10:43:43.029] INFO: Test took 3940ms.
[10:43:43.064] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:43.780] INFO: Expecting 41600 events.
[10:43:47.089] INFO: 41600 events read in total (2782ms).
[10:43:47.090] INFO: Test took 4008ms.
[10:43:47.126] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:47.845] INFO: Expecting 41600 events.
[10:43:51.119] INFO: 41600 events read in total (2747ms).
[10:43:51.120] INFO: Test took 3974ms.
[10:43:51.157] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:51.877] INFO: Expecting 41600 events.
[10:43:55.177] INFO: 41600 events read in total (2773ms).
[10:43:55.178] INFO: Test took 4003ms.
[10:43:55.213] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:55.932] INFO: Expecting 41600 events.
[10:43:59.223] INFO: 41600 events read in total (2764ms).
[10:43:59.224] INFO: Test took 3993ms.
[10:43:59.260] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:59.981] INFO: Expecting 41600 events.
[10:44:03.249] INFO: 41600 events read in total (2742ms).
[10:44:03.250] INFO: Test took 3973ms.
[10:44:03.287] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:03.998] INFO: Expecting 41600 events.
[10:44:07.274] INFO: 41600 events read in total (2749ms).
[10:44:07.275] INFO: Test took 3964ms.
[10:44:07.311] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:08.028] INFO: Expecting 41600 events.
[10:44:11.385] INFO: 41600 events read in total (2830ms).
[10:44:11.386] INFO: Test took 4057ms.
[10:44:11.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:12.138] INFO: Expecting 41600 events.
[10:44:15.432] INFO: 41600 events read in total (2767ms).
[10:44:15.433] INFO: Test took 3988ms.
[10:44:15.468] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:16.187] INFO: Expecting 41600 events.
[10:44:19.475] INFO: 41600 events read in total (2761ms).
[10:44:19.476] INFO: Test took 3990ms.
[10:44:19.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:20.217] INFO: Expecting 41600 events.
[10:44:23.532] INFO: 41600 events read in total (2789ms).
[10:44:23.533] INFO: Test took 3997ms.
[10:44:23.569] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:24.286] INFO: Expecting 41600 events.
[10:44:27.593] INFO: 41600 events read in total (2780ms).
[10:44:27.594] INFO: Test took 4007ms.
[10:44:27.631] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:28.350] INFO: Expecting 41600 events.
[10:44:31.739] INFO: 41600 events read in total (2863ms).
[10:44:31.740] INFO: Test took 4091ms.
[10:44:31.776] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:32.491] INFO: Expecting 41600 events.
[10:44:35.861] INFO: 41600 events read in total (2843ms).
[10:44:35.862] INFO: Test took 4067ms.
[10:44:35.897] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:36.620] INFO: Expecting 41600 events.
[10:44:39.875] INFO: 41600 events read in total (2728ms).
[10:44:39.876] INFO: Test took 3961ms.
[10:44:39.911] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:40.631] INFO: Expecting 41600 events.
[10:44:43.888] INFO: 41600 events read in total (2730ms).
[10:44:43.889] INFO: Test took 3960ms.
[10:44:43.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:44.648] INFO: Expecting 41600 events.
[10:44:47.903] INFO: 41600 events read in total (2728ms).
[10:44:47.904] INFO: Test took 3961ms.
[10:44:47.939] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:48.660] INFO: Expecting 41600 events.
[10:44:51.902] INFO: 41600 events read in total (2715ms).
[10:44:51.903] INFO: Test took 3945ms.
[10:44:51.938] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:52.661] INFO: Expecting 41600 events.
[10:44:55.801] INFO: 41600 events read in total (2613ms).
[10:44:55.803] INFO: Test took 3847ms.
[10:44:55.837] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:56.197] INFO: enter test to run
[10:45:04.604] INFO: test: HighRate no parameter change
[10:45:04.604] INFO: running: highrate
[10:45:04.605] INFO: ----------------------------------------------------------------------
[10:45:04.605] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:45:04.605] INFO: ----------------------------------------------------------------------
[10:45:05.216] INFO: Expecting 208000 events.
[10:45:17.161] INFO: 208000 events read in total (11418ms).
[10:45:17.165] INFO: Test took 12553ms.
[10:45:17.312] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:17.569] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 166
[10:45:17.569] INFO: number of red-efficiency pixels: 74 58 99 141 170 150 170 109 107 118 133 108 109 60 21 198
[10:45:17.569] INFO: number of X-ray hits detected: 68488 44329 71596 111745 115487 114245 112100 81167 78416 103579 98208 87110 92272 56658 22528 28335
[10:45:17.569] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:45:17.569] INFO: number of Vcal hits detected: 207923 207941 207899 207854 207826 207845 207828 207890 207890 207876 207866 207890 207887 207940 207979 199668
[10:45:17.569] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[10:45:17.569] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 96.0
[10:45:17.569] INFO: X-ray hit rate [MHz/cm2]: 20.1 13.0 21.0 32.8 33.9 33.5 32.9 23.8 23.0 30.4 28.8 25.5 27.0 16.6 6.6 8.3
[10:45:17.569] INFO: PixTestHighRate::doXPixelAlive() done
[10:45:17.615] INFO: PixTest:: pg_setup set to default.
[10:45:17.632] INFO: enter test to run
[10:45:33.620] INFO: test: HighRate no parameter change
[10:45:33.620] INFO: running: highrate
[10:45:33.621] INFO: ----------------------------------------------------------------------
[10:45:33.621] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:45:33.621] INFO: ----------------------------------------------------------------------
[10:45:34.241] INFO: Expecting 208000 events.
[10:45:47.842] INFO: 208000 events read in total (13074ms).
[10:45:47.847] INFO: Test took 14216ms.
[10:45:48.133] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:48.437] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 166
[10:45:48.437] INFO: number of red-efficiency pixels: 266 117 301 511 549 444 525 309 275 363 424 294 342 189 58 240
[10:45:48.437] INFO: number of X-ray hits detected: 136921 88684 142540 221958 230413 226125 224755 161954 157020 207330 196318 173903 185541 114243 44996 56566
[10:45:48.437] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:45:48.437] INFO: number of Vcal hits detected: 207712 207878 207667 207452 207393 207519 207414 207674 207714 207618 207540 207678 207638 207798 207942 199625
[10:45:48.437] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.9 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[10:45:48.437] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.8 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 96.0
[10:45:48.437] INFO: X-ray hit rate [MHz/cm2]: 40.1 26.0 41.8 65.1 67.5 66.3 65.9 47.5 46.0 60.8 57.5 51.0 54.4 33.5 13.2 16.6
[10:45:48.437] INFO: PixTestHighRate::doXPixelAlive() done
[10:45:48.485] INFO: PixTest:: pg_setup set to default.
[10:45:48.499] INFO: enter test to run
[10:46:07.180] INFO: test: HighRate no parameter change
[10:46:07.180] INFO: running: highrate
[10:46:07.181] INFO: ----------------------------------------------------------------------
[10:46:07.181] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:46:07.181] INFO: ----------------------------------------------------------------------
[10:46:07.798] INFO: Expecting 208000 events.
[10:46:23.203] INFO: 208000 events read in total (14878ms).
[10:46:23.210] INFO: Test took 16018ms.
[10:46:23.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:23.005] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 166
[10:46:23.005] INFO: number of red-efficiency pixels: 515 229 670 1134 1257 1004 1211 797 631 863 926 761 732 386 97 270
[10:46:23.005] INFO: number of X-ray hits detected: 204023 134538 214520 332906 345834 339814 338689 242975 235285 310998 293150 261132 276451 170539 68138 85562
[10:46:23.005] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:46:23.005] INFO: number of Vcal hits detected: 207354 207750 207103 206540 206325 206745 206403 207034 207272 206985 206888 207114 207151 207555 207897 199593
[10:46:23.005] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.4 99.3 99.5 99.3 99.6 99.7 99.6 99.5 99.6 99.6 99.8 100.0 99.9
[10:46:23.005] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.3 99.2 99.4 99.2 99.5 99.7 99.5 99.5 99.6 99.6 99.8 100.0 96.0
[10:46:23.005] INFO: X-ray hit rate [MHz/cm2]: 59.8 39.4 62.9 97.6 101.4 99.6 99.3 71.2 69.0 91.2 85.9 76.5 81.0 50.0 20.0 25.1
[10:46:23.005] INFO: PixTestHighRate::doXPixelAlive() done
[10:46:24.055] INFO: PixTest:: pg_setup set to default.
[10:46:24.075] INFO: enter test to run
[10:46:28.427] INFO: test: exit no parameter change
[10:46:28.819] QUIET: Connection to board 33 closed.
[10:46:28.834] INFO: pXar: this is the end, my friend