Bug 1252160 - tuned profile aborts with ERROR NameError: name 'listdir' is not defined
tuned profile aborts with ERROR NameError: name 'listdir' is not defined
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: tuned (Show other bugs)
7.2
Unspecified Unspecified
unspecified Severity unspecified
: rc
: ---
Assigned To: Jaroslav Škarvada
Tereza Cerna
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-08-10 16:39 EDT by Jeff Nelson
Modified: 2016-11-04 03:24 EDT (History)
4 users (show)

See Also:
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 03:24:14 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
tuned logfile (58.12 KB, text/plain)
2015-08-10 16:39 EDT, Jeff Nelson
no flags Details


External Trackers
Tracker ID Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2016:2479 normal SHIPPED_LIVE tuned bug fix and enhancement update 2016-11-03 10:08:42 EDT

  None (edit)
Description Jeff Nelson 2015-08-10 16:39:27 EDT
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 09:44:55 EDT
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 09:54:33 EDT
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 11:29:15 EDT
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 11:54:34 EDT
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 12:08:42 EDT
(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 12:10:24 EDT
I opened bug 1357617 regarding this problem.
Comment 11 Tereza Cerna 2016-09-08 07:21:56 EDT
=================================================
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 03:24:14 EDT
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

Note You need to log in before you can comment on or make changes to this bug.