[16:17:24.492] INFO: *** Welcome to pxar ***
[16:17:24.492] INFO: *** Today: 2016/05/23
[16:17:24.509] INFO: *** Version: v1.9.0-796-gef167-dirty
[16:17:24.509] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//dacParameters35_C15.dat
[16:17:24.510] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:17:24.510] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//defaultMaskFile.dat
[16:17:24.510] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C15.dat
[16:17:24.581] INFO: clk: 4
[16:17:24.581] INFO: ctr: 4
[16:17:24.581] INFO: sda: 19
[16:17:24.581] INFO: tin: 9
[16:17:24.581] INFO: level: 15
[16:17:24.581] INFO: triggerdelay: 0
[16:17:24.581] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[16:17:24.581] INFO: Log level: INFO
[16:17:24.598] QUIET: Connection to board DTB_WREK4U opened.
[16:17:24.602] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[16:17:24.604] INFO: RPC call hashes of host and DTB match: 398089610
[16:17:26.138] INFO: DUT info:
[16:17:26.139] INFO: The DUT currently contains the following objects:
[16:17:26.139] INFO: 2 TBM Cores tbm08c (2 ON)
[16:17:26.139] INFO: TBM Core alpha (0): 7 registers set
[16:17:26.139] INFO: TBM Core beta (1): 7 registers set
[16:17:26.139] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:17:26.139] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.139] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:17:26.542] INFO: enter 'restricted' command line mode
[16:17:26.542] INFO: enter test to run
[16:17:28.446] INFO: test: timing no parameter change
[16:17:28.446] INFO: running: timing
[16:17:28.456] INFO: ######################################################################
[16:17:28.456] INFO: PixTestTiming::doTest()
[16:17:28.456] INFO: ######################################################################
[16:17:28.456] INFO: ----------------------------------------------------------------------
[16:17:28.456] INFO: PixTestTiming::TBMPhaseScan()
[16:17:28.456] INFO: ----------------------------------------------------------------------
[16:21:49.054] INFO: TBM Phase Settings: 236
[16:21:49.054] INFO: 400MHz Phase: 3
[16:21:49.054] INFO: 160MHz Phase: 7
[16:21:49.054] INFO: Functional Phase Area: 3
[16:21:49.057] INFO: Test took 260601 ms.
[16:21:49.057] INFO: PixTestTiming::TBMPhaseScan() done.
[16:21:49.058] INFO: ----------------------------------------------------------------------
[16:21:49.058] INFO: PixTestTiming::ROCDelayScan()
[16:21:49.058] INFO: ----------------------------------------------------------------------
[16:23:44.591] INFO: ROC Delay Settings: 228
[16:23:44.591] INFO: ROC Header-Trailer/Token Delay: 11
[16:23:44.591] INFO: ROC Port 0 Delay: 4
[16:23:44.592] INFO: ROC Port 1 Delay: 4
[16:23:44.592] INFO: Functional ROC Area: 4
[16:23:44.595] INFO: Test took 115537 ms.
[16:23:44.595] INFO: PixTestTiming::ROCDelayScan() done.
[16:23:44.595] INFO: ----------------------------------------------------------------------
[16:23:44.595] INFO: PixTestTiming::TimingTest()
[16:23:44.595] INFO: ----------------------------------------------------------------------
[16:24:00.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:15.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:30.724] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:45.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:25:00.689] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:25:15.680] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:25:30.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:25:45.653] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:26:00.632] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:26:15.616] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:26:15.994] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:26:16.013] INFO: ----------------------------------------------------------------------
[16:26:16.013] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[16:26:16.013] INFO: ----------------------------------------------------------------------
[16:26:16.013] INFO: ----------------------------------------------------------------------
[16:26:16.013] INFO: Read back bit status: 1
[16:26:16.013] INFO: ----------------------------------------------------------------------
[16:26:16.013] INFO: ----------------------------------------------------------------------
[16:26:16.013] INFO: Timings are good!
[16:26:16.013] INFO: ----------------------------------------------------------------------
[16:26:16.013] INFO: Test took 151418 ms.
[16:26:16.013] INFO: PixTestTiming::TimingTest() done.
[16:26:16.028] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//tbmParameters_C0a.dat
[16:26:16.029] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:26:16.029] INFO: PixTestTiming::doTest took 527578 ms.
[16:26:16.029] INFO: PixTestTiming::doTest() done
[16:26:16.029] INFO: Write out TBMPhaseScan_0_V0
[16:26:16.054] INFO: Write out TBMPhaseScan_1_V0
[16:26:16.054] INFO: Write out CombinedTBMPhaseScan_V0
[16:26:16.055] INFO: Write out ROCDelayScan3_V0
[16:26:16.055] INFO: enter test to run
[16:26:25.907] INFO: test: PixelAlive no parameter change
[16:26:25.907] INFO: running: pixelalive
[16:26:25.911] INFO: ----------------------------------------------------------------------
[16:26:25.911] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:26:25.911] INFO: ----------------------------------------------------------------------
[16:26:26.235] INFO: Expecting 41600 events.
[16:26:30.565] INFO: 41600 events read in total (3614ms).
[16:26:30.566] INFO: Test took 4651ms.
[16:26:30.572] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:26:30.968] INFO: PixTestAlive::aliveTest() done
[16:26:30.968] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:26:30.971] INFO: enter test to run
[16:27:02.618] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:27:02.618] INFO: running: highrate
[16:27:02.619] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:27:02.772] INFO: ----------------------------------------------------------------------
[16:27:02.772] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:27:02.772] INFO: ----------------------------------------------------------------------
[16:27:02.772] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:27:02.772] INFO: edge/corner pixel THR is adjusted
[16:27:02.772] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:27:03.729] INFO: Collecting data for 5 seconds...
[16:27:08.746] INFO: Done with hot pixel readout
[16:27:20.102] INFO: PixTest:: pg_setup set to default.
[16:27:20.103] INFO: 2 hot pixels found in step 0
[16:27:21.091] INFO: Collecting data for 5 seconds...
[16:27:26.107] INFO: Done with hot pixel readout
[16:27:37.466] INFO: PixTest:: pg_setup set to default.

[16:27:37.467] INFO: 3 hot pixels found in step 1
[16:27:38.456] INFO: Collecting data for 5 seconds...
[16:27:43.472] INFO: Done with hot pixel readout
[16:27:54.855] INFO: PixTest:: pg_setup set to default.

[16:27:54.856] INFO: 2 hot pixels found in step 2
[16:27:55.845] INFO: Collecting data for 5 seconds...
[16:28:00.861] INFO: Done with hot pixel readout
[16:28:12.241] INFO: PixTest:: pg_setup set to default.

[16:28:12.242] INFO: 2 hot pixels found in step 3
[16:28:13.231] INFO: Collecting data for 5 seconds...
[16:28:18.247] INFO: Done with hot pixel readout
[16:28:29.637] INFO: PixTest:: pg_setup set to default.

[16:28:29.638] INFO: 2 hot pixels found in step 4
[16:28:30.627] INFO: Collecting data for 5 seconds...
[16:28:35.643] INFO: Done with hot pixel readout
[16:28:46.920] INFO: PixTest:: pg_setup set to default.

[16:28:46.921] INFO: 1 hot pixels found in step 5
[16:28:46.954] INFO: 1 hot pixels could not be trimmed and have been masked.
[16:28:46.957] INFO: PixTest::trimHotPixels() done
[16:28:46.958] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C0.dat
[16:28:46.964] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C1.dat
[16:28:46.970] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C2.dat
[16:28:46.975] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C3.dat
[16:28:46.981] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C4.dat
[16:28:46.987] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C5.dat
[16:28:46.992] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C6.dat
[16:28:46.997] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C7.dat
[16:28:46.002] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C8.dat
[16:28:47.008] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C9.dat
[16:28:47.013] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C10.dat
[16:28:47.018] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C11.dat
[16:28:47.024] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C12.dat
[16:28:47.029] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C13.dat
[16:28:47.034] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C14.dat
[16:28:47.039] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C15.dat
[16:28:47.045] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//defaultMaskFile.dat
[16:28:47.057] INFO: enter test to run
[16:29:06.802] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:29:06.802] INFO: running: highrate
[16:29:06.806] INFO: ----------------------------------------------------------------------
[16:29:06.806] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:29:06.806] INFO: ----------------------------------------------------------------------
[16:29:06.806] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:29:06.806] INFO: edge/corner pixel THR is adjusted
[16:29:06.806] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:29:07.763] INFO: Collecting data for 1 seconds...
[16:29:08.767] INFO: Done with hot pixel readout
[16:29:12.484] INFO: PixTest:: pg_setup set to default.
[16:29:12.484] INFO: 0 hot pixels found in step 0
[16:29:12.490] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:29:12.591] INFO: PixTest::trimHotPixels() done
[16:29:12.592] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C0.dat
[16:29:12.602] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C1.dat
[16:29:12.608] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C2.dat
[16:29:12.613] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C3.dat
[16:29:12.618] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C4.dat
[16:29:12.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C5.dat
[16:29:12.628] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C6.dat
[16:29:12.634] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C7.dat
[16:29:12.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C8.dat
[16:29:12.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C9.dat
[16:29:12.649] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C10.dat
[16:29:12.654] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C11.dat
[16:29:12.659] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C12.dat
[16:29:12.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C13.dat
[16:29:12.670] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C14.dat
[16:29:12.675] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//trimParameters35_C15.dat
[16:29:12.680] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-J-4-17_FPIXTest-17C-FNAL-160512-1436_2016-05-12_14h37m_1463081836/000_FPIXTest_p17//defaultMaskFile.dat
[16:29:12.697] INFO: enter test to run
[16:29:31.345] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:29:31.345] INFO: running: xray
[16:29:31.346] INFO: ----------------------------------------------------------------------
[16:29:31.346] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:29:31.346] INFO: ----------------------------------------------------------------------
[16:29:32.311] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:29:44.367] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[16:30:13.437] INFO: Resuming triggers.
[16:30:25.492] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[16:30:54.505] INFO: Resuming triggers.
[16:31:06.564] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[16:31:35.712] INFO: Resuming triggers.
[16:31:47.767] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[16:32:17.631] INFO: Resuming triggers.
[16:32:29.687] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[16:32:59.404] INFO: Resuming triggers.
[16:33:11.457] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[16:33:41.499] INFO: Resuming triggers.
[16:33:53.555] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[16:34:22.656] INFO: Resuming triggers.
[16:34:34.712] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[16:35:03.873] INFO: Resuming triggers.
[16:35:07.784] INFO: data taking finished, elapsed time: 100 seconds.
[16:35:17.585] INFO: PixTest:: pg_setup set to default.
[16:35:17.588] INFO: PixTestXray::doPhRun() done
[16:35:17.721] INFO: enter test to run
[16:36:21.190] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:36:21.190] INFO: running: xray
[16:36:21.192] INFO: ----------------------------------------------------------------------
[16:36:21.192] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:36:21.192] INFO: ----------------------------------------------------------------------
[16:36:22.156] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:36:29.452] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[16:36:59.565] INFO: Resuming triggers.
[16:37:06.862] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[16:37:37.051] INFO: Resuming triggers.
[16:37:44.350] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[16:38:14.529] INFO: Resuming triggers.
[16:38:21.823] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[16:38:51.913] INFO: Resuming triggers.
[16:38:59.212] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[16:39:29.344] INFO: Resuming triggers.
[16:39:36.640] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[16:40:06.619] INFO: Resuming triggers.
[16:40:13.917] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[16:40:43.855] INFO: Resuming triggers.
[16:40:51.151] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[16:41:21.358] INFO: Resuming triggers.
[16:41:28.657] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[16:41:59.496] INFO: Resuming triggers.
[16:42:06.796] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[16:42:37.460] INFO: Resuming triggers.
[16:42:44.753] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[16:43:15.208] INFO: Resuming triggers.
[16:43:22.506] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[16:43:53.728] INFO: Resuming triggers.
[16:44:01.021] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[16:44:32.284] INFO: Resuming triggers.
[16:44:37.769] INFO: data taking finished, elapsed time: 100 seconds.
[16:45:00.860] INFO: PixTest:: pg_setup set to default.
[16:45:00.864] INFO: PixTestXray::doPhRun() done
[16:45:01.010] INFO: enter test to run
[16:45:48.714] INFO: test: HighRate no parameter change
[16:45:48.714] INFO: running: highrate
[16:45:48.715] INFO: ----------------------------------------------------------------------
[16:45:48.715] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:45:48.715] INFO: ----------------------------------------------------------------------
[16:45:48.855] INFO: Expecting 768 events.
[16:45:49.989] INFO: 768 events read in total (418ms).
[16:45:49.990] INFO: Test took 1269ms.
[16:45:50.793] INFO: Expecting 41600 events.
[16:45:53.850] INFO: 41600 events read in total (2531ms).
[16:45:53.851] INFO: Test took 3854ms.
[16:45:53.881] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:54.617] INFO: Expecting 41600 events.
[16:45:57.787] INFO: 41600 events read in total (2644ms).
[16:45:57.788] INFO: Test took 3890ms.
[16:45:57.818] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:58.549] INFO: Expecting 41600 events.
[16:46:01.746] INFO: 41600 events read in total (2671ms).
[16:46:01.747] INFO: Test took 3913ms.
[16:46:01.777] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:02.505] INFO: Expecting 41600 events.
[16:46:05.709] INFO: 41600 events read in total (2677ms).
[16:46:05.710] INFO: Test took 3917ms.
[16:46:05.740] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:06.471] INFO: Expecting 41600 events.
[16:46:09.678] INFO: 41600 events read in total (2680ms).
[16:46:09.679] INFO: Test took 3923ms.
[16:46:09.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:10.438] INFO: Expecting 41600 events.
[16:46:13.631] INFO: 41600 events read in total (2667ms).
[16:46:13.632] INFO: Test took 3905ms.
[16:46:13.663] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:14.395] INFO: Expecting 41600 events.
[16:46:17.446] INFO: 41600 events read in total (2525ms).
[16:46:17.447] INFO: Test took 3768ms.
[16:46:17.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:18.210] INFO: Expecting 41600 events.
[16:46:21.417] INFO: 41600 events read in total (2681ms).
[16:46:21.418] INFO: Test took 3923ms.
[16:46:21.448] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:22.176] INFO: Expecting 41600 events.
[16:46:25.387] INFO: 41600 events read in total (2684ms).
[16:46:25.388] INFO: Test took 3923ms.
[16:46:25.419] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:26.148] INFO: Expecting 41600 events.
[16:46:29.358] INFO: 41600 events read in total (2683ms).
[16:46:29.359] INFO: Test took 3924ms.
[16:46:29.389] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:30.118] INFO: Expecting 41600 events.
[16:46:33.331] INFO: 41600 events read in total (2686ms).
[16:46:33.332] INFO: Test took 3927ms.
[16:46:33.362] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:34.093] INFO: Expecting 41600 events.
[16:46:37.314] INFO: 41600 events read in total (2694ms).
[16:46:37.315] INFO: Test took 3935ms.
[16:46:37.345] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:38.072] INFO: Expecting 41600 events.
[16:46:41.277] INFO: 41600 events read in total (2678ms).
[16:46:41.278] INFO: Test took 3915ms.
[16:46:41.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:42.040] INFO: Expecting 41600 events.
[16:46:45.247] INFO: 41600 events read in total (2680ms).
[16:46:45.248] INFO: Test took 3924ms.
[16:46:45.279] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:46.006] INFO: Expecting 41600 events.
[16:46:49.209] INFO: 41600 events read in total (2676ms).
[16:46:49.210] INFO: Test took 3915ms.
[16:46:49.242] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:49.973] INFO: Expecting 41600 events.
[16:46:53.181] INFO: 41600 events read in total (2681ms).
[16:46:53.182] INFO: Test took 3923ms.
[16:46:53.212] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:53.943] INFO: Expecting 41600 events.
[16:46:57.142] INFO: 41600 events read in total (2672ms).
[16:46:57.143] INFO: Test took 3913ms.
[16:46:57.174] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:46:57.904] INFO: Expecting 41600 events.
[16:47:01.103] INFO: 41600 events read in total (2672ms).
[16:47:01.104] INFO: Test took 3913ms.
[16:47:01.135] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:47:01.868] INFO: Expecting 41600 events.
[16:47:05.059] INFO: 41600 events read in total (2664ms).
[16:47:05.060] INFO: Test took 3908ms.
[16:47:05.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:47:05.819] INFO: Expecting 41600 events.
[16:47:08.885] INFO: 41600 events read in total (2539ms).
[16:47:08.885] INFO: Test took 3778ms.
[16:47:08.916] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:47:09.285] INFO: enter test to run
[16:47:53.145] INFO: test: HighRate no parameter change
[16:47:53.145] INFO: running: highrate
[16:47:53.147] INFO: ----------------------------------------------------------------------
[16:47:53.147] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:47:53.147] INFO: ----------------------------------------------------------------------
[16:47:53.758] INFO: Expecting 208000 events.
[16:48:05.466] INFO: 208000 events read in total (11181ms).
[16:48:05.468] INFO: Test took 12311ms.
[16:48:05.598] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:05.844] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:48:05.844] INFO: number of red-efficiency pixels: 68 52 73 101 132 97 117 79 66 112 99 86 82 49 16 29
[16:48:05.844] INFO: number of X-ray hits detected: 61087 38731 58846 90850 93636 94140 96626 73901 73064 90144 86518 71602 75243 43129 19863 22447
[16:48:05.844] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:48:05.844] INFO: number of Vcal hits detected: 207931 207947 207923 207899 207866 207902 207880 207919 207933 207886 207897 207912 207917 207950 207983 207971
[16:48:05.844] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 100.0 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[16:48:05.844] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 99.9 100.0 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[16:48:05.844] INFO: X-ray hit rate [MHz/cm2]: 17.9 11.4 17.2 26.6 27.4 27.6 28.3 21.7 21.4 26.4 25.4 21.0 22.1 12.6 5.8 6.6
[16:48:05.844] INFO: PixTestHighRate::doXPixelAlive() done
[16:48:05.895] INFO: PixTest:: pg_setup set to default.
[16:48:05.908] INFO: enter test to run
[16:48:37.561] INFO: test: HighRate no parameter change
[16:48:37.561] INFO: running: highrate
[16:48:37.562] INFO: ----------------------------------------------------------------------
[16:48:37.562] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:48:37.562] INFO: ----------------------------------------------------------------------
[16:48:38.176] INFO: Expecting 208000 events.
[16:48:51.368] INFO: 208000 events read in total (12665ms).
[16:48:51.373] INFO: Test took 13803ms.
[16:48:51.633] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:51.925] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:48:51.925] INFO: number of red-efficiency pixels: 203 111 179 259 389 376 402 284 221 332 306 223 237 142 53 59
[16:48:51.925] INFO: number of X-ray hits detected: 125431 80387 122364 186648 191981 195405 200789 152930 151156 184982 177523 150087 156285 89858 41746 46376
[16:48:51.925] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:48:51.925] INFO: number of Vcal hits detected: 207786 207884 207815 207728 207593 207592 207561 207702 207772 207650 207679 207768 207753 207854 207944 207940
[16:48:51.925] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 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
[16:48:51.925] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[16:48:51.925] INFO: X-ray hit rate [MHz/cm2]: 36.8 23.6 35.9 54.7 56.3 57.3 58.9 44.8 44.3 54.2 52.0 44.0 45.8 26.3 12.2 13.6
[16:48:51.926] INFO: PixTestHighRate::doXPixelAlive() done
[16:48:51.975] INFO: PixTest:: pg_setup set to default.
[16:48:51.994] INFO: enter test to run
[16:49:28.361] INFO: test: HighRate no parameter change
[16:49:28.361] INFO: running: highrate
[16:49:28.362] INFO: ----------------------------------------------------------------------
[16:49:28.362] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:49:28.362] INFO: ----------------------------------------------------------------------
[16:49:28.977] INFO: Expecting 208000 events.
[16:49:43.607] INFO: 208000 events read in total (14103ms).
[16:49:43.613] INFO: Test took 15242ms.
[16:49:43.998] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:49:44.326] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:49:44.326] INFO: number of red-efficiency pixels: 417 191 324 557 776 839 874 539 380 701 704 417 547 270 70 67
[16:49:44.326] INFO: number of X-ray hits detected: 185228 118401 180012 273441 282836 287182 292854 224941 222790 272714 262088 220518 229510 132275 61293 68701
[16:49:44.326] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:49:44.326] INFO: number of Vcal hits detected: 207528 207793 207632 207386 207094 207018 206966 207384 207591 207203 207202 207552 207403 207700 207930 207930
[16:49:44.326] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.7 99.6 99.6 99.5 99.7 99.8 99.7 99.6 99.8 99.7 99.9 100.0 100.0
[16:49:44.326] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.6 99.5 99.5 99.7 99.8 99.6 99.6 99.8 99.7 99.9 100.0 100.0
[16:49:44.326] INFO: X-ray hit rate [MHz/cm2]: 54.3 34.7 52.8 80.1 82.9 84.2 85.8 65.9 65.3 79.9 76.8 64.6 67.3 38.8 18.0 20.1
[16:49:44.326] INFO: PixTestHighRate::doXPixelAlive() done
[16:49:44.370] INFO: PixTest:: pg_setup set to default.
[16:49:44.390] INFO: enter test to run
[16:49:45.904] INFO: test: exit no parameter change
[16:49:46.346] QUIET: Connection to board 32 closed.
[16:49:46.348] INFO: pXar: this is the end, my friend