Note: This bug is displayed in read-only format because
the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
DescriptionDaniel Bristot de Oliveira
2020-10-28 10:38:57 UTC
Description of problem:
While trying to achieve low latency on OCP, I noticed the execution of this kworker on the isolated CPU:
----------------- %< ---------------
ksoftirqd/4-50 [004] d...113 9301.455882: workqueue_queue_work: work struct=000000006eb18cd3 function=vmstat_update workqueue=00000000dac03c76 req_cpu=4 cpu=4
ksoftirqd/4-50 [004] d...313 9301.455884: sched_wakeup: comm=kworker/4:1 pid=875 prio=120 target_cpu=004
ksoftirqd/4-50 [004] d...413 9301.455891: <stack trace>
=> trace_event_raw_event_sched_wakeup_template
=> ttwu_do_wakeup
=> try_to_wake_up
=> __queue_work
=> delayed_work_timer_fn
=> run_timer_softirq
=> __do_softirq
=> run_ksoftirqd
=> smpboot_thread_fn
=> kthread
=> ret_from_fork
kworker/4:1-875 [004] ....... 9301.455901: workqueue_execute_start: work struct 000000006eb18cd3: function vmstat_update
----------------- >% ---------------
Version-Release number of selected component (if applicable):
4.18.0-193.27.1.rt13.76
How reproducible:
Always
Steps to Reproduce:
1. Running oslat on OCP
2. Watch dmesg -w looking for stalld messages
Actual results:
Kworkers running, with trace pointing to vmstat_update work.
Expected results:
No kworkers
Additional info:
The good news is that it seems that they execute at the beginning of the "exclusive" container (in the first 120-ish seconds), and might be a side effect of the transition from non-exclusive to exclusive.
Note: I also saw this kworker:
----------------- %< ---------------
<...>-512642 [043] d...111 8670.567448: workqueue_queue_work: work struct=00000000299a67e1 function=drain_local_stock workqueue=000000002cfc6246 req_cpu=4 cpu=4
<...>-512642 [043] d...311 8670.567453: sched_wakeup: comm=kworker/4:1 pid=875 prio=120 target_cpu=004
<...>-512642 [043] d...411 8670.567461: <stack trace>
=> trace_event_raw_event_sched_wakeup_template
=> ttwu_do_wakeup
=> try_to_wake_up
=> __queue_work
=> queue_work_on
=> drain_all_stock
=> mem_cgroup_css_offline
=> css_killed_work_fn
=> process_one_work
=> worker_thread
=> kthread
=> ret_from_fork
kworker/4:1-875 [004] ....... 8670.567465: workqueue_execute_start: work struct 00000000299a67e1: function drain_local_stock
----------------- >% ---------------
But it seems to run at the end of the exclusive execution, to remove data from there. Anyway, if it is also happening during the execution, we will need to file another BZ.
Daniel,
It might be useful to open individual bugs for each kworker (since the solution
is separate).
Also, for the runc issue... Note that for kworkers there is an expectation that 10us per 1ms division
will be sufficient (since we know that kworkers perform periodic, short jobs) but for userspace
sufficient execution time might be larger: lack of progress might trigger timeouts up the stack,
causing (for example) container restarts.
Great progress!
Comment 3Daniel Bristot de Oliveira
2020-10-28 14:18:53 UTC
Yeah, I thought about opening two BZs, but if the memcg happens only after the end of the exclusive pod, it will not be a problem. So I mentioned it here as a "hey, if you hit this stack while the workload is running, please file a BZ."
The side effects of throttling kworkers will be felt by the threads waiting for it, obviously. That is why it is important to try to avoid them at all, as you are trying to achieve.
(In reply to Marcelo Tosatti from comment #7)
> Created attachment 1732633[details]
> testpmd patch to quiet vmstat before pkt fwd loop
>
> Built but untested.
Against dpdk.git.
One question, would something like this work as a wrapper too?
isolate.sh
#!/bin/sh
cat > /proc/sys/vm/quiet_vmstat &
exec "$@"
./isolate.sh oslat ....
(In reply to Martin Sivák from comment #12)
> One question, would something like this work as a wrapper too?
>
> isolate.sh
> #!/bin/sh
> cat > /proc/sys/vm/quiet_vmstat &
> exec "$@"
>
>
>
> ./isolate.sh oslat ....
Depends on the application, but for oslat, for example, it won't work.
So its better to suggest a proper change (which won't be a write to a file in /proc/, but
a prctl interface).
Anyway, for the current interface, please do it properly inside the application.
Description of problem: While trying to achieve low latency on OCP, I noticed the execution of this kworker on the isolated CPU: ----------------- %< --------------- ksoftirqd/4-50 [004] d...113 9301.455882: workqueue_queue_work: work struct=000000006eb18cd3 function=vmstat_update workqueue=00000000dac03c76 req_cpu=4 cpu=4 ksoftirqd/4-50 [004] d...313 9301.455884: sched_wakeup: comm=kworker/4:1 pid=875 prio=120 target_cpu=004 ksoftirqd/4-50 [004] d...413 9301.455891: <stack trace> => trace_event_raw_event_sched_wakeup_template => ttwu_do_wakeup => try_to_wake_up => __queue_work => delayed_work_timer_fn => run_timer_softirq => __do_softirq => run_ksoftirqd => smpboot_thread_fn => kthread => ret_from_fork kworker/4:1-875 [004] ....... 9301.455901: workqueue_execute_start: work struct 000000006eb18cd3: function vmstat_update ----------------- >% --------------- Version-Release number of selected component (if applicable): 4.18.0-193.27.1.rt13.76 How reproducible: Always Steps to Reproduce: 1. Running oslat on OCP 2. Watch dmesg -w looking for stalld messages Actual results: Kworkers running, with trace pointing to vmstat_update work. Expected results: No kworkers Additional info: The good news is that it seems that they execute at the beginning of the "exclusive" container (in the first 120-ish seconds), and might be a side effect of the transition from non-exclusive to exclusive. Note: I also saw this kworker: ----------------- %< --------------- <...>-512642 [043] d...111 8670.567448: workqueue_queue_work: work struct=00000000299a67e1 function=drain_local_stock workqueue=000000002cfc6246 req_cpu=4 cpu=4 <...>-512642 [043] d...311 8670.567453: sched_wakeup: comm=kworker/4:1 pid=875 prio=120 target_cpu=004 <...>-512642 [043] d...411 8670.567461: <stack trace> => trace_event_raw_event_sched_wakeup_template => ttwu_do_wakeup => try_to_wake_up => __queue_work => queue_work_on => drain_all_stock => mem_cgroup_css_offline => css_killed_work_fn => process_one_work => worker_thread => kthread => ret_from_fork kworker/4:1-875 [004] ....... 8670.567465: workqueue_execute_start: work struct 00000000299a67e1: function drain_local_stock ----------------- >% --------------- But it seems to run at the end of the exclusive execution, to remove data from there. Anyway, if it is also happening during the execution, we will need to file another BZ.