Bug 1265547

Summary: [vdsm] logrotate for /var/log/core again not working
Product: [oVirt] vdsm Reporter: Jiri Belka <jbelka>
Component: GeneralAssignee: Yaniv Bronhaim <ybronhei>
Status: CLOSED CURRENTRELEASE QA Contact: Jiri Belka <jbelka>
Severity: high Docs Contact:
Priority: unspecified    
Version: ---CC: bazulay, bugs, danken, ecohen, gklein, jbelka, knarra, lsurette, mgoldboi, obockows, oourfali, rbalakri, sbonazzo, ybronhei, ycui, yeylon
Target Milestone: ovirt-3.6.1Keywords: Regression
Target Release: 4.17.11Flags: rule-engine: ovirt-3.6.z+
rule-engine: blocker+
mgoldboi: planning_ack+
oourfali: devel_ack+
pstehlik: testing_ack+
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: infra
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-01-13 14:38:14 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Infra RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1305135    

Description Jiri Belka 2015-09-23 08:24:39 UTC
Description of problem:
logrotate for /var/log/core again not working.

explanation: /var/log/core contant is DAC 600. logrotate script is run as vdsm:kvm, vdsm has additional group 'qemu' so it can enter the path but the script got egid only in this context and thus cannot read files as group permission are missing.

# logrotate -v -f /etc/vdsm/logrotate/vdsm 2>&1 | sed -n '/^rotating pattern: \/var\/log\/core/,$p'
rotating pattern: /var/log/core/*.dump  forced from command line (1 rotations)
empty log files are rotated, old logs are removed
switching euid to 36 and egid to 36
considering log /var/log/core/core.24839.1442294276.dump
  log needs rotating
considering log /var/log/core/core.60957.1442272065.dump
  log needs rotating
rotating log /var/log/core/core.24839.1442294276.dump, log->rotateCount is 1
dateext suffix '-20150923'
glob pattern '-[0-9][0-9][0-9][0-9][0-9][0-9][0-9][0-9]'
renaming /var/log/core/core.24839.1442294276.dump.1.xz to /var/log/core/core.24839.1442294276.dump.2.xz (rotatecount 1, logstart 1, i 1), 
old log /var/log/core/core.24839.1442294276.dump.1.xz does not exist
renaming /var/log/core/core.24839.1442294276.dump.0.xz to /var/log/core/core.24839.1442294276.dump.1.xz (rotatecount 1, logstart 1, i 0), 
old log /var/log/core/core.24839.1442294276.dump.0.xz does not exist
log /var/log/core/core.24839.1442294276.dump.2.xz doesn't exist -- won't try to dispose of it
renaming /var/log/core/core.24839.1442294276.dump to /var/log/core/core.24839.1442294276.dump.1
error: failed to rename /var/log/core/core.24839.1442294276.dump to /var/log/core/core.24839.1442294276.dump.1: Operation not permitted
rotating log /var/log/core/core.60957.1442272065.dump, log->rotateCount is 1
dateext suffix '-20150923'
glob pattern '-[0-9][0-9][0-9][0-9][0-9][0-9][0-9][0-9]'
renaming /var/log/core/core.60957.1442272065.dump.1.xz to /var/log/core/core.60957.1442272065.dump.2.xz (rotatecount 1, logstart 1, i 1), 
old log /var/log/core/core.60957.1442272065.dump.1.xz does not exist
renaming /var/log/core/core.60957.1442272065.dump.0.xz to /var/log/core/core.60957.1442272065.dump.1.xz (rotatecount 1, logstart 1, i 0), 
old log /var/log/core/core.60957.1442272065.dump.0.xz does not exist
log /var/log/core/core.60957.1442272065.dump.2.xz doesn't exist -- won't try to dispose of it
renaming /var/log/core/core.60957.1442272065.dump to /var/log/core/core.60957.1442272065.dump.1
error: failed to rename /var/log/core/core.60957.1442272065.dump to /var/log/core/core.60957.1442272065.dump.1: Operation not permitted
switching euid to 0 and egid to 0

# mail
Message 45:
From root.eng.bos.example.com  Wed Sep 16 14:01:01 2015
Return-Path: <root.eng.bos.example.com>
X-Original-To: root
Delivered-To: root.eng.bos.example.com
From: "(Cron Daemon)" <root.eng.bos.example.com>
To: root.eng.bos.example.com
Subject: Cron <root@ibm-p8-rhevm-04> run-parts /etc/cron.hourly
Content-Type: text/plain; charset=UTF-8
Auto-Submitted: auto-generated
Precedence: bulk
X-Cron-Env: <XDG_SESSION_ID=19041>
X-Cron-Env: <XDG_RUNTIME_DIR=/run/user/0>
X-Cron-Env: <LANG=en_US.UTF-8>
X-Cron-Env: <SHELL=/bin/bash>
X-Cron-Env: <PATH=/sbin:/bin:/usr/sbin:/usr/bin>
X-Cron-Env: <MAILTO=root>
X-Cron-Env: <HOME=/root>
X-Cron-Env: <LOGNAME=root>
X-Cron-Env: <USER=root>
Date: Wed, 16 Sep 2015 14:01:01 -0500 (CDT)
Status: RO

/etc/cron.hourly/vdsm-logrotate:

error: failed to rename /var/log/core/core.24839.1442294276.dump to /var/log/core/core.24839.1442294276.dump.1: Operation not permitted
error: failed to rename /var/log/core/core.60957.1442272065.dump to /var/log/core/core.60957.1442272065.dump.1: Operation not permitted

# ls -ld /var/log/core
drwxrwxrwt 2 qemu qemu 83 Sep 23 03:09 /var/log/core
[root@ibm-p8-rhevm-04 ~]# getenforce 
Disabled
[root@ibm-p8-rhevm-04 ~]# ls -l /var/log/core/
total 2186272
-rw------- 1 qemu qemu 1209073664 Sep 15 00:17 core.24839.1442294276.dump
-rw------- 1 qemu qemu 1209073664 Sep 14 18:07 core.60957.1442272065.dump

# su -s /bin/bash - vdsm
Last login: Wed Sep 23 03:10:29 CDT 2015 on pts/1
-bash-4.2$ id
uid=36(vdsm) gid=36(kvm) groups=36(kvm),107(qemu),179(sanlock)
-bash-4.2$ cd /var/log/core
-bash-4.2$ touch vdsmtest
-bash-4.2$ mv core.24839.1442294276.dump core.24839.1442294276.dump.1
mv: cannot move 'core.24839.1442294276.dump' to 'core.24839.1442294276.dump.1': Operation not permitted

Version-Release number of selected component (if applicable):
vdsm-4.17.7-1.el7ev.noarch

How reproducible:
100%

Steps to Reproduce:
1. logrotate -v -f /etc/vdsm/logrotate/vdsm 2>&1 | sed -n '/^rotating pattern: \/var\/log\/core/,$p'
2. (yum -y install mailx ; mail)
3.

Actual results:
huge files are not rotated and could fill filesystem (and as linux people are usually ignoring good partitioning it would fill root fs)

Expected results:
logrotate should work

Additional info:
issue found on ppc64le but same exists on x86 platform as well

Comment 1 Red Hat Bugzilla Rules Engine 2015-10-14 06:34:03 UTC
This bug report has Keywords: Regression or TestBlocker.
Since no regressions or test blockers are allowed between releases, it is also being identified as a blocker for this release. Please resolve ASAP.

Comment 2 Yaniv Bronhaim 2015-10-14 11:09:35 UTC
I tried that and it worked fine: please see below and tell me what I miss..

[root@vm-17-62 core]# kill -6 5185
[root@vm-17-62 core]# ls
core.5185.1444820851.dump
[root@vm-17-62 core]# 
[root@vm-17-62 core]# 
[root@vm-17-62 core]# logrotate -v -f /etc/vdsm/logrotate/vdsm 2>&1 | sed -n '/^rotating pattern: \/var\/log\/core/,$p'
rotating pattern: /var/log/core/*.dump  forced from command line (1 rotations)
empty log files are rotated, old logs are removed
switching euid to 36 and egid to 36
considering log /var/log/core/core.5185.1444820851.dump
  log needs rotating
rotating log /var/log/core/core.5185.1444820851.dump, log->rotateCount is 1
dateext suffix '-20151014'
glob pattern '-[0-9][0-9][0-9][0-9][0-9][0-9][0-9][0-9]'
renaming /var/log/core/core.5185.1444820851.dump.1.xz to /var/log/core/core.5185.1444820851.dump.2.xz (rotatecount 1, logstart 1, i 1), 
old log /var/log/core/core.5185.1444820851.dump.1.xz does not exist
renaming /var/log/core/core.5185.1444820851.dump.0.xz to /var/log/core/core.5185.1444820851.dump.1.xz (rotatecount 1, logstart 1, i 0), 
old log /var/log/core/core.5185.1444820851.dump.0.xz does not exist
log /var/log/core/core.5185.1444820851.dump.2.xz doesn't exist -- won't try to dispose of it
fscreate context set to system_u:object_r:virt_cache_t:s0
renaming /var/log/core/core.5185.1444820851.dump to /var/log/core/core.5185.1444820851.dump.1
compressing log with: /usr/bin/xz
switching uid to 36 and gid to 36
switching euid to 0 and egid to 0
set default create context
[root@vm-17-62 core]# geten
getenforce  getent      
[root@vm-17-62 core]# geten
getenforce  getent      
[root@vm-17-62 core]# getenforce 
Enforcing
[root@vm-17-62 core]#

Comment 3 Red Hat Bugzilla Rules Engine 2015-10-14 11:09:37 UTC
This bug report has Keywords: Regression or TestBlocker.
Since no regressions or test blockers are allowed between releases, it is also being identified as a blocker for this release. Please resolve ASAP.

Comment 4 Jiri Belka 2015-10-23 15:58:49 UTC
(In reply to Yaniv Bronhaim from comment #2)
> I tried that and it worked fine: please see below and tell me what I miss..
> 
> [root@vm-17-62 core]# kill -6 5185
> [root@vm-17-62 core]# ls
> core.5185.1444820851.dump

this info is not complete, what about `ls -l' on this file? who's owner, what group is set?

> [root@vm-17-62 core]# 
> [root@vm-17-62 core]# 
> [root@vm-17-62 core]# logrotate -v -f /etc/vdsm/logrotate/vdsm 2>&1 | sed -n
> '/^rotating pattern: \/var\/log\/core/,$p'
> rotating pattern: /var/log/core/*.dump  forced from command line (1
> rotations)
> empty log files are rotated, old logs are removed
> switching euid to 36 and egid to 36
> considering log /var/log/core/core.5185.1444820851.dump
>   log needs rotating
> rotating log /var/log/core/core.5185.1444820851.dump, log->rotateCount is 1
> dateext suffix '-20151014'
> glob pattern '-[0-9][0-9][0-9][0-9][0-9][0-9][0-9][0-9]'
> renaming /var/log/core/core.5185.1444820851.dump.1.xz to
> /var/log/core/core.5185.1444820851.dump.2.xz (rotatecount 1, logstart 1, i
> 1), 
> old log /var/log/core/core.5185.1444820851.dump.1.xz does not exist
> renaming /var/log/core/core.5185.1444820851.dump.0.xz to
> /var/log/core/core.5185.1444820851.dump.1.xz (rotatecount 1, logstart 1, i
> 0), 
> old log /var/log/core/core.5185.1444820851.dump.0.xz does not exist
> log /var/log/core/core.5185.1444820851.dump.2.xz doesn't exist -- won't try
> to dispose of it
> fscreate context set to system_u:object_r:virt_cache_t:s0
> renaming /var/log/core/core.5185.1444820851.dump to
> /var/log/core/core.5185.1444820851.dump.1
> compressing log with: /usr/bin/xz
> switching uid to 36 and gid to 36
> switching euid to 0 and egid to 0
> set default create context

no info about OS at all. fully reproducible on:

[root@dell-r210ii-04 core]# rpm -qa kernel systemd redhat-release-server selinux-policy-targeted
selinux-policy-targeted-3.13.1-60.el7.noarch
redhat-release-server-7.2-7.el7.x86_64
systemd-219-19.el7.x86_64
kernel-3.10.0-324.el7.x86_64
[root@dell-r210ii-04 core]# cat /etc/redhat-release 
Red Hat Enterprise Linux Server release 7.2 Beta (Maipo)
[root@dell-r210ii-04 core]# rpm -qa kernel systemd redhat-release-server selinux-policy-targeted
selinux-policy-targeted-3.13.1-60.el7.noarch
redhat-release-server-7.2-7.el7.x86_64
systemd-219-19.el7.x86_64
kernel-3.10.0-324.el7.x86_64

installed from:

http://download.englab.brq.redhat.com/pub/rhel/rel-eng/RHEL-7.2-20151015.0/compose/Server/x86_64/os/

[root@dell-r210ii-04 core]# ls -l
total 52960
-rw-------. 1 qemu qemu 1269874688 Oct 23 17:39 core.15104.1445614743.dump

[root@dell-r210ii-04 core]# logrotate -v -f /etc/vdsm/logrotate/vdsm 2>&1 | sed -n '/^rotating pattern: \/var\/log\/core/,$p'
rotating pattern: /var/log/core/*.dump  forced from command line (1 rotations)
empty log files are rotated, old logs are removed
switching euid to 36 and egid to 36
considering log /var/log/core/core.15104.1445614743.dump
  log needs rotating
rotating log /var/log/core/core.15104.1445614743.dump, log->rotateCount is 1
dateext suffix '-20151023'
glob pattern '-[0-9][0-9][0-9][0-9][0-9][0-9][0-9][0-9]'
renaming /var/log/core/core.15104.1445614743.dump.1.xz to /var/log/core/core.15104.1445614743.dump.2.xz (rotatecount 1, logstart 1, i 1), 
old log /var/log/core/core.15104.1445614743.dump.1.xz does not exist
renaming /var/log/core/core.15104.1445614743.dump.0.xz to /var/log/core/core.15104.1445614743.dump.1.xz (rotatecount 1, logstart 1, i 0), 
old log /var/log/core/core.15104.1445614743.dump.0.xz does not exist
log /var/log/core/core.15104.1445614743.dump.2.xz doesn't exist -- won't try to dispose of it
error: error opening /var/log/core/core.15104.1445614743.dump: Permission denied
switching euid to 0 and egid to 0
set default create context

Comment 5 Yaniv Bronhaim 2015-10-25 12:14:09 UTC
Of course it doesn't work.. this is qemu core dump. vdsm configuration rotates the file as vdsm user - therefore it can rotate only vdsm core dump files which are created by vdsm user - 

do you except vdsm configuration to rotate any core file in this directory? If yes we need to remove the "su vdsm kvm" in /etc/vdsm/logrotate/vdsm.

Dan, this was added quite long ago - http://gerrit.ovirt.org/971
we configure to throw all coredumps to /var/log/core , also libvirt's which are created by root .. What do you say? su root root?

Comment 6 Jiri Belka 2015-10-26 08:48:26 UTC
I'm curious, what is then that core file in /var/log/core ? :) I just send ABRT signal to qemu-kvm.

Comment 7 Dan Kenigsberg 2015-10-28 09:55:58 UTC
Yaniv, I'm afraid that I don't recall the motivation for adding "su" to logrotate. Until we integrate properly with ABRT, and as long we mess with /var/log/core, we should be able to log-rotate everything that is put there.

Comment 8 Yaniv Bronhaim 2015-10-29 09:24:41 UTC
so be it - I can't just remove the su to rotate files. it will give us: error: skipping "/var/log/core/core.5626.1445764996.dump" because parent directory has insecure permissions (It's world writable or writable by group which is not "root") Set "su" directive in config file to tell logrotate which user/group should be used for rotation.

Therefore, we will need "su root root" there ..

Comment 9 Yaniv Bronhaim 2015-11-04 10:18:40 UTC
*** Bug 1221464 has been marked as a duplicate of this bug. ***

Comment 10 Jiri Belka 2016-01-13 12:19:18 UTC
ok, vdsm-4.17.15-0.el7ev.noarch

# grep su /etc/vdsm/logrotate/vdsm ; rpm -qf /etc/vdsm/logrotate/vdsm
    su root root
vdsm-4.17.15-0.el7ev.noarch

# ls -l /var/log/core/core.16118.1452686885.dump                                                                                                                                             
-rw-------. 1 qemu qemu 1839423488 Jan 13 13:08 /var/log/core/core.16118.1452686885.dump

# logrotate -v -f /etc/vdsm/logrotate/vdsm 2>&1 | sed -n '/^rotating pattern: \/var\/log\/core/,$p'                                                                                          
rotating pattern: /var/log/core/*.dump  forced from command line (1 rotations)
empty log files are rotated, old logs are removed
considering log /var/log/core/core.16118.1452686885.dump
  log needs rotating
rotating log /var/log/core/core.16118.1452686885.dump, log->rotateCount is 1
dateext suffix '-20160113'
glob pattern '-[0-9][0-9][0-9][0-9][0-9][0-9][0-9][0-9]'
renaming /var/log/core/core.16118.1452686885.dump.1.xz to /var/log/core/core.16118.1452686885.dump.2.xz (rotatecount 1, logstart 1, i 1), 
old log /var/log/core/core.16118.1452686885.dump.1.xz does not exist
renaming /var/log/core/core.16118.1452686885.dump.0.xz to /var/log/core/core.16118.1452686885.dump.1.xz (rotatecount 1, logstart 1, i 0), 
old log /var/log/core/core.16118.1452686885.dump.0.xz does not exist
log /var/log/core/core.16118.1452686885.dump.2.xz doesn't exist -- won't try to dispose of it
fscreate context set to system_u:object_r:virt_cache_t:s0
renaming /var/log/core/core.16118.1452686885.dump to /var/log/core/core.16118.1452686885.dump.1
compressing log with: /usr/bin/xz
set default create context
[root@dell-r210ii-13 ~]# ls -l /var/log/core/
total 150896
-rw-------. 1 qemu qemu 154513628 Jan 13 13:08 core.16118.1452686885.dump.1.xz

Comment 11 Sandro Bonazzola 2016-01-13 14:38:14 UTC
oVirt 3.6.1 has been released, closing current release

Comment 12 Douglas Schilling Landgraf 2016-04-11 19:37:01 UTC
*** Bug 1311053 has been marked as a duplicate of this bug. ***