Bug 912308 - vdsm.log ownership is root:root when log rotate run at the same time as supervdsm writes to the same log file
Summary: vdsm.log ownership is root:root when log rotate run at the same time as super...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: vdsm
Version: 3.2.0
Hardware: x86_64
OS: Linux
high
high
Target Milestone: ---
: 3.2.0
Assignee: Yaniv Bronhaim
QA Contact: Daniel Paikov
URL:
Whiteboard: infra
Depends On:
Blocks: 891843 917401 949686
TreeView+ depends on / blocked
 
Reported: 2013-02-18 11:22 UTC by Eyal Edri
Modified: 2022-07-09 05:56 UTC (History)
18 users (show)

Fixed In Version: vdsm-4.10.2-13.0.el6ev
Doc Type: Bug Fix
Doc Text:
When the vdsm.log file is removed, either manually or by logrotate, the supervdsm user can create the log file and set its ownership to root:root. When this happens, the vdsmd service is stopped until the user resets the vdsm.log ownership to vdsm:kvm, and restarts the service. This update separates supervdsm log to a supervdsm.log file, so after vdsm.log is rotated it remains owned by vdsm:kvm.
Clone Of:
: 949686 (view as bug list)
Environment:
Last Closed: 2013-06-10 20:41:31 UTC
oVirt Team: Infra
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker RHV-47050 0 None None None 2022-07-09 05:56:01 UTC
Red Hat Product Errata RHSA-2013:0886 0 normal SHIPPED_LIVE Moderate: rhev 3.2 - vdsm security and bug fix update 2013-06-11 00:25:02 UTC
oVirt gerrit 12160 0 None None None Never
oVirt gerrit 12940 0 None None None Never

Description Eyal Edri 2013-02-18 11:22:11 UTC
Description of problem:

Seen on various times in multiple hosts, /var/log/vdsm.log ownership is changed to root:root. 

after investigating logs, its seems that log rotate file [1] run at the same time the vdsm.log file changed.

disabling log rotate fixed the problem and file ownership isn't changed anymore.

[1] /etc/cron.hourly/vdsm-logrotate

Version-Release number of selected component (if applicable):


How reproducible:

it's a race, so it doesn't happen all the time.


Steps to Reproduce:
1.install vdsm on a host
2.activate log rotate (or change values to less then 15M)
3.run supervdsm commands 
  
Actual results:
vdsm.log has root:root ownership.

Expected results:
vdsm.log stays with vdsm:kvm ownership


Additional info:

Comment 2 Barak 2013-02-18 12:10:13 UTC
So if I understand correctly every logrotate the vdsm log changes ownership ?

Comment 3 Eyal Edri 2013-02-18 12:15:09 UTC
no it's not.
like i said, it's a race and it will happen only if log rotate runs exactly the same time as supervdsm writes to the log. 

not easy to reproduce, but i can assure that once i disabled log rotate the problems stopped.

Comment 4 Yaniv Bronhaim 2013-02-18 13:47:15 UTC
Added to tracker patch that supposed to create the new file with vdsm as owner. 

Eyal - can you add to /etc/logrotate.d/vdsm in the below scope:

/var/log/vdsm/*.log {                                                                                                                                                        
    rotate 100                                                                                                                                                               
    missingok                                                                                                                                                                
    size 15M                                                                                                                                                                 
    compress                                                                                                                                                                 
    compresscmd /usr/bin/xz                                                                                                                                                  
    uncompresscmd /usr/bin/unxz                                                                                                                                              
    compressext .xz                                                                                                                                                          
    create 644 vdsm kvm     <----   This line.                                                                                                                                              
}          

And continue your usual integration tests. Inform me if this scenario appears again.

Comment 5 Eyal Edri 2013-02-19 13:43:03 UTC
it will be better if you can prepare a patch with the change and we'll build a custom vdsm to deploy on all the hosts with it.

Comment 6 Yaniv Bronhaim 2013-02-19 15:54:07 UTC
I did - please check https://gerrit.eng.lab.tlv.redhat.com/#/c/6519/ - base rhev-3.2

Comment 7 Alon Bar-Lev 2013-02-25 16:09:36 UTC
I don't think that logrotate is a solution for this, as I can expect that after clearing /var/log/ programs will work correctly.

logrotate happens once in a day or so, and is optional component at most distributions.

A better solution is to create the log in proper ownership if running as root.

Comment 9 Dan Kenigsberg 2013-02-27 15:21:47 UTC
(In reply to comment #7)
> I don't think that logrotate is a solution for this, as I can expect that
> after clearing /var/log/ programs will work correctly.
> 
> logrotate happens once in a day or so, and is optional component at most
> distributions.
> 
> A better solution is to create the log in proper ownership if running as
> root.

Indeed, the current solution is raceful - if vdsm.log is removed (by logrotate or otherwise), supervdsm may be the first to create it, as root:root, and silently drop all following vdsm logs.

If we cannot as supervdsm to create the file as vdsm:kvm, we should have it write to a log file of its own.

Comment 10 Yaniv Bronhaim 2013-02-28 16:34:08 UTC
That's right.. 
The first thought was to separate the logs. I agree that we should separate between logs that different level of users write to it. The case of that patch was to solve error\race that logrotate can cause.. deleting the file manually it something else to handle with..

Comment 11 Alon Bar-Lev 2013-02-28 16:53:57 UTC
(In reply to comment #10)
> deleting the file
> manually it something else to handle with..

No it is not, it is the exact issue, log rotate deletes the files, just like manual delete.

Logrotate is support utility which is optional, building a solution around it is not correct.

Comment 12 Haim 2013-03-05 14:34:40 UTC
re-open, happened today on our jenkins machines with vdsm build vdsm-4.10.2-10.0.el6ev.x86_64.

seems like the race still exists, had to change the permission manually.

Comment 13 Rejy M Cyriac 2013-03-07 04:37:54 UTC
Just reporting in, that this bug hit a RHEL 6.4 Hypervisor added to a POSIXfs Data Center, as a single Hypervisor.

Everything was working fine for a day,and then on the second day, I noticed the Hypervisor was in non-responsive state, and the Storage Domain and Data Center was brought down. The Storage Domain and Data Center was brought down probably because the non-responsive Hypervisor was the lone Hypervisor in the Data Center.

Investigation showed that the vdsm log file ownership was wrong, and changing it back resolved the issue.

-----------------------------------------------------------------

# cat /etc/redhat-release 
Red Hat Enterprise Linux Server release 6.4 (Santiago)

# rpm -qa | grep vdsm
vdsm-python-4.10.2-1.6.el6.x86_64
vdsm-cli-4.10.2-1.6.el6.noarch
vdsm-4.10.2-1.6.el6.x86_64
vdsm-xmlrpc-4.10.2-1.6.el6.noarch

# ls -l /var/log/vdsm/vdsm.log*
-rw-r--r--. 1 root root    930 Mar  1 22:01 /var/log/vdsm/vdsm.log
-rw-r--r--. 1 vdsm kvm  681976 Mar  1 22:01 /var/log/vdsm/vdsm.log.1.xz
-rw-r--r--. 1 vdsm kvm  745700 Mar  1 17:01 /var/log/vdsm/vdsm.log.2.xz
-rw-r--r--. 1 vdsm kvm  746640 Mar  1 10:01 /var/log/vdsm/vdsm.log.3.xz
-rw-r--r--. 1 vdsm kvm  753100 Mar  1 03:01 /var/log/vdsm/vdsm.log.4.xz
-rw-r--r--. 1 vdsm kvm  743516 Feb 28 20:01 /var/log/vdsm/vdsm.log.5.xz

-----------------------------------------------------------------
-
rejy (rmc)

Comment 14 Barak 2013-03-07 13:44:12 UTC
Saggi, Yaniv,

What logger configuration does the superVdsm uses ?

Can we control the file ownership through the logger configuration ?

If this is not the case than I don't see any other solution than separating the log files.

Comment 15 Yaniv Bronhaim 2013-03-10 10:37:46 UTC
As mentioned since comment 9, the case that causes this is that the log file was deleted manually, and the root process continues the writing before vdsm while both still running and using the already opened logger. The logger doesn't check anything before writing to the file, it creates the file with the user that writes and continue. In that case, if we want to handle manual deletion, the only solution I see is to have 2 logs.

Saggi, do you have another point of view to raise?

Comment 17 Cheryn Tan 2013-04-03 07:02:00 UTC
This bug is currently attached to errata RHBA-2012:14332. If this change is not to be documented in the text for this errata please either remove it from the errata, set the requires_doc_text flag to minus (-), or leave a "Doc Text" value of "--no tech note required" if you do not have permission to alter the flag.

Otherwise to aid in the development of relevant and accurate release documentation, please fill out the "Doc Text" field above with these four (4) pieces of information:

* Cause: What actions or circumstances cause this bug to present.

* Consequence: What happens when the bug presents.

* Fix: What was done to fix the bug.

* Result: What now happens when the actions or circumstances above occur. (NB: this is not the same as 'the bug doesn't present anymore')

Once filled out, please set the "Doc Type" field to the appropriate value for the type of change made and submit your edits to the bug.

For further details on the Cause, Consequence, Fix, Result format please refer to:

https://bugzilla.redhat.com/page.cgi?id=fields.html#cf_release_notes

Thanks in advance.

Comment 18 Oded Ramraz 2013-04-08 08:48:52 UTC
setting 3.1.z stream flag according to comment 16

Comment 19 Simon Grinberg 2013-04-08 16:53:59 UTC
(In reply to comment #18)
> setting 3.1.z stream flag according to comment 16

Oded, what is the impact on the end user?

Comment 20 Oded Ramraz 2013-04-08 16:57:16 UTC
(In reply to comment #19)
> (In reply to comment #18)
> > setting 3.1.z stream flag according to comment 16
> 
> Oded, what is the impact on the end user?

When it happen , the vdsmd service is down until the user chown vdsm:kvm vdsm.log and start the service again .

Comment 23 Daniel Paikov 2013-04-22 10:33:56 UTC
Couldn't reprocude, closing as VERIFIED as of vdsm-4.10.2-1.10.

Comment 25 errata-xmlrpc 2013-06-10 20:41:31 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.

http://rhn.redhat.com/errata/RHSA-2013-0886.html


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