[17:07:41.127] INFO: *** Welcome to pxar ***
[17:07:41.127] INFO: *** Today: 2016/07/27
[17:07:41.158] INFO: *** Version: v1.9.0-818-g96727
[17:07:41.158] INFO: readRocDacs: /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//dacParameters35_C15.dat
[17:07:41.159] INFO: readTbmDacs: /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//tbmParameters_C0b.dat
[17:07:41.160] INFO: readMaskFile: /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//defaultMaskFile.dat
[17:07:41.160] INFO: readTrimFile: /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C15.dat
[17:07:41.233] INFO: clk: 4
[17:07:41.233] INFO: ctr: 4
[17:07:41.233] INFO: sda: 19
[17:07:41.233] INFO: tin: 9
[17:07:41.233] INFO: level: 15
[17:07:41.233] INFO: triggerdelay: 0
[17:07:41.233] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[17:07:41.233] INFO: Log level: INFO
[17:07:41.251] QUIET: Connection to board DTB_WREKRL opened.
[17:07:41.255] 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:
------------------------------------------------------
[17:07:41.258] INFO: RPC call hashes of host and DTB match: 398089610
[17:07:42.785] INFO: DUT info:
[17:07:42.785] INFO: The DUT currently contains the following objects:
[17:07:42.785] INFO: 2 TBM Cores tbm08c (2 ON)
[17:07:42.785] INFO: TBM Core alpha (0): 7 registers set
[17:07:42.785] INFO: TBM Core beta (1): 7 registers set
[17:07:42.785] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[17:07:42.785] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.785] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.785] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.785] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.786] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.786] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.786] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.786] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.786] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.786] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.786] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.786] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.786] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.786] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.786] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:42.786] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:07:43.189] INFO: enter 'restricted' command line mode
[17:07:43.189] INFO: enter test to run
[17:07:53.495] INFO: test: PixelAlive no parameter change
[17:07:53.495] INFO: running: pixelalive
[17:07:53.504] INFO: ----------------------------------------------------------------------
[17:07:53.504] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:07:53.504] INFO: ----------------------------------------------------------------------
[17:07:53.824] INFO: Expecting 41600 events.
[17:07:58.165] INFO: 41600 events read in total (3622ms).
[17:07:58.330] INFO: Test took 4824ms.
[17:07:58.338] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:58.602] INFO: PixTestAlive::aliveTest() done
[17:07:58.602] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:07:58.632] INFO: enter test to run
[17:08:00.215] INFO: test: timing no parameter change
[17:08:00.215] INFO: running: timing
[17:08:00.235] INFO: ######################################################################
[17:08:00.235] INFO: PixTestTiming::doTest()
[17:08:00.235] INFO: ######################################################################
[17:08:00.235] INFO: ----------------------------------------------------------------------
[17:08:00.236] INFO: PixTestTiming::TBMPhaseScan()
[17:08:00.236] INFO: ----------------------------------------------------------------------
[17:16:25.166] INFO: TBM Phase Settings: 240
[17:16:25.166] INFO: 400MHz Phase: 4
[17:16:25.166] INFO: 160MHz Phase: 7
[17:16:25.166] INFO: Functional Phase Area: 5
[17:16:25.170] INFO: Test took 504935 ms.
[17:16:25.170] INFO: PixTestTiming::TBMPhaseScan() done.
[17:16:25.170] INFO: ----------------------------------------------------------------------
[17:16:25.170] INFO: PixTestTiming::ROCDelayScan()
[17:16:25.170] INFO: ----------------------------------------------------------------------
[17:18:28.657] INFO: ROC Delay Settings: 228
[17:18:28.658] INFO: ROC Header-Trailer/Token Delay: 11
[17:18:28.658] INFO: ROC Port 0 Delay: 4
[17:18:28.658] INFO: ROC Port 1 Delay: 4
[17:18:28.658] INFO: Functional ROC Area: 5
[17:18:28.661] INFO: Test took 123491 ms.
[17:18:28.661] INFO: PixTestTiming::ROCDelayScan() done.
[17:18:28.661] INFO: ----------------------------------------------------------------------
[17:18:28.661] INFO: PixTestTiming::TimingTest()
[17:18:28.661] INFO: ----------------------------------------------------------------------
[17:18:44.819] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:59.783] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:19:14.745] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:19:29.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:19:44.671] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:19:59.625] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:14.584] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:29.542] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:44.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:59.483] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:59.865] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:59.883] INFO: ----------------------------------------------------------------------
[17:20:59.883] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[17:20:59.883] INFO: ----------------------------------------------------------------------
[17:20:59.883] INFO: ----------------------------------------------------------------------
[17:20:59.883] INFO: Read back bit status: 1
[17:20:59.883] INFO: ----------------------------------------------------------------------
[17:20:59.883] INFO: ----------------------------------------------------------------------
[17:20:59.883] INFO: Timings are good!
[17:20:59.883] INFO: ----------------------------------------------------------------------
[17:20:59.883] INFO: Test took 151222 ms.
[17:20:59.883] INFO: PixTestTiming::TimingTest() done.
[17:20:59.897] INFO: write tbm parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//tbmParameters_C0a.dat
[17:20:59.897] INFO: write tbm parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//tbmParameters_C0b.dat
[17:20:59.897] INFO: PixTestTiming::doTest took 779665 ms.
[17:20:59.897] INFO: PixTestTiming::doTest() done
[17:20:59.897] INFO: Write out TBMPhaseScan_0_V0
[17:20:59.897] INFO: Write out TBMPhaseScan_1_V0
[17:20:59.898] INFO: Write out CombinedTBMPhaseScan_V0
[17:20:59.899] INFO: Write out ROCDelayScan3_V0
[17:20:59.900] INFO: enter test to run
[17:21:18.666] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[17:21:18.666] INFO: running: highrate
[17:21:18.666] INFO: readGainPedestalParameters /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[17:21:18.825] INFO: ----------------------------------------------------------------------
[17:21:18.825] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[17:21:18.825] INFO: ----------------------------------------------------------------------
[17:21:18.825] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[17:21:18.825] INFO: edge/corner pixel THR is adjusted
[17:21:18.825] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:21:19.782] INFO: Collecting data for 5 seconds...
[17:21:24.799] INFO: Done with hot pixel readout
[17:21:36.221] INFO: PixTest:: pg_setup set to default.


[17:21:36.223] INFO: 4 hot pixels found in step 0
[17:21:37.213] INFO: Collecting data for 5 seconds...
[17:21:42.230] INFO: Done with hot pixel readout
[17:21:53.644] INFO: PixTest:: pg_setup set to default.



[17:21:53.645] INFO: 7 hot pixels found in step 1
[17:21:54.634] INFO: Collecting data for 5 seconds...
[17:21:59.653] INFO: Done with hot pixel readout
[17:22:11.106] INFO: PixTest:: pg_setup set to default.



[17:22:11.107] INFO: 3 hot pixels found in step 2
[17:22:11.141] INFO: 3 hot pixels could not be trimmed and have been masked.
[17:22:11.145] INFO: PixTest::trimHotPixels() done
[17:22:11.145] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C0.dat
[17:22:11.150] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C1.dat
[17:22:11.156] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C2.dat
[17:22:11.163] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C3.dat
[17:22:11.168] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C4.dat
[17:22:11.173] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C5.dat
[17:22:11.178] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C6.dat
[17:22:11.183] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C7.dat
[17:22:11.189] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C8.dat
[17:22:11.194] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C9.dat
[17:22:11.199] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C10.dat
[17:22:11.204] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C11.dat
[17:22:11.210] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C12.dat
[17:22:11.215] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C13.dat
[17:22:11.220] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C14.dat
[17:22:11.225] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C15.dat
[17:22:11.230] INFO: write masked pixels into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//defaultMaskFile.dat
[17:22:11.241] INFO: enter test to run
[17:23:11.289] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[17:23:11.289] INFO: running: highrate
[17:23:11.293] INFO: ----------------------------------------------------------------------
[17:23:11.293] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[17:23:11.293] INFO: ----------------------------------------------------------------------
[17:23:11.293] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[17:23:11.293] INFO: edge/corner pixel THR is adjusted
[17:23:11.293] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:23:12.251] INFO: Collecting data for 1 seconds...
[17:23:13.255] INFO: Done with hot pixel readout
[17:23:17.035] INFO: PixTest:: pg_setup set to default.
[17:23:17.036] INFO: 0 hot pixels found in step 0
[17:23:17.042] INFO: 0 hot pixels could not be trimmed and have been masked.
[17:23:17.142] INFO: PixTest::trimHotPixels() done
[17:23:17.142] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C0.dat
[17:23:17.152] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C1.dat
[17:23:17.157] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C2.dat
[17:23:17.162] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C3.dat
[17:23:17.167] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C4.dat
[17:23:17.173] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C5.dat
[17:23:17.178] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C6.dat
[17:23:17.183] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C7.dat
[17:23:17.188] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C8.dat
[17:23:17.193] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C9.dat
[17:23:17.198] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C10.dat
[17:23:17.204] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C11.dat
[17:23:17.209] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C12.dat
[17:23:17.214] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C13.dat
[17:23:17.219] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C14.dat
[17:23:17.224] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//trimParameters35_C15.dat
[17:23:17.230] INFO: write masked pixels into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-P-2-20_FPIXTest-17C-Nebraska-160712-1316_2016-07-12_13h17m_1468347421/000_FPIXTest_p17//defaultMaskFile.dat
[17:23:17.240] INFO: enter test to run
[17:23:42.384] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[17:23:42.385] INFO: running: xray
[17:23:42.386] INFO: ----------------------------------------------------------------------
[17:23:42.386] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:23:42.386] INFO: ----------------------------------------------------------------------
[17:23:43.350] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:23:55.151] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[17:24:24.285] INFO: Resuming triggers.
[17:24:36.088] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[17:25:05.301] INFO: Resuming triggers.
[17:25:17.104] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[17:25:46.658] INFO: Resuming triggers.
[17:25:58.461] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[17:26:27.977] INFO: Resuming triggers.
[17:26:39.783] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[17:27:09.103] INFO: Resuming triggers.
[17:27:20.909] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[17:27:50.385] INFO: Resuming triggers.
[17:28:02.192] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[17:28:32.143] INFO: Resuming triggers.
[17:28:43.949] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[17:29:13.741] INFO: Resuming triggers.
[17:29:19.670] INFO: data taking finished, elapsed time: 100 seconds.
[17:29:35.024] INFO: PixTest:: pg_setup set to default.
[17:29:35.027] INFO: PixTestXray::doPhRun() done
[17:29:35.161] INFO: enter test to run
[17:30:14.486] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[17:30:14.486] INFO: running: xray
[17:30:14.487] INFO: ----------------------------------------------------------------------
[17:30:14.487] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:30:14.487] INFO: ----------------------------------------------------------------------
[17:30:15.451] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:30:22.609] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[17:30:52.617] INFO: Resuming triggers.
[17:30:59.775] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[17:31:29.681] INFO: Resuming triggers.
[17:31:36.839] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[17:32:06.819] INFO: Resuming triggers.
[17:32:13.978] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[17:32:44.028] INFO: Resuming triggers.
[17:32:51.185] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[17:33:21.266] INFO: Resuming triggers.
[17:33:28.420] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[17:33:58.472] INFO: Resuming triggers.
[17:34:05.625] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[17:34:35.577] INFO: Resuming triggers.
[17:34:42.733] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[17:35:12.793] INFO: Resuming triggers.
[17:35:19.950] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[17:35:49.994] INFO: Resuming triggers.
[17:35:57.152] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[17:36:27.186] INFO: Resuming triggers.
[17:36:34.344] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[17:37:04.368] INFO: Resuming triggers.
[17:37:11.525] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[17:37:41.744] INFO: Resuming triggers.
[17:37:48.902] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[17:38:19.426] INFO: Resuming triggers.
[17:38:26.585] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[17:38:57.795] INFO: Resuming triggers.
[17:38:57.930] INFO: data taking finished, elapsed time: 100 seconds.
[17:38:58.940] INFO: PixTest:: pg_setup set to default.
[17:38:58.943] INFO: PixTestXray::doPhRun() done
[17:38:59.098] INFO: enter test to run
[17:39:33.394] INFO: test: HighRate no parameter change
[17:39:33.394] INFO: running: highrate
[17:39:33.407] INFO: ----------------------------------------------------------------------
[17:39:33.407] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:39:33.407] INFO: ----------------------------------------------------------------------
[17:39:33.547] INFO: Expecting 768 events.
[17:39:34.692] INFO: 768 events read in total (430ms).
[17:39:34.692] INFO: Test took 1279ms.
[17:39:35.495] INFO: Expecting 41600 events.
[17:39:38.606] INFO: 41600 events read in total (2584ms).
[17:39:38.607] INFO: Test took 3909ms.
[17:39:38.639] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:39:39.369] INFO: Expecting 41600 events.
[17:39:42.616] INFO: 41600 events read in total (2720ms).
[17:39:42.617] INFO: Test took 3962ms.
[17:39:42.649] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:39:43.365] INFO: Expecting 41600 events.
[17:39:46.656] INFO: 41600 events read in total (2764ms).
[17:39:46.657] INFO: Test took 3991ms.
[17:39:46.689] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:39:47.417] INFO: Expecting 41600 events.
[17:39:50.686] INFO: 41600 events read in total (2742ms).
[17:39:50.687] INFO: Test took 3981ms.
[17:39:50.721] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:39:51.443] INFO: Expecting 41600 events.
[17:39:54.749] INFO: 41600 events read in total (2779ms).
[17:39:54.750] INFO: Test took 4013ms.
[17:39:54.782] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:39:55.502] INFO: Expecting 41600 events.
[17:39:58.799] INFO: 41600 events read in total (2771ms).
[17:39:58.800] INFO: Test took 4001ms.
[17:39:58.832] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:39:59.556] INFO: Expecting 41600 events.
[17:40:02.882] INFO: 41600 events read in total (2799ms).
[17:40:02.883] INFO: Test took 4034ms.
[17:40:02.915] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:03.644] INFO: Expecting 41600 events.
[17:40:06.873] INFO: 41600 events read in total (2702ms).
[17:40:06.874] INFO: Test took 3942ms.
[17:40:06.906] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:07.631] INFO: Expecting 41600 events.
[17:40:10.862] INFO: 41600 events read in total (2704ms).
[17:40:10.863] INFO: Test took 3940ms.
[17:40:10.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:11.625] INFO: Expecting 41600 events.
[17:40:14.890] INFO: 41600 events read in total (2739ms).
[17:40:14.891] INFO: Test took 3978ms.
[17:40:14.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:15.644] INFO: Expecting 41600 events.
[17:40:18.850] INFO: 41600 events read in total (2679ms).
[17:40:18.851] INFO: Test took 3910ms.
[17:40:18.885] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:19.595] INFO: Expecting 41600 events.
[17:40:22.859] INFO: 41600 events read in total (2737ms).
[17:40:22.860] INFO: Test took 3958ms.
[17:40:22.892] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:23.620] INFO: Expecting 41600 events.
[17:40:26.870] INFO: 41600 events read in total (2723ms).
[17:40:26.870] INFO: Test took 3960ms.
[17:40:26.903] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:27.631] INFO: Expecting 41600 events.
[17:40:30.861] INFO: 41600 events read in total (2703ms).
[17:40:30.862] INFO: Test took 3942ms.
[17:40:30.894] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:31.618] INFO: Expecting 41600 events.
[17:40:34.812] INFO: 41600 events read in total (2667ms).
[17:40:34.813] INFO: Test took 3902ms.
[17:40:34.844] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:35.575] INFO: Expecting 41600 events.
[17:40:38.890] INFO: 41600 events read in total (2788ms).
[17:40:38.891] INFO: Test took 4030ms.
[17:40:38.923] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:39.649] INFO: Expecting 41600 events.
[17:40:42.974] INFO: 41600 events read in total (2798ms).
[17:40:42.975] INFO: Test took 4033ms.
[17:40:43.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:43.730] INFO: Expecting 41600 events.
[17:40:46.980] INFO: 41600 events read in total (2723ms).
[17:40:46.980] INFO: Test took 3956ms.
[17:40:47.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:47.740] INFO: Expecting 41600 events.
[17:40:50.993] INFO: 41600 events read in total (2726ms).
[17:40:50.994] INFO: Test took 3965ms.
[17:40:51.026] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:51.743] INFO: Expecting 41600 events.
[17:40:54.713] INFO: 41600 events read in total (2444ms).
[17:40:54.714] INFO: Test took 3670ms.
[17:40:54.745] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:40:55.115] INFO: enter test to run
[17:41:39.961] INFO: test: HighRate no parameter change
[17:41:39.961] INFO: running: highrate
[17:41:39.962] INFO: ----------------------------------------------------------------------
[17:41:39.962] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:41:39.962] INFO: ----------------------------------------------------------------------
[17:41:40.611] INFO: Expecting 208000 events.
[17:41:52.323] INFO: 208000 events read in total (11185ms).
[17:41:52.326] INFO: Test took 12354ms.
[17:41:52.458] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:41:52.705] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 160 0 0 0 0 0 0 0 0
[17:41:52.705] INFO: number of red-efficiency pixels: 71 42 76 117 114 136 142 246 86 138 93 62 95 45 18 26
[17:41:52.705] INFO: number of X-ray hits detected: 58926 39139 64199 98612 107828 105736 105287 70570 69526 90607 87993 72846 73571 44996 18277 23218
[17:41:52.705] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:41:52.705] INFO: number of Vcal hits detected: 207929 207957 207921 207880 207882 207860 207855 199911 207913 207858 207905 207938 207904 207953 207982 207974
[17:41:52.705] 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 100.0 100.0 100.0 100.0 100.0 100.0
[17:41:52.705] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 96.1 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[17:41:52.705] INFO: X-ray hit rate [MHz/cm2]: 17.3 11.5 18.8 28.9 31.6 31.0 30.9 20.7 20.4 26.6 25.8 21.4 21.6 13.2 5.4 6.8
[17:41:52.705] INFO: PixTestHighRate::doXPixelAlive() done
[17:41:52.756] INFO: PixTest:: pg_setup set to default.
[17:41:52.769] INFO: enter test to run
[17:42:10.545] INFO: test: HighRate no parameter change
[17:42:10.545] INFO: running: highrate
[17:42:10.546] INFO: ----------------------------------------------------------------------
[17:42:10.546] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:42:10.546] INFO: ----------------------------------------------------------------------
[17:42:11.163] INFO: Expecting 208000 events.
[17:42:24.369] INFO: 208000 events read in total (12679ms).
[17:42:24.374] INFO: Test took 13819ms.
[17:42:24.633] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:42:24.920] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 160 0 0 0 0 0 0 0 0
[17:42:24.920] INFO: number of red-efficiency pixels: 179 94 204 335 345 479 374 423 202 364 315 198 220 186 39 67
[17:42:24.920] INFO: number of X-ray hits detected: 119527 79098 130439 199023 217480 211489 212360 142451 140298 183569 175800 147264 148545 90584 37057 46673
[17:42:24.920] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:42:24.920] INFO: number of Vcal hits detected: 207813 207903 207782 207655 207632 207481 207599 199723 207795 207612 207664 207795 207766 207806 207961 207932
[17:42:24.921] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[17:42:24.921] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 96.0 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[17:42:24.921] INFO: X-ray hit rate [MHz/cm2]: 35.0 23.2 38.2 58.3 63.7 62.0 62.2 41.8 41.1 53.8 51.5 43.2 43.5 26.6 10.9 13.7
[17:42:24.921] INFO: PixTestHighRate::doXPixelAlive() done
[17:42:24.968] INFO: PixTest:: pg_setup set to default.
[17:42:24.986] INFO: enter test to run
[17:42:43.425] INFO: test: HighRate no parameter change
[17:42:43.425] INFO: running: highrate
[17:42:43.426] INFO: ----------------------------------------------------------------------
[17:42:43.426] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:42:43.426] INFO: ----------------------------------------------------------------------
[17:42:44.045] INFO: Expecting 208000 events.
[17:42:58.852] INFO: 208000 events read in total (14280ms).
[17:42:58.859] INFO: Test took 15422ms.
[17:42:59.252] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:42:59.585] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 160 0 0 0 0 0 0 0 0
[17:42:59.585] INFO: number of red-efficiency pixels: 449 170 470 745 814 1043 891 758 380 797 758 410 533 326 71 104
[17:42:59.585] INFO: number of X-ray hits detected: 181538 120784 199509 302553 332188 322543 321839 217620 214665 279844 269513 224821 225953 138704 56804 72040
[17:42:59.585] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:42:59.585] INFO: number of Vcal hits detected: 207465 207815 207427 207143 207040 206672 206907 199266 207578 207072 207125 207551 207414 207630 207928 207895
[17:42:59.586] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.6 99.4 99.5 99.7 99.8 99.6 99.6 99.8 99.7 99.8 100.0 100.0
[17:42:59.586] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.6 99.5 99.4 99.5 95.8 99.8 99.6 99.6 99.8 99.7 99.8 100.0 99.9
[17:42:59.586] INFO: X-ray hit rate [MHz/cm2]: 53.2 35.4 58.5 88.7 97.4 94.5 94.3 63.8 62.9 82.0 79.0 65.9 66.2 40.7 16.6 21.1
[17:42:59.586] INFO: PixTestHighRate::doXPixelAlive() done
[17:42:59.640] INFO: PixTest:: pg_setup set to default.
[17:42:59.657] INFO: enter test to run
[17:43:06.849] INFO: test: exit no parameter change
[17:43:07.253] QUIET: Connection to board 33 closed.
[17:43:07.254] INFO: pXar: this is the end, my friend