Bug 1444013

Summary: Scheduler/NOHZ: local_softirq_pending: SCHED/TASK
Product: Red Hat Enterprise Linux 7 Reporter: Marcelo Tosatti <mtosatti>
Component: kernel-rtAssignee: Crystal Wood <crwood>
kernel-rt sub component: Scheduler QA Contact: Red Hat Kernel QE team <kernel-qe>
Status: CLOSED WORKSFORME Docs Contact:
Severity: unspecified    
Priority: unspecified CC: bhu, core-kernel-mgr, crwood, jkacur, lgoncalv, mtosatti, williams
Version: 7.4   
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-10-23 18:39:11 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1474991, 1655690    

Description Marcelo Tosatti 2017-04-20 12:28:19 UTC 
(entering IDLE with pending SCHED/HRTIMER/TASK softirqs... should run pending softirq before entering IDLE i suppose?) What are the consequences of 
entering HLT with pending softirqs?


1) Kernel: kernel-rt-3.10.0-644.rt56.560.el7.x86_64
(had started a KVM guest, then DHCP activity, chrony...).

Apr 19 16:24:21 localhost avahi-daemon[909]: Registering new address record for fe80::405d:8dff:fe33:9eb4 on tap0.*.
Apr 19 16:24:21 localhost kernel: virbr0: port 2(tap0) entered learning state
Apr 19 16:24:23 localhost NetworkManager[961]: <info>  [1492629863.6244] device (virbr0): link connected
Apr 19 16:24:23 localhost kernel: virbr0: port 2(tap0) entered forwarding state
Apr 19 16:24:23 localhost kernel: virbr0: topology change detected, propagating
Apr 19 16:24:23 localhost kernel: IPv6: ADDRCONF(NETDEV_CHANGE): virbr0: link becomes ready
Apr 19 16:24:26 localhost kernel: kvm [3667]: vcpu0 unhandled rdmsr: 0x606
Apr 19 16:24:32 localhost kernel: kvm [3667]: vcpu0 unhandled rdmsr: 0x611
Apr 19 16:24:32 localhost kernel: kvm [3667]: vcpu0 unhandled rdmsr: 0x639
Apr 19 16:24:32 localhost kernel: kvm [3667]: vcpu0 unhandled rdmsr: 0x641
Apr 19 16:24:32 localhost kernel: kvm [3667]: vcpu0 unhandled rdmsr: 0x619
Apr 19 16:25:20 localhost dnsmasq-dhcp[2280]: DHCPDISCOVER(virbr0) 192.168.122.65 52:54:00:d8:75:ac
Apr 19 16:25:20 localhost dnsmasq-dhcp[2280]: DHCPOFFER(virbr0) 192.168.122.65 52:54:00:d8:75:ac
Apr 19 16:25:20 localhost dnsmasq-dhcp[2280]: DHCPREQUEST(virbr0) 192.168.122.65 52:54:00:d8:75:ac
Apr 19 16:25:20 localhost dnsmasq-dhcp[2280]: DHCPACK(virbr0) 192.168.122.65 52:54:00:d8:75:ac
Apr 19 16:25:22 localhost dnsmasq-dhcp[2280]: DHCPDISCOVER(virbr0) 52:54:00:d8:75:ac
Apr 19 16:25:22 localhost dnsmasq-dhcp[2280]: DHCPOFFER(virbr0) 192.168.122.65 52:54:00:d8:75:ac
Apr 19 16:25:22 localhost dnsmasq-dhcp[2280]: DHCPREQUEST(virbr0) 192.168.122.65 52:54:00:d8:75:ac
Apr 19 16:25:22 localhost dnsmasq-dhcp[2280]: DHCPACK(virbr0) 192.168.122.65 52:54:00:d8:75:ac
Apr 19 16:28:17 localhost systemd: Starting Cleanup of Temporary Directories...
Apr 19 16:28:30 localhost systemd: Started Cleanup of Temporary Directories.
Apr 19 16:30:02 localhost systemd: Started Session 6 of user root.
Apr 19 16:30:02 localhost systemd: Starting Session 6 of user root.
Apr 19 16:35:14 localhost systemd-logind: New session 7 of user root.
Apr 19 16:35:14 localhost systemd: Started Session 7 of user root.
Apr 19 16:35:14 localhost systemd: Starting Session 7 of user root.
Apr 19 16:35:29 localhost systemd-logind: Removed session 7.
Apr 19 16:38:14 localhost chronyd[924]: Can't synchronise: no selectable sources
Apr 19 16:40:02 localhost systemd: Started Session 8 of user root.
Apr 19 16:40:02 localhost systemd: Starting Session 8 of user root.
Apr 19 16:48:30 localhost dnsmasq-dhcp[2280]: DHCPREQUEST(virbr0) 192.168.122.65 52:54:00:d8:75:ac
Apr 19 16:48:30 localhost dnsmasq-dhcp[2280]: DHCPACK(virbr0) 192.168.122.65 52:54:00:d8:75:ac
Apr 19 16:50:01 localhost systemd: Started Session 9 of user root.
Apr 19 16:50:01 localhost systemd: Starting Session 9 of user root.
Apr 19 16:52:30 localhost dnsmasq-dhcp[2280]: DHCPREQUEST(virbr0) 192.168.122.65 52:54:00:d8:75:ac
Apr 19 16:52:30 localhost dnsmasq-dhcp[2280]: DHCPACK(virbr0) 192.168.122.65 52:54:00:d8:75:ac
Apr 19 17:00:01 localhost systemd: Started Session 10 of user root.
Apr 19 17:00:01 localhost systemd: Starting Session 10 of user root.
Apr 19 17:01:01 localhost systemd: Started Session 11 of user root.
Apr 19 17:01:01 localhost systemd: Starting Session 11 of user root.
Apr 19 17:09:07 localhost systemd-logind: New session 12 of user root.
Apr 19 17:09:07 localhost systemd: Started Session 12 of user root.
Apr 19 17:09:07 localhost systemd: Starting Session 12 of user root.
Apr 19 17:09:28 localhost dbus-daemon: dbus[957]: [system] Activating service name='org.freedesktop.problems' (using servicehelper)
Apr 19 17:09:28 localhost dbus[957]: [system] Activating service name='org.freedesktop.problems' (using servicehelper)
Apr 19 17:09:28 localhost dbus-daemon: dbus[957]: [system] Successfully activated service 'org.freedesktop.problems'
Apr 19 17:09:28 localhost dbus[957]: [system] Successfully activated service 'org.freedesktop.problems'
Apr 19 17:10:01 localhost systemd: Started Session 13 of user root.
Apr 19 17:10:01 localhost systemd: Starting Session 13 of user root.
Apr 19 17:10:35 localhost chronyd[924]: Selected source 200.160.7.193
Apr 19 17:14:51 localhost systemd-logind: Removed session 2.
Apr 19 17:15:01 localhost avahi-daemon[909]: Withdrawing address record for fe80::405d:8dff:fe33:9eb4 on tap0.
Apr 19 17:15:01 localhost kernel: CPU1: NOHZ: local_softirq_pending: TASKLET
Apr 19 17:15:01 localhost kernel: CPU1: NOHZ: local_softirq_pending: TASKLET
Apr 19 17:15:01 localhost kernel: virbr0: port 2(tap0) entered disabled state

2) Kernel: 3.10.0-631.rt56.546.el7.x86_64


Description of https://bugzilla.redhat.com/show_bug.cgi?id=1438120

So at present there does not seem to be a synthetic reproducer.
Comment 2 Crystal Wood 2017-06-07 02:57:22 UTC 
It looks like this can happen if a thread is trying to handle multiple softirqs, and is blocked on lock_softirq() for a different softirq that is currently being handled by another thread, which in turn is blocked on some other lock.  The former thread won't have gotten to the point where it records itself in softirq_runners, and thus won't be seen by softirq_check_pending_idle().
Comment 6 Marcelo Tosatti 2019-10-23 18:39:11 UTC 
Closing as haven't seen this recently. 

Please reopen if necessary.