Bug 1434360

Summary: tuned can list profile as loaded even if it is not correctly loaded
Product: Red Hat Enterprise Linux 7 Reporter: Jaroslav Škarvada <jskarvad>
Component: tunedAssignee: Jaroslav Škarvada <jskarvad>
Status: CLOSED ERRATA QA Contact: Tereza Cerna <tcerna>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: 7.4CC: cchen, jeder, jianzzha, jskarvad, olysonek, qe-baseos-daemons, tcerna
Target Milestone: rcKeywords: Patch, Upstream
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: tuned-2.8.0-1.el7 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 1432240 Environment:
Last Closed: 2017-08-01 12:35:21 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:

Comment 2 Jaroslav Škarvada 2017-03-21 11:01:59 UTC
Reproducer:

1. Make test profile (let's name it 'test') with e.g. the following content:
 [variables]
2. start tuned
3. set the test profile:
 tuned-adm profile test
4. change the test profile to contain the following:
 [variables]
 assert=${f:assertion:invalid:1:2}
5. reapply the profile by
 tuned-adm profile test

Check tuned.log, you will find there something like:
2017-03-21 11:15:16,247 INFO     tuned.profiles.loader: loading profile: test
2017-03-21 11:15:16,249 ERROR    tuned.profiles.functions.function_assertion: assertion 'invalid' failed: '1' != '2'
2017-03-21 11:15:16,249 INFO     tuned.daemon.daemon: starting tuning
2017-03-21 11:15:16,250 INFO     tuned.daemon.daemon: static tuning from profile 'test' applied

And the last line is apparently wrong.

Comment 3 Jaroslav Škarvada 2017-03-21 11:03:16 UTC
Clonned as bug 1434360.

Comment 4 Jaroslav Škarvada 2017-03-21 11:04:26 UTC
(In reply to Jaroslav Škarvada from comment #3)
> Clonned as bug 1434360.

Comment which belongs to parent bug :)

Comment 5 Ondřej Lysoněk 2017-03-22 15:36:15 UTC
(In reply to Jaroslav Škarvada from comment #2)
> And the last line is apparently wrong.

I wouldn't say it's wrong, but it is inacurate and confusing. Loading of the profile in fact succeeds, however tuned loads the old version of the profile, which it still holds in memory. Maybe we could just print a warning that we're loading an old version of the profile, for example like this:

2017-03-21 11:15:16,247 INFO     tuned.profiles.loader: loading profile: test
2017-03-21 11:15:16,249 ERROR    tuned.profiles.functions.function_assertion: assertion 'invalid' failed: '1' != '2'
2017-03-21 11:15:16,249 INFO     tuned.daemon.daemon: starting tuning
2017-03-21 11:15:16,249 WARNING     tuned.daemon.daemon: loading an old version of profile 'test'
2017-03-21 11:15:16,250 INFO     tuned.daemon.daemon: static tuning from out-dated profile 'test' applied

Any other proposals?

Comment 6 Jaroslav Škarvada 2017-03-22 16:35:59 UTC
(In reply to Ondřej Lysoněk from comment #5)
> (In reply to Jaroslav Škarvada from comment #2)
> > And the last line is apparently wrong.
> 
> I wouldn't say it's wrong, but it is inacurate and confusing. Loading of the
> profile in fact succeeds, however tuned loads the old version of the
> profile, which it still holds in memory. Maybe we could just print a warning
> that we're loading an old version of the profile, for example like this:
> 
> 2017-03-21 11:15:16,247 INFO     tuned.profiles.loader: loading profile: test
> 2017-03-21 11:15:16,249 ERROR   
> tuned.profiles.functions.function_assertion: assertion 'invalid' failed: '1'
> != '2'
> 2017-03-21 11:15:16,249 INFO     tuned.daemon.daemon: starting tuning
> 2017-03-21 11:15:16,249 WARNING     tuned.daemon.daemon: loading an old
> version of profile 'test'
> 2017-03-21 11:15:16,250 INFO     tuned.daemon.daemon: static tuning from
> out-dated profile 'test' applied
> 
> Any other proposals?

Thanks for taking deeper look. I think this is really confusing behavior. Maybe we could add the warning for 7.4, but for 7.5 this needs to be resolved more robust way, i.e.:
- we need to do correct roll-back of partially loaded profiles
- we need to allow Tuned to run and correctly respond to DBus calls even if running without profile
- we need to fix the assertion function to correctly work everywhere in the tuned.conf

Chen are you OK with the 7.4 workaround, i.e. with the warning in the logs?

Comment 7 Chen 2017-03-23 05:37:58 UTC
Hi Jaroslav,

Sure I'm OK with the workaround. Actually what I am really caring about is the release of fixing [1] because this is kind of preventing the deployment of OpenStack.

[1] https://github.com/redhat-performance/tuned/commit/e052fd14a17e7872d0880720b15db2097b58f5a4.

Best Regards,
Chen

Comment 8 Ondřej Lysoněk 2017-03-23 09:06:00 UTC
(In reply to Jaroslav Škarvada from comment #6)

> Chen are you OK with the 7.4 workaround, i.e. with the warning in the logs?

I don't quite see how my proposal is a workaround.

> - we need to do correct roll-back of partially loaded profiles
> - we need to allow Tuned to run and correctly respond to DBus calls even if
> running without profile
> - we need to fix the assertion function to correctly work everywhere in the
> tuned.conf

These problems are IMHO more or less unrelated to what this bugzilla is about. We're dealing with what to do, when applying a profile fails. The obvious options are a) run without a profile, and b) fallback to the previously applied profile. b) is what we currently have. And the problem is, that we don't check if the profile configuration we have loaded in memory is the same as it is on disk, and so we get confusing messages in the log. My proposal is to check whether the profile on disk and in memory differ, and print a warning if they do. So I don't really see this as a workaround, but a real solution. It might not be the best solution of course.

Comment 9 Ondřej Lysoněk 2017-03-23 09:27:20 UTC
Another option might be the following: if the name of the profile, which failed to apply, is the same as the name of the previously applied profile, then we discard the profile from memory and run without a profile. This would probably be much simpler to implement.

Comment 10 Jaroslav Škarvada 2017-03-23 09:37:31 UTC
(In reply to Chen from comment #7)
> Hi Jaroslav,
> 
> Sure I'm OK with the workaround. Actually what I am really caring about is
> the release of fixing [1] because this is kind of preventing the deployment
> of OpenStack.
> 
> [1]
> https://github.com/redhat-performance/tuned/commit/
> e052fd14a17e7872d0880720b15db2097b58f5a4.
> 
It's already upstream, and it will target RHEL-7.4. If you need to z-stream the change or target specific product/dist-git branch other than RHEL-7.4. it will need additional care (flags, clone, etc.).

Comment 11 Jaroslav Škarvada 2017-03-23 09:39:25 UTC
(In reply to Ondřej Lysoněk from comment #8)
> (In reply to Jaroslav Škarvada from comment #6)
> 
> > Chen are you OK with the 7.4 workaround, i.e. with the warning in the logs?
> 
> I don't quite see how my proposal is a workaround.
> 
> > - we need to do correct roll-back of partially loaded profiles
> > - we need to allow Tuned to run and correctly respond to DBus calls even if
> > running without profile
> > - we need to fix the assertion function to correctly work everywhere in the
> > tuned.conf
> 
> These problems are IMHO more or less unrelated to what this bugzilla is
> about. We're dealing with what to do, when applying a profile fails. The
> obvious options are a) run without a profile, and b) fallback to the
> previously applied profile. b) is what we currently have. And the problem
> is, that we don't check if the profile configuration we have loaded in
> memory is the same as it is on disk, and so we get confusing messages in the
> log. My proposal is to check whether the profile on disk and in memory
> differ, and print a warning if they do. So I don't really see this as a
> workaround, but a real solution. It might not be the best solution of course.

Source of the problem is assertion built-in function which started like a hack and needs to be improved. Without it it's unlikely that loading of stock profiles fail.

Comment 12 Jaroslav Škarvada 2017-03-23 09:40:25 UTC
(In reply to Ondřej Lysoněk from comment #9)
> Another option might be the following: if the name of the profile, which
> failed to apply, is the same as the name of the previously applied profile,
> then we discard the profile from memory and run without a profile. This
> would probably be much simpler to implement.

If it works without side effects I am for it.

Comment 13 Jaroslav Škarvada 2017-03-27 13:11:45 UTC
Upstream fix (I would say workaround, but let's call it fix :):
https://github.com/redhat-performance/tuned/pull/29

Comment 15 Tereza Cerna 2017-05-04 11:38:24 UTC
Works as expected. -> VERIFIED

======================================================
Verified in:
    tuned-2.8.0-2.el7.noarch
    tuned-profiles-cpu-partitioning-2.8.0-2.el7.noarch
PASS
======================================================

~~ odd numbers ~~

# tuned-adm profile balanced
# cat /etc/tuned/cpu-partitioning-variables.conf
isolated_cores=1,3,5,7
# tuned-adm profile cpu-partitioning
# tuned-adm active
Current active profile: cpu-partitioning
# reboot

# tuned-adm verify
Verfication succeeded, current system settings match the preset profile.
See tuned log file ('/var/log/tuned/tuned.log') for details.

~~ even numbers ~~

# tuned-adm profile balanced
# cat /etc/tuned/cpu-partitioning-variables.conf
isolated_cores=2,4,6,8
# tuned-adm profile cpu-partitioning
# tuned-adm active
Current active profile: cpu-partitioning
# reboot

# tuned-adm verify
Verfication succeeded, current system settings match the preset profile.
See tuned log file ('/var/log/tuned/tuned.log') for details.


======================================================
Reproduced in:
    tuned-2.7.1-5.20170314git92d558b8.el7.noarch
    tuned-profiles-cpu-partitioning-2.7.1-5.20170314git92d558b8.el7.noarch
FAIL
======================================================

~~ odd numbers ~~

# tuned-adm profile balanced
# cat /etc/tuned/cpu-partitioning-variables.conf 
isolated_cores=1,3,5,7
# tuned-adm profile cpu-partitioning
# tuned-adm active
Current active profile: cpu-partitioning
# reboot

# tuned-adm verify
Verfication succeeded, current system settings match the preset profile.
See tuned log file ('/var/log/tuned/tuned.log') for details.

~~ even numbers ~~

# tuned-adm profile balanced
# cat /etc/tuned/cpu-partitioning-variables.conf 
isolated_cores=2,4,6,8
# tuned-adm profile cpu-partitioning
Cannot load profile 'cpu-partitioning': Assertion 'isolated_cores contains present CPU(s)' failed.
# tuned-adm active
Current active profile: balanced
# cat /var/log/tuned/tuned.log | grep ERROR
2017-05-04 07:30:23,730 ERROR    tuned.profiles.functions.function_assertion: assertion 'isolated_cores contains present CPU(s)' failed: '2,4,6,8' != '8,2,4,6'

Comment 16 Tereza Cerna 2017-05-04 14:03:57 UTC
Mentioned reproducer in comment #15 is reproducer for bug 1432240.

Comment 17 Tereza Cerna 2017-05-04 14:30:28 UTC
When profile with invalid isolated cores is loaded, previously used profile is applied and warning message is printed to tuned.log file.

======================================================
Verified in:
	tuned-2.8.0-2.el7.noarch
	tuned-profiles-cpu-partitioning-2.8.0-2.el7.noarch
PASS
======================================================

>> Apply profile with valid isolated cores

# cat /etc/tuned/cpu-partitioning-variables.conf
isolated_cores=2,3,11
# tuned-adm profile cpu-partitioning

>> Apply profile with invalid isolated cores

# cat /etc/tuned/cpu-partitioning-variables.conf
isolated_cores=2,3,11,35
# tuned-adm profile cpu-partitioning
Cannot load profile 'cpu-partitioning': Assertion 'isolated_cores contains present CPU(s)' failed.

# cat /var/log/tuned/tuned.log
...
2017-05-04 10:20:17,738 INFO     tuned.profiles.loader: loading profile: cpu-partitioning
2017-05-04 10:20:17,746 ERROR    tuned.profiles.functions.function_assertion: assertion 'isolated_cores contains present CPU(s)' failed: '2,3,11,35' != '2,3,11'
2017-05-04 10:20:17,746 ERROR    tuned.daemon.controller: Failed to reapply profile 'cpu-partitioning'. Did it change on disk and break?
2017-05-04 10:20:17,746 WARNING  tuned.daemon.controller: Applying previously applied (possibly out-dated) profile 'cpu-partitioning'.
2017-05-04 10:20:17,746 INFO     tuned.daemon.daemon: starting tuning
...

>> Warning message "Applying previously applied (possibly out-dated) profile 'cpu-partitioning'." were applied.

======================================================
Reproduced in:
    tuned-2.7.1-5.20170314git92d558b8.el7.noarch
    tuned-profiles-cpu-partitioning-2.7.1-5.20170314git92d558b8.el7.noarch
FAIL
======================================================

# cat /etc/tuned/cpu-partitioning-variables.conf
isolated_cores=2,3,11

# tuned-adm profile cpu-partitioning
Cannot load profile 'cpu-partitioning': Assertion 'isolated_cores contains present CPU(s)' failed.

# cat /var/log/tuned/tuned.log
...
2017-05-04 10:05:18,877 INFO     tuned.profiles.loader: loading profile: cpu-partitioning
2017-05-04 10:05:18,882 ERROR    tuned.profiles.functions.function_assertion: assertion 'isolated_cores contains present CPU(s)' failed: '2,3,11' != '3,2,11'
2017-05-04 10:05:18,882 INFO     tuned.daemon.daemon: starting tuning
...

Comment 18 errata-xmlrpc 2017-08-01 12:35:21 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://access.redhat.com/errata/RHBA-2017:2102