Re: Vector Source and QT GUI Time Sink causes performance drop

Hi,

Thanks for the hint, I didn't know about this method of profiling :). I did as you requested and it seems that it spends quite a lot of time in Qt, namely in gray_render_line and gray_render_scanline functions.

If my understanding is correct, this time is spent in Qt itself, not in the underlying graphics stack. Which would mean that either GNU Radio generates too many rendering requests or this version of Qt is buggy. What do you think?

Full output:

+ 33,04% 32,32% python3 libQt5Gui.so.5 [.] gray_render_line
+ 23,39% 22,70% python3 libQt5Gui.so.5 [.] gray_render_scanline
+ 11,10% 0,00% swapper [kernel.kallsyms] [k] secondary_startup_64
+ 11,10% 0,00% swapper [kernel.kallsyms] [k] cpu_startup_entry
+ 11,08% 0,02% swapper [kernel.kallsyms] [k] do_idle
+ 10,59% 0,01% swapper [kernel.kallsyms] [k] call_cpuidle
+ 10,58% 0,00% swapper [kernel.kallsyms] [k] cpuidle_enter
+ 10,56% 0,04% swapper [kernel.kallsyms] [k] cpuidle_enter_state
+ 10,08% 0,00% swapper [kernel.kallsyms] [k] start_secondary
+ 6,50% 0,02% swapper [kernel.kallsyms] [k] acpi_idle_enter
+ 6,47% 6,20% swapper [kernel.kallsyms] [k] acpi_processor_ffh_cstate_enter
+ 6,46% 0,00% swapper [kernel.kallsyms] [k] acpi_idle_do_entry
+ 4,26% 0,00% python3 [unknown] [k] 0x0000000000000004
+ 4,15% 0,35% python3 libc-2.31.so [.] __sched_yield
+ 4,04% 0,01% swapper [kernel.kallsyms] [k] acpi_idle_enter_bm
+ 3,57% 0,00% swapper [kernel.kallsyms] [k] ret_from_intr
+ 3,57% 0,00% swapper [kernel.kallsyms] [k] do_IRQ
+ 3,56% 0,00% swapper [kernel.kallsyms] [k] handle_fasteoi_irq
+ 3,56% 0,00% swapper [kernel.kallsyms] [k] handle_irq_event
+ 3,56% 0,00% swapper [kernel.kallsyms] [k] handle_irq_event_percpu
+ 3,48% 0,00% swapper [kernel.kallsyms] [k] __handle_irq_event_percpu
+ 3,37% 0,14% python3 [kernel.kallsyms] [k] entry_SYSCALL_64_after_hwframe
+ 3,18% 0,08% python3 [kernel.kallsyms] [k] do_syscall_64
+ 2,87% 0,06% python3 [kernel.kallsyms] [k] __x64_sys_sched_yield
+ 2,65% 0,08% python3 [kernel.kallsyms] [k] do_sched_yield
+ 2,54% 0,07% python3 [kernel.kallsyms] [k] schedule
+ 2,30% 0,00% swapper [kernel.kallsyms] [k] acpi_irq
+ 2,29% 0,00% swapper [kernel.kallsyms] [k] acpi_ev_sci_xrupt_handler
+ 2,27% 0,42% python3 [kernel.kallsyms] [k] __sched_text_start
+ 2,26% 0,00% swapper [kernel.kallsyms] [k] acpi_ev_gpe_detect
+ 2,23% 0,00% swapper [kernel.kallsyms] [k] acpi_ev_detect_gpe
+ 2,01% 0,04% WebExtensions [unknown] [.] 0000000000000000
+ 1,96% 0,01% swapper [kernel.kallsyms] [k] acpi_hw_read
+ 1,94% 0,00% swapper [kernel.kallsyms] [k] acpi_hw_read_port
+ 1,93% 1,93% swapper [kernel.kallsyms] [k] acpi_os_read_port
+ 1,50% 0,43% python3 [kernel.kallsyms] [k] pick_next_task_fair
+ 1,10% 0,00% WebExtensions [unknown] [.] 0xf8894804751efe83
+ 1,10% 0,00% WebExtensions libxul.so [.] 0x00007fe0e92a31f0
+ 1,02% 0,00% swapper [kernel.kallsyms] [k] x86_64_start_kernel
+ 1,02% 0,00% swapper [kernel.kallsyms] [k] x86_64_start_reservations
+ 1,02% 0,00% swapper [kernel.kallsyms] [k] start_kernel
+ 1,02% 0,00% swapper [kernel.kallsyms] [k] arch_call_rest_init
+ 1,02% 0,00% swapper [kernel.kallsyms] [k] rest_init
+ 1,00% 1,00% python3 libQt5Gui.so.5 [.] gray_set_cell

It seems that 50% of the time is spend in libQt5Gui.so. As far as I understand the output, "swapper" is a kernel process, so it may or may not be related.

I'll try to build latest Qt separately later and link GNU Radio against it, and see what happens :>

Best Regards,

Mariusz Plucinski

Am Mo., 11. Jan. 2021 um 12:29 Uhr schrieb Marcus Müller <mueller@kit.edu>:

Hi,

I'm on the run, else I'd start a Ubuntu VM myself, but:

sudo apt install linux-tools
sudo sysctl -w kernel.perf_event_paranoid=-1

perf record -ag python3 /path/to/your/flowgraph.py

run for a couple of seconds, close.

Afterwards,

perf report

will hopefully show you a percentage of "of the times we looked, the CPU
was busy with this and that function".

Best regards,
Marcus

On 11/01/2021 12.15, Mariusz Pluciński wrote:
> Hi,
>
> I tested on a different machine of mine (Fedora 32, GNU Radio 3.8.2) and
> the problem does not occur there.
> This suggests that the problem is somehow specific to this Ubuntu
> system, but not to a specific build of GNU Radio (nor Python, it occurs
> with both 3.8 and 3.9). Since this looks more like a GUI problem than
> signal processing itself, I'm wondering if it may be related to the Qt
> version there - 5.12.8. The machine it works correctly on has 5.14.2
> installed.
>
> Attached the test file. It works fine on my Fedora but very slow (in
> terms of GUI responsiveness) on my Ubuntu. Would be great if somebody
> could point me in a right direction of what else I can check.
>
> Mit freundlichen Grüßen
> Mariusz Plucinski
>
>
> Am So., 10. Jan. 2021 um 18:41 Uhr schrieb Jeff Long
> <willcode4@gmail.com <mailto:willcode4@gmail.com>>:
>
> I was using 2MS/s, tested with 3.8 and master (which should be close
> enough to 3.9). Nothing comes to mind. You could post a GRC file,
> just in case there's a misunderstanding of how something works.
>
> On Sun, Jan 10, 2021 at 10:00 AM Mariusz Pluciński
> <plucinski.mariusz@gmail.com <mailto:plucinski.mariusz@gmail.com>>
> wrote:
>
> Thank you for trying this. It assures me that it's something
> wrong either in my project or in my configuration.
>
> I also tried to build GNU Radio from source (3.9.0 RC2 from
> git), but the problem also occurs there.
>
> What do you mean by "reasonable sample rate"? I'm trying with
> very low values like 300 (in both throttler and time sink) and
> the problem still occurs.
>
> In the new build, there seems to be a small delay before the
> data appear on the chart. Up to this moment, the window is
> reponsive, but as soon as the green lines appear, it becomes not
> responsive again - best visible when trying to resize the window.
>
> Is there anything else I can check?
>
> Mit freundlichen Grüßen
> Mariusz Plucinski
>
>
> Am So., 10. Jan. 2021 um 02:55 Uhr schrieb Jeff Long
> <willcode4@gmail.com <mailto:willcode4@gmail.com>>:
>
> I gave this a try, adding Vector Source -> Throttle -> QT
> GUI Time Sink to a flowgraph. Performance is fine at 2MS/s
> on an older laptop. Make sure that the Throttle is being set
> to a reasonable sample rate.
>
> On Sat, Jan 9, 2021 at 6:35 PM Mariusz Pluciński
> <plucinski.mariusz@gmail.com
> <mailto:plucinski.mariusz@gmail.com>> wrote:
>
> Hi,
>
> Thanks for the answers. Unfortunately, I already tried
> this before (forgot to mention) and it doesn't change
> anything in this weird behavior of the GUI window.
> It also doesn't help to have a hardware source and/or
> sink in the flow (tried with Audio Sink and osmocom
> Sink/Source); as soon as I enable both Vector Source and
> QT GUI Time Sink at the same time (anywhere in the
> flow), everything becomes unusably slow.
>
> I also tried to add a separate path Null Source ->
> Throttle -> Null Sink (as seen somewhere in the Wiki),
> but this also didn't help. Changing sample rate of the
> throttle also doesn't seem to change anything.
>
> Is there any way I can diagnose this issue?
>
> Regards,
> Mariusz
>
> Am Sa., 9. Jan. 2021 um 23:47 Uhr schrieb Derek Kozel
> <derek@bitstovolts.com <mailto:derek@bitstovolts.com>>:
>
> Hi Mariusz,
>
> The main issue here is that you're missing a
> Throttle block in your flowgraph. You have no
> Hardware block in the flowgraph, it is pure
> simulation. GNU Radio will try to run the processing
> as fast as possible, using 100% of available CPU. A
> Throttle block limits the simulation speed to
> approximately realtime (to the set sample rate per
> second).
>
> A hardware source or sink will have a real, physical
> clock and will restrict the number of samples
> produced (Source) or consumed (Sink) and the other
> blocks will not be able to run at infinite speed
> (using all the CPU).
>
> I'm curious why that would work better with a
> different non-hardware source rather than the Vector
> Source, but the recommended fix is straightforward.
>
> Regards,
> Derek
>
>
>
>
> Am Sa., 9. Jan. 2021 um 23:49 Uhr schrieb Ron Economos
> <w6rz@comcast.net <mailto:w6rz@comcast.net>>:
>
> It's telling you what's wrong.
>
> >>> Warning: This flow graph may not have flow
> control: no audio or RF hardware blocks found. Add a
> Misc->Throttle block to your flow graph to avoid CPU
> congestion.
>
> Add a Throttle block between the Vector Source and
> QT GUI Time Sink blocks.
>
> Ron
>
>
> On 1/9/21 14:32, Mariusz Pluciński wrote:
>> Hello everybody,
>>
>> I'm quite new to GNU Radio (and to signal
>> processing as well), but I did a few successful
>> experimens. But now, I encountered a weird
>> behavior, namely:
>>
>> Every flowgraph including Vector Source and QT GUI
>> Time Sink conencted (regardless if directly or
>> with intermediate steps) causes huge performance
>> degradation. CPU usage jumps to 100% of a core,
>> window takes a few seconds to refresh, GUI becomes
>> almost unusable.
>>
>> Everything works well if I use any different
>> source, .e.g. Signal Source or osmocom Source.
>> Everything works well if I use any different sink,
>> e.g. Audio Sink or QT GUI Frequency Sink.
>>
>> It's just this specific combination that causes
>> the issue. Drastically reducing the number of
>> points in the Time Sink helps, but at the cost of
>> the output becoming useless.
>>
>> To reproduce the problem, it's enough to do the
>> following in GNU Radio Companion:
>> 1. Create an empty flow graph
>> 2. Add "Vector Source"
>> 3. Change "Vector" parameter to "(0, 0, 0, 1)"
>> 4. Add "QT GUI Time Sink"
>> 5. Connect both blocks
>> 6. Run
>>
>> Am I doing something wrong here?
>>
>> (in case it's necessary, my ultimate goal here is
>> to use the vector source as a source of bits to
>> modulate a square wave; the output will later be
>> transmitted out, but first, I'd like to see it in
>> the Time Sink)
>>
>> I'm using GNU Radio 3.8.1.0 on Ubuntu 20.04.
>>
>> Best Regards,
>> Mariusz Plucinski
>

From:	Mariusz Pluciński
Subject:	Re: Vector Source and QT GUI Time Sink causes performance drop
Date:	Mon, 11 Jan 2021 16:53:36 +0100