Bug 1252160

Summary: tuned profile aborts with ERROR NameError: name 'listdir' is not defined
Product: Red Hat Enterprise Linux 7 Reporter: Jeff Nelson <jen>
Component: tunedAssignee: Jaroslav Škarvada <jskarvad>
Status: CLOSED ERRATA QA Contact: Tereza Cerna <tcerna>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7.2CC: jeder, jen, jskarvad, tcerna
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: tuned-2.7.0-1.el7 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 1357617 (view as bug list) Environment:
Last Closed: 2016-11-04 07:24:14 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:
Attachments:
Description Flags
tuned logfile none

Description Jeff Nelson 2015-08-10 20:39:27 UTC
Created attachment 1061250 [details]
tuned logfile

Description of problem:
While reporting earlier problems in tuned, noticed the following errors in the tuned logfile starting at 16:11:

2015-08-10 16:11:00,030 INFO     tuned.daemon.daemon: stopping tunning
2015-08-10 16:11:00,478 INFO     tuned.plugins.plugin_script: calling script '/usr/lib/tuned/realtime-virtual-host/script.sh' with argument 'stop'
2015-08-10 16:11:00,624 ERROR    tuned.plugins.plugin_script: script '/usr/lib/tuned/realtime-virtual-host/script.sh' error: 1, 'Traceback (most recent call last):
  File "/usr/libexec/tuned/defirqaffinity.py", line 106, in <module>
    interruptdirs = [ f for f in listdir(irqpath) if isdir(join(irqpath,f)) ]
NameError: name 'listdir' is not defined'
2015-08-10 16:11:00,656 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 459's affinity: Invalid argument
2015-08-10 16:11:00,661 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 450's affinity: Invalid argument
2015-08-10 16:11:00,665 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 452's affinity: Invalid argument

I do not know if the affinity errors are triggered by the preceding listdir error, but I am including them in this report so that they can be solved too.

Version-Release number of selected component (if applicable):
# yum list installed | egrep tuned
tuned.noarch                          2.5.1-1.el7             @beaker-Server/7.2
tuned-profiles-nfv.noarch             2.5.1-1.el7             @/tuned-profiles-nfv-2.5.1-1.el7.noarch
tuned-profiles-realtime.noarch        2.5.1-1.el7             @beaker-Server-RT 


How reproducible:
Seen only once.

Steps to Reproduce:
1. Unknown. Perhaps just:
   # tuned-adm profile realtime-virtual-host
   # tuned-adm verify
and then wait?


Actual results:
Errors as shown above.

Expected results:
No errors

Additional info:
# uname -a
Linux localhost.localdomain 3.10.0-302.rt56.174.el7.x86_64 #1 SMP PREEMPT RT Mon Aug 3 15:01:33 EDT 2015 x86_64 x86_64 x86_64 GNU/Linux
# cat /proc/cmdline 
BOOT_IMAGE=/vmlinuz-3.10.0-302.rt56.174.el7.x86_64 root=/dev/mapper/rhel_virtlab420-root ro crashkernel=auto rd.lvm.lv=rhel_virtlab420/root rd.lvm.lv=rhel_virtlab420/swap console=ttyS1,115200 default_hugepagesz=1G isolcpus=1,3,5,7,9,11,13,14,15 nohz_full=1,3,5,7,9,11,13,14,15 intel_pstate=disable nosoftlockup
# lscpu | grep NUMA
NUMA node(s):          2
NUMA node0 CPU(s):     0,2,4,6,8,10,12,14
NUMA node1 CPU(s):     1,3,5,7,9,11,13,15

Comment 2 Jaroslav Škarvada 2015-08-20 13:44:55 UTC
Fixed by following upstream commit:
https://git.fedorahosted.org/cgit/tuned.git/commit/?id=7d1febccaa6d73fbb00bb1626c37f599e5d555ff

It's merged code and the interruptdirs have probably never been set correctly. If you think it qualifies as a blocker, feel free to propose it, otherwise I am going to postpone it to RHEL-7.3.

Comment 3 Jaroslav Škarvada 2015-08-20 13:54:33 UTC
Regarding taskset error, I think it is not related, could you provide log from run in debug mode? The easiest way is:

# systemctl stop tuned
# tuned -DP

It should show something like:
DEBUG:... setting affinity to '%s' for PID '%s'

Comment 6 Jeff Nelson 2015-08-28 15:29:15 UTC
An annotated log has been uploaded. Search for "%MARK%" to locate comments that describe what was done to trigger the output that follows.

It appears that the taskset error is triggered by:

* tuned-adm off
* typing ^C in the window running tuned -DP

Comment 7 Jaroslav Škarvada 2016-07-18 15:54:34 UTC
The taskset errors are harmless, it seems the following is happening:
- the CPU is isolated
- tasks are migrated from it
- machine shutdown triggers the Tuned shutdown or Tuned profile is changed
- Tuned rollbacks its changes and it tries to migrate the tasks back to their original CPUs, but it's no longer possible, because the CPU(s) is(are) isolated

I will open new bugzilla regarding this problem.

Comment 8 Jaroslav Škarvada 2016-07-18 16:08:42 UTC
(In reply to Jaroslav Škarvada from comment #7)
> The taskset errors are harmless, it seems the following is happening:
> - the CPU is isolated
> - tasks are migrated from it
> - machine shutdown triggers the Tuned shutdown or Tuned profile is changed
> - Tuned rollbacks its changes and it tries to migrate the tasks back to
> their original CPUs, but it's no longer possible, because the CPU(s) is(are)
> isolated
> 
> I will open new bugzilla regarding this problem.

Well, the taskset should be able to move the task to the isolated CPU. Maybe it cannot have SCHED_FIFO. I will definitely look on this later.

Comment 9 Jaroslav Škarvada 2016-07-18 16:10:24 UTC
I opened bug 1357617 regarding this problem.

Comment 11 Tereza Cerna 2016-09-08 11:21:56 UTC
=================================================
Verified in:
   tuned-2.7.1-2.el7.noarch
   tuned-profiles-nfv-2.7.1-2.el7.noarch
   tuned-profiles-realtime-2.7.1-2.el7.noarch
PASS
=================================================

# cat /etc/tuned/realtime-virtual-host-variables.conf
isolated_cores=1-3

# tuned-adm profile realtime-virtual-host
# tuned-adm active
Current active profile: realtime-virtual-host

# cat /var/log/tuned/tuned.log | grep ERROR
2016-09-08 07:20:56,115 ERROR    tuned.utils.polkit: error querying polkit: Unable to guess signature from an empty dict
2016-09-08 07:20:56,589 ERROR    tuned.utils.polkit: error querying polkit: Unable to guess signature from an empty dict

No mentioned error about 'affinity: Invalid argument'.

=================================================
Reproduced in:
   tuned-2.5.1-4.el7_2.3.noarch
   tuned-profiles-nfv-2.5.1-4.el7_2.3.noarch
   tuned-profiles-realtime-2.5.1-4.el7_2.3.noarch
FAIL
=================================================

# cat /etc/tuned/realtime-virtual-host-variables.conf
isolated_cores=1-3

# tuned-adm profile realtime-virtual-host
# tuned-adm active
Current active profile: realtime-virtual-host

# cat /var/log/tuned/tuned.log | grep ERROR
2016-09-08 07:13:34,881 ERROR    tuned.plugins.plugin_script: script '/usr/lib/tuned/realtime-virtual-host/script.sh' error: 1, 'Traceback (most recent call last):
2016-09-08 07:13:35,908 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 216's affinity: Invalid argument
2016-09-08 07:13:35,913 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 212's affinity: Invalid argument
2016-09-08 07:13:35,918 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 229's affinity: Invalid argument
2016-09-08 07:13:35,922 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 156's affinity: Invalid argument
2016-09-08 07:13:35,927 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 313's affinity: Invalid argument
2016-09-08 07:13:35,932 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 337's affinity: Invalid argument
2016-09-08 07:13:35,936 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 196's affinity: Invalid argument
2016-09-08 07:13:35,941 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 317's affinity: Invalid argument
2016-09-08 07:13:35,946 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 333's affinity: Invalid argument
2016-09-08 07:13:35,950 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 192's affinity: Invalid argument
2016-09-08 07:13:35,955 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 393's affinity: Invalid argument
2016-09-08 07:13:35,959 ERROR    tuned.utils.commands: Executing taskset error: taskset: failed to set pid 273's affinity: Invalid argument
...

Comment 13 errata-xmlrpc 2016-11-04 07:24:14 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2016-2479.html