Hi,
Here are the top cycle-eaters. I knew that the frequency xlating fir filter
was quite hungry, but I'm unsure of how to decide on a transition
bandwidth. I have changed it from 1kHz to 3kHz (that is taps =
firdes.low_pass(1,614400,2.5*9600,3000)) and the flowgraph seems to be
running without problem now. I'll run it overnight and see what happens.
If you could offer some advice on the transition bandwidth I'd be very
grateful, but thanks for this perf tip - very useful!
Cheers,
Jack
# To display the perf.data header info, please use --header/--header-only
options.
#
#
# Total Lost Samples: 0
#
# Samples: 2M of event 'cycles'
# Event count (approx.): 1036611178011
#
# Children Self Command Shared
Object
Symbol
# ........ ........ ...............
......................................
..........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................
#
37.39% 37.20% freq_xlating_f1
libvolk.so.1.3 [.]
volk_32fc_x2_dot_prod_32fc_a_sse4_1
35.73% 0.00% python2
[unknown] [.] 0x00000000000005c0
|
---0x5c0
|
|--21.15%--__sched_yield
| |
| |--17.36%--entry_SYSCALL_64_fastpath
| | |
| | |--15.96%--sys_sched_yield
| | | |
| | | --15.34%--schedule
| | | |
| | |
|--13.68%--__schedule
| | | |
|
| | | |
|--7.62%--pick_next_task_rt
| | | |
| |
| | | |
| |--3.10%--update_curr_rt
| | | |
| | |
| | | |
| | --1.21%--cpuacct_charge
| | | |
| |
| | | |
| |--1.50%--put_prev_task_rt
| | | |
| | |
| | | |
| | --0.54%--plist_add
| | | |
| |
| | | |
| --0.74%--_raw_spin_lock
| | | |
|
| | | |
--3.05%--update_rq_clock.part.79
| | |
| |
| | |
| |--1.63%--sched_clock
| | |
| |
| | |
| --1.29%--sched_clock_cpu
| | |
| |
| | |
| --1.15%--native_sched_clock
| | | |
| | |
--0.73%--_raw_spin_lock
| | |
| | --0.72%--_raw_spin_lock
| |
| |--1.08%--entry_SYSCALL_64_after_swapgs
| |
| --0.89%--entry_SYSCALL_64
|
|--6.54%--boost::this_thread::interruption_point
| |
| --0.70%--__sched_yield
| |
| --0.63%--entry_SYSCALL_64_fastpath
| |
| --0.58%--sys_sched_yield
| |
|
--0.55%--schedule
|
|--2.72%--pthread_mutex_unlock
|
|--1.38%--uhd::time_spec_t::time_spec_t
|
--1.10%--pthread_mutex_lock
35.72% 0.00% python2
libuhd.so.3.11 [.]
udp_zero_copy_asio_impl::~udp_zero_copy_asio_impl
|
---udp_zero_copy_asio_impl::~udp_zero_copy_asio_impl
0x5c0
|
|--21.15%--__sched_yield
| |
| |--17.36%--entry_SYSCALL_64_fastpath
| | |
| | |--15.96%--sys_sched_yield
| | | |
| | | --15.34%--schedule
| | | |
| | |
|--13.68%--__schedule
| | | |
|
| | | |
|--7.62%--pick_next_task_rt
| | | |
| |
| | | |
| |--3.10%--update_curr_rt
| | | |
| | |
| | | |
| | --1.21%--cpuacct_charge
| | | |
| |
| | | |
| |--1.50%--put_prev_task_rt
| | | |
| | |
| | | |
| | --0.54%--plist_add
| | | |
| |
| | | |
| --0.74%--_raw_spin_lock
| | | |
|
| | | |
--3.05%--update_rq_clock.part.79
| | |
| |
| | |
| |--1.63%--sched_clock
| | |
| |
| | |
| --1.29%--sched_clock_cpu
| | |
| |
| | |
| --1.15%--native_sched_clock
| | | |
| | |
--0.73%--_raw_spin_lock
| | |
| | --0.72%--_raw_spin_lock
| |
| |--1.08%--entry_SYSCALL_64_after_swapgs
| |
| --0.89%--entry_SYSCALL_64
|
|--6.54%--boost::this_thread::interruption_point
| |
| --0.70%--__sched_yield
| |
| --0.63%--entry_SYSCALL_64_fastpath
| |
| --0.58%--sys_sched_yield
| |
|
--0.55%--schedule
|
|--2.72%--pthread_mutex_unlock
|
|--1.38%--uhd::time_spec_t::time_spec_t
|
--1.10%--pthread_mutex_lock
35.72% 0.00% python2
[unknown] [.] 0xfd89485355544100
|
---0xfd89485355544100
udp_zero_copy_asio_impl::~udp_zero_copy_asio_impl
0x5c0
|
|--21.15%--__sched_yield
| |
| |--17.36%--entry_SYSCALL_64_fastpath
| | |
| | |--15.96%--sys_sched_yield
| | | |
| | | --15.34%--schedule
| | | |
| | |
|--13.68%--__schedule
| | | |
|
| | | |
|--7.62%--pick_next_task_rt
| | | |
| |
| | | |
| |--3.10%--update_curr_rt
| | | |
| | |
| | | |
| | --1.21%--cpuacct_charge
| | | |
| |
| | | |
| |--1.50%--put_prev_task_rt
| | | |
| | |
| | | |
| | --0.54%--plist_add
| | | |
| |
| | | |
| --0.74%--_raw_spin_lock
| | | |
|
| | | |
--3.05%--update_rq_clock.part.79
| | |
| |
| | |
| |--1.63%--sched_clock
| | |
| |
| | |
| --1.29%--sched_clock_cpu
| | |
| |
| | |
| --1.15%--native_sched_clock
| | | |
| | |
--0.73%--_raw_spin_lock
| | |
| | --0.72%--_raw_spin_lock
| |
| |--1.08%--entry_SYSCALL_64_after_swapgs
| |
| --0.89%--entry_SYSCALL_64
|
|--6.54%--boost::this_thread::interruption_point
| |
| --0.70%--__sched_yield
| |
| --0.63%--entry_SYSCALL_64_fastpath
| |
| --0.58%--sys_sched_yield
| |
|
--0.55%--schedule
|
|--2.72%--pthread_mutex_unlock
|
|--1.38%--uhd::time_spec_t::time_spec_t
|
--1.10%--pthread_mutex_lock
26.61% 1.76% python2 libc-2.23.so
[.] __sched_yield
|
|--24.86%--__sched_yield
| |
| |--22.25%--entry_SYSCALL_64_fastpath
| | |
| | |--20.45%--sys_sched_yield
| | | |
| | | --19.66%--schedule
| | | |
| | |
|--17.53%--__schedule
| | | |
|
| | | |
|--9.72%--pick_next_task_rt
| | | |
| |
| | | |
| |--3.95%--update_curr_rt
| | | |
| | |
| | | |
| | --1.53%--cpuacct_charge
| | | |
| |
| | | |
| |--1.91%--put_prev_task_rt
| | | |
| | |
| | | |
| | --0.69%--plist_add
| | | |
| |
| | | |
| --0.94%--_raw_spin_lock
| | | |
|
| | | |
--3.90%--update_rq_clock.part.79
| | |
| |
| | |
| |--2.08%--sched_clock
| | |
| |
| | |
| --1.65%--sched_clock_cpu
| | |
| |
| | |
| --1.48%--native_sched_clock
| | | |
| | |
--0.93%--_raw_spin_lock
| | |
| | --0.92%--_raw_spin_lock
| |
| |--1.38%--entry_SYSCALL_64_after_swapgs
| |
| --1.14%--entry_SYSCALL_64
|
--1.75%--0xfd89485355544100
udp_zero_copy_asio_impl::~udp_zero_copy_asio_impl
0x5c0
__sched_yield
22.40% 0.78% python2
[kernel.kallsyms] [k] entry_SYSCALL_64_fastpath
|
|--21.62%--entry_SYSCALL_64_fastpath
| |
| |--20.45%--sys_sched_yield
| | |
| | --19.66%--schedule
| | |
| | |--17.53%--__schedule
| | | |
| | |
|--9.72%--pick_next_task_rt
| | | |
|
| | | |
|--3.95%--update_curr_rt
| | | |
| |
| | | |
| --1.53%--cpuacct_charge
| | | |
|
| | | |
|--1.91%--put_prev_task_rt
| | | |
| |
| | | |
| --0.69%--plist_add
| | | |
|
| | | |
--0.94%--_raw_spin_lock
| | | |
| | |
--3.90%--update_rq_clock.part.79
| | |
|
| | |
|--2.08%--sched_clock
| | |
|
| | |
--1.65%--sched_clock_cpu
| |
| |
| |
| --1.48%--native_sched_clock
| | |
| | --0.93%--_raw_spin_lock
| |
| --0.92%--_raw_spin_lock
|
--0.76%--0xfd89485355544100
udp_zero_copy_asio_impl::~udp_zero_copy_asio_impl
0x5c0
|
--0.61%--__sched_yield
entry_SYSCALL_64_fastpath
20.52% 0.54% python2
[kernel.kallsyms] [k] sys_sched_yield
|
|--19.98%--sys_sched_yield
| |
| --19.66%--schedule
| |
| |--17.53%--__schedule
| | |
| | |--9.72%--pick_next_task_rt
| | | |
| | |
|--3.95%--update_curr_rt
| | | |
|
| | | |
--1.53%--cpuacct_charge
| | | |
| | |
|--1.91%--put_prev_task_rt
| | | |
|
| | | |
--0.69%--plist_add
| | | |
| | |
--0.94%--_raw_spin_lock
| | |
| |
--3.90%--update_rq_clock.part.79
| | |
| |
|--2.08%--sched_clock
| | |
| |
--1.65%--sched_clock_cpu
| |
|
| |
--1.48%--native_sched_clock
| |
| --0.93%--_raw_spin_lock
|
--0.53%--0xfd89485355544100
udp_zero_copy_asio_impl::~udp_zero_copy_asio_impl
0x5c0
19.72% 0.26% python2
[kernel.kallsyms] [k] schedule
|
--19.46%--schedule
|
|--17.55%--__schedule
| |
| |--9.72%--pick_next_task_rt
| | |
| | |--3.95%--update_curr_rt
| | | |
| | |
--1.53%--cpuacct_charge
| | |
| | |--1.91%--put_prev_task_rt
| | | |
| | | --0.69%--plist_add
| | |
| | --0.94%--_raw_spin_lock
| |
| --3.90%--update_rq_clock.part.79
| |
| |--2.08%--sched_clock
| |
| --1.65%--sched_clock_cpu
| |
|
--1.48%--native_sched_clock
|
--0.93%--_raw_spin_lock
17.60% 2.28% python2
[kernel.kallsyms] [k] __schedule
|
|--15.32%--__schedule
| |
| |--9.72%--pick_next_task_rt
| | |
| | |--3.95%--update_curr_rt
| | | |
| | | --1.53%--cpuacct_charge
| | |
| | |--1.91%--put_prev_task_rt
| | | |
| | | --0.69%--plist_add
| | |
| | --0.94%--_raw_spin_lock
| |
| --3.90%--update_rq_clock.part.79
| |
| |--2.08%--sched_clock
| |
| --1.65%--sched_clock_cpu
| |
| --1.48%--native_sched_clock
|
--2.23%--0xfd89485355544100
udp_zero_copy_asio_impl::~udp_zero_copy_asio_impl
0x5c0
|
--1.77%--__sched_yield
entry_SYSCALL_64_fastpath
sys_sched_yield
|
--1.73%--schedule
__schedule
9.88% 1.78% python2
[kernel.kallsyms] [k] pick_next_task_rt
|
|--8.10%--pick_next_task_rt
| |
| |--3.95%--update_curr_rt
| | |
| | --1.53%--cpuacct_charge
| |
| |--1.91%--put_prev_task_rt
| | |
| | --0.69%--plist_add
| |
| --0.94%--_raw_spin_lock
|
--1.77%--0xfd89485355544100
udp_zero_copy_asio_impl::~udp_zero_copy_asio_impl
0x5c0
|
--1.39%--__sched_yield
entry_SYSCALL_64_fastpath
sys_sched_yield
schedule
|
--1.27%--__schedule
pick_next_task_rt
On Thu, Aug 3, 2017 at 12:48 PM, Marcus Müller via USRP-users <
usrp-users@lists.ettus.com> wrote:
> Hi Jack,
>
> that is really peculiar, as 400k is really not a rate I'd assume you'd be
> getting into trouble. I'd agree with your interpretation of the netstat
> observations – but really, why on earth would the kernel be so short on
> ressources that it has to drop packets?
>
> This calls for an investigation of the run-time behaviour of your flow
> graph – something is eating up your ressources. Would you mind installing
> "perf" (under Fedora/Redhat/centos: dnf install perf,
> debian/Ubuntu/mint...: apt-get install linux-tools), then
>
> sudo sysctl kernel.perf_event_paranoid=-1
> perf record -ag python /path/to/your/flow/graph
> [let run for a minute or so, then stop operation]
> perf report
>
> That should give you a text UI that allows you to see at which points in
> operation the CPU was whenever perf looked.
> If you want to share that, an easy way would be writing the call tree to a
> file, e.g. "perf report --stdio > report.txt" and sharing that report.txt.
>
> Thanks!
> Marcus
>
>
> On 08/03/2017 12:06 PM, Jack White via USRP-users wrote:
>
> For the moment it's just a UHF satellite telemetry downlink (attached)
> with GMSK. The initial behaviour was that after maybe a minute, I would
> suddenly get a load of dropped packets (D in the log) - maybe a hundred or
> so - then 'normal service' would resume. But this process repeated for
> about an hour and then communication would stop, the processor load for
> python would drop to 0% and the gui plots would remain static in their last
> configuration. However, it's not that the programme has frozen, because I
> can still rescale all the plots - it's communication with the X310 that's
> stopped.
>
> Following the guidance of someone's post somewhere, I used netstat to
> monitor the kernel receive buffer errors (RcvbufErrors), which spiked over
> the running of the flowgraph. The poster said that this indicated the
> packets are being dropped in the kernel, not on the network card used for
> interfacing with the X310. So I installed a low-latency kernel. This has
> almost entirely got rid of the dropped packets, but the freeze now happens
> after maybe five minutes. GNU Radio doesn't log an error. I can ping the
> X310, but uhd_find_devices and uhd_usrp_probe don't find it, though maybe
> that's because there's still and open connection to it.
>
> Cheers,
>
> Jack
>
>
>
> On Thu, Aug 3, 2017 at 10:19 AM, Marcus Müller <marcus.muel...@ettus.com>
> wrote:
>
>> Ah! You've set the data type of the QT GUI sink to "complex message"; I
>> wasn't aware that this feature had made it to the master branch :)
>>
>> The point of moving to C++ was that the flowgraph I *really* want to use
>> is just causing me huge problems - most notably that there are periods of a
>> few seconds every now and again when the USRP drops a load of packets and
>> then, after a while, the flow just freezes up. I find it difficult to
>> follow how GNU Radio really works and I thought it would be a better bet to
>> be directly in control of my samples all the way.
>>
>> Hm, yeah, I know it's not trivial, but I'm pretty sure this isn't the way
>> to go. What kind of flow graph was giving you so much trouble?
>>
>>
>> Best regards,
>>
>> Marcus
>>
>> On 08/03/2017 11:15 AM, Jack White wrote:
>>
>> Hi Marcus,
>>
>> Thanks for the response. I attach the flowgraph I am using for this test,
>> and for which I got the "unknown data type of samples" error.
>>
>> I wasn't aware that the metadata was included in the PDUs, so that makes
>> more sense now.
>>
>> The point of moving to C++ was that the flowgraph I *really* want to use
>> is just causing me huge problems - most notably that there are periods of a
>> few seconds every now and again when the USRP drops a load of packets and
>> then, after a while, the flow just freezes up. I find it difficult to
>> follow how GNU Radio really works and I thought it would be a better bet to
>> be directly in control of my samples all the way.
>>
>> Jack
>>
>>
>>
>> On Wed, Aug 2, 2017 at 10:45 PM, Marcus Müller via USRP-users <
>> usrp-users@lists.ettus.com> wrote:
>>
>>> Hi Jack,
>>>
>>> PDUs are not just samples one after the other – they contain metadata. I
>>> can't really imagine what your flow graph looks like, so I'd be grateful
>>> for a screenshot (File->Screen Capture).
>>>
>>> Anyway, there'd be no obvious reason your UDP detour would make things
>>> faster – maybe the intermediate socket buffering might help, but you'd
>>> probably get the same result by extending a UHD USRP Source's Output Buffer
>>> Size.
>>>
>>> So, I'm not sure where we should take this – from a gut feeling, we
>>> should maybe move on to the discuss-gnuradio mailing list and discuss what
>>> part in your GNU Radio application isn't performing well enough – as I'm
>>> currently assuming your approach wasn't born through an in-depth analysis,
>>> but might more be of a trial&error iteration?
>>>
>>> Best regards,
>>>
>>> Marcus
>>>
>>> On 02.08.2017 13:10, Jack White via USRP-users wrote:
>>>
>>> Hi,
>>>
>>> I've been having some difficulty getting reliable data flow from my USRP
>>> X310 with a GRC flowgraph, so I'm trying out writing my system in C++ with
>>> the UHD driver API. My first step has been to retrieve samples from the
>>> X310, forward them to a UDP port and then pick them up with a GRC Socket
>>> PDU component and then plot them. The C++ programme, so far, follows
>>> Ettus's example rx_samples_to_udp almost exactly and uses the
>>> std::complex<float> data type.
>>>
>>> When the data enters the running flowgraph from the UDP transport, I get
>>> this error:
>>>
>>> thread[thread-per-block[1]: <block freq_sink_c (1)>]: freq_sink_c:
>>> unknown data type of samples; must be complex.
>>>
>>> Can anyone offer insight into why this should occur?
>>>
>>> Many thanks,
>>>
>>> --
>>> Jack White
>>> white.n.j...@googlemail.com
>>> 07875 813 745
>>>
>>>
>>> _______________________________________________
>>> USRP-users mailing
>>> listUSRP-users@lists.ettus.comhttp://lists.ettus.com/mailman/listinfo/usrp-users_lists.ettus.com
>>>
>>> _______________________________________________ USRP-users mailing list
>>> USRP-users@lists.ettus.com http://lists.ettus.com/mailman
>>> /listinfo/usrp-users_lists.ettus.com
>>
>> --
>> Jack White white.n.j...@googlemail.com 07875 813 745
>>
>> --
> Jack White white.n.j...@googlemail.com 07875 813 745
>
> _______________________________________________
> USRP-users mailing
> listUSRP-users@lists.ettus.comhttp://lists.ettus.com/mailman/listinfo/usrp-users_lists.ettus.com
>
>
> _______________________________________________
> USRP-users mailing list
> USRP-users@lists.ettus.com
> http://lists.ettus.com/mailman/listinfo/usrp-users_lists.ettus.com
>
>
--
Jack White
white.n.j...@googlemail.com
07875 813 745
_______________________________________________
USRP-users mailing list
USRP-users@lists.ettus.com
http://lists.ettus.com/mailman/listinfo/usrp-users_lists.ettus.com
