Bug 1009379

Are you getting AVC msgs?

# ausearch -m avc

No.

I do have some denials related to Munin, but no messages from awstats or cron.

so ... what leads you into believing SELinux is the culprit here? does it work for you with selinux off?

btw, I've filed bug #1011599 for the logging issue

(In reply to Karel Volný from comment #3)
> so ... what leads you into believing SELinux is the culprit here? does it
> work for you with selinux off?

Good question. It was a "theory" based on observing different results between "running manually" and "running as cronjob", remembering vaguely from the past that such behaviour was often caused by SElinux (different context for interactive session compared to cron deamon's context).

Plus message "Error: AWStats database directory defined in config file by 'DirData' parameter (/var/lib/awstats) does not exist or is not writable." also gave a clue as, when manually investigating:

a) directory clearly exists

b) is writable by root

c) hourly cron job is running (as far as I know) as root


To verify, I've disabled SElinux for one hour using `setenforce permissive`.

awstats is supposed to update stat data in /var/lib/awstats . Before, the data was not updated by cron job. With SElinux set to permissive mode, awstats update was successful and file in awstats got updated. With SElinux in full force again (`setenforce enforcing`), updates stopped working.

> btw, I've filed bug #1011599 for the logging issue

Thank you.

thanks for testing

I did a different test and I have found that adding "touch /var/lib/awstats/test" into the cron script works - touch is able to create the file from the cronjob while awstats.pl is denied

btw, note that there are also some PAM issues with cronie, see bug #995590

if this is a selinux problem, it seems that some dontaudit rule hides it (have I already said that dontaudit is evil, evil, evil?)

according to http://danwalsh.livejournal.com/11673.html one possibility to disable dontaudit rules is to run

# semodule -DB

so ... after doing that, the denial should be visible in logs and so we can see what exactly goes wrong

(In reply to Karel Volný from comment #5)
> thanks for testing
> 
> I did a different test and I have found that adding "touch
> /var/lib/awstats/test" into the cron script works - touch is able to create
> the file from the cronjob while awstats.pl is denied
> 
> btw, note that there are also some PAM issues with cronie, see bug #995590

I have cronie-1.4.10-5.fc19.x86_64 installed. I leave this at that for now ... see below.

> if this is a selinux problem, it seems that some dontaudit rule hides it
> (have I already said that dontaudit is evil, evil, evil?)

(+1) :)

> according to http://danwalsh.livejournal.com/11673.html one possibility to
> disable dontaudit rules is to run
> 
> # semodule -DB
> 
> so ... after doing that, the denial should be visible in logs and so we can
> see what exactly goes wrong

OK, I disabled dontaudit and here's what I got from one (still unsuccessful) run of awstats job:

type=SYSCALL msg=audit(1380117661.374:55768): arch=c000003e syscall=2 success=no exit=-13 a0=368e97c4af a1=80000 a2=1b6 a3=0 items=0 ppid=6846 pid=6848 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=2327 tty=(none) comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
...

(see attached file for the whole output)

Created attachment 802876 [details]
whole set of denial messagws from one unsucesfull awststs cron job with dontaudit disabled

ok, this is from my audit.log:

time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.242:188): arch=c000003e syscall=2 success=no exit=-13 a0=7f609f9754af a1=80000 a2=1b6 a3=7fffa31400a0 items=0 ppid=1266 pid=1267 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.242:188): avc:  denied  { read } for  pid=1267 comm="sh" name="meminfo" dev="proc" ino=4026532027 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:proc_t:s0 tclass=file
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.242:189): arch=c000003e syscall=4 success=no exit=-13 a0=261b040 a1=7fffa31400f0 a2=7fffa31400f0 a3=7fffa313fea0 items=0 ppid=1266 pid=1267 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.242:189): avc:  denied  { getattr } for  pid=1267 comm="sh" path="/root" dev="sda3" ino=265 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:admin_home_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.242:190): arch=c000003e syscall=4 success=no exit=-13 a0=4a7ef7 a1=7fffa3140190 a2=7fffa3140190 a3=7fffa313ff00 items=0 ppid=1266 pid=1267 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.242:190): avc:  denied  { search } for  pid=1267 comm="sh" name="root" dev="sda3" ino=265 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:admin_home_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.270:191): arch=c000003e syscall=4 success=no exit=-13 a0=151da20 a1=7fff059211a0 a2=7fff059211a0 a3=0 items=0 ppid=1267 pid=1268 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="awstats.pl" exe="/usr/bin/perl" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.270:191): avc:  denied  { search } for  pid=1268 comm="awstats.pl" name="root" dev="sda3" ino=265 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:admin_home_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.270:192): arch=c000003e syscall=4 success=no exit=-13 a0=1497a40 a1=7fff059210f0 a2=7fff059210f0 a3=0 items=0 ppid=1267 pid=1268 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="awstats.pl" exe="/usr/bin/perl" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.270:192): avc:  denied  { search } for  pid=1268 comm="awstats.pl" name="root" dev="sda3" ino=265 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:admin_home_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.390:193): arch=c000003e syscall=4 success=no exit=-13 a0=14492f0 a1=12c6138 a2=12c6138 a3=0 items=0 ppid=1267 pid=1268 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="awstats.pl" exe="/usr/bin/perl" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.390:193): avc:  denied  { search } for  pid=1268 comm="awstats.pl" name="lib" dev="sda3" ino=269 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:var_lib_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.394:194): arch=c000003e syscall=2 success=no exit=-13 a0=7f69adc914af a1=80000 a2=1b6 a3=7fffad73a3f0 items=0 ppid=1266 pid=1269 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.394:194): avc:  denied  { read } for  pid=1269 comm="sh" name="meminfo" dev="proc" ino=4026532027 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:proc_t:s0 tclass=file
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.395:195): arch=c000003e syscall=4 success=no exit=-13 a0=7f2040 a1=7fffad73a440 a2=7fffad73a440 a3=7fffad73a1f0 items=0 ppid=1266 pid=1269 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.395:195): avc:  denied  { getattr } for  pid=1269 comm="sh" path="/root" dev="sda3" ino=265 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:admin_home_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.395:196): arch=c000003e syscall=4 success=no exit=-13 a0=4a7ef7 a1=7fffad73a4e0 a2=7fffad73a4e0 a3=7fffad73a250 items=0 ppid=1266 pid=1269 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.395:196): avc:  denied  { search } for  pid=1269 comm="sh" name="root" dev="sda3" ino=265 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:admin_home_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.422:197): arch=c000003e syscall=4 success=no exit=-13 a0=1d8baf0 a1=7fffd6e1c060 a2=7fffd6e1c060 a3=0 items=0 ppid=1269 pid=1270 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="awstats.pl" exe="/usr/bin/perl" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.422:197): avc:  denied  { search } for  pid=1270 comm="awstats.pl" name="root" dev="sda3" ino=265 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:admin_home_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.422:198): arch=c000003e syscall=4 success=no exit=-13 a0=1d05be0 a1=7fffd6e1bfb0 a2=7fffd6e1bfb0 a3=0 items=0 ppid=1269 pid=1270 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="awstats.pl" exe="/usr/bin/perl" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.422:198): avc:  denied  { search } for  pid=1270 comm="awstats.pl" name="root" dev="sda3" ino=265 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:admin_home_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.544:199): arch=c000003e syscall=4 success=no exit=-13 a0=1cd7ad0 a1=1b34138 a2=1b34138 a3=0 items=0 ppid=1269 pid=1270 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="awstats.pl" exe="/usr/bin/perl" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.544:199): avc:  denied  { search } for  pid=1270 comm="awstats.pl" name="lib" dev="sda3" ino=269 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:var_lib_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.548:200): arch=c000003e syscall=2 success=no exit=-13 a0=7f0fca2ad4af a1=80000 a2=1b6 a3=7fff777aa0c0 items=0 ppid=1266 pid=1271 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.548:200): avc:  denied  { read } for  pid=1271 comm="sh" name="meminfo" dev="proc" ino=4026532027 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:proc_t:s0 tclass=file
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.548:201): arch=c000003e syscall=4 success=no exit=-13 a0=864040 a1=7fff777aa110 a2=7fff777aa110 a3=7fff777a9ec0 items=0 ppid=1266 pid=1271 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.548:201): avc:  denied  { getattr } for  pid=1271 comm="sh" path="/root" dev="sda3" ino=265 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:admin_home_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.548:202): arch=c000003e syscall=4 success=no exit=-13 a0=4a7ef7 a1=7fff777aa1b0 a2=7fff777aa1b0 a3=7fff777a9f20 items=0 ppid=1266 pid=1271 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="sh" exe="/usr/bin/bash" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.548:202): avc:  denied  { search } for  pid=1271 comm="sh" name="root" dev="sda3" ino=265 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:admin_home_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.576:203): arch=c000003e syscall=4 success=no exit=-13 a0=16c1af0 a1=7fff94f0d4a0 a2=7fff94f0d4a0 a3=0 items=0 ppid=1271 pid=1272 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="awstats.pl" exe="/usr/bin/perl" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.576:203): avc:  denied  { search } for  pid=1272 comm="awstats.pl" name="root" dev="sda3" ino=265 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:admin_home_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.576:204): arch=c000003e syscall=4 success=no exit=-13 a0=163bbe0 a1=7fff94f0d3f0 a2=7fff94f0d3f0 a3=0 items=0 ppid=1271 pid=1272 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="awstats.pl" exe="/usr/bin/perl" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.576:204): avc:  denied  { search } for  pid=1272 comm="awstats.pl" name="root" dev="sda3" ino=265 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:admin_home_t:s0 tclass=dir
----
time->Wed Sep 25 16:01:01 2013
type=SYSCALL msg=audit(1380117661.697:205): arch=c000003e syscall=4 success=no exit=-13 a0=160dad0 a1=146a138 a2=146a138 a3=0 items=0 ppid=1271 pid=1272 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=9 tty=(none) comm="awstats.pl" exe="/usr/bin/perl" subj=system_u:system_r:awstats_t:s0-s0:c0.c1023 key=(null)
type=AVC msg=audit(1380117661.697:205): avc:  denied  { search } for  pid=1272 comm="awstats.pl" name="lib" dev="sda3" ino=269 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:var_lib_t:s0 tclass=dir



... WTH these are hidden rather than resolved? :-(

If you add a local policy from this AVC

type=AVC msg=audit(1380117661.697:205): avc:  denied  { search } for  pid=1272 comm="awstats.pl" name="lib" dev="sda3" ino=269 scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023 tcontext=system_u:object_r:var_lib_t:s0 tclass=dir

does it work?

(In reply to Miroslav Grepl from comment #9)

> If you add a local policy from this AVC
> 
> type=AVC msg=audit(1380117661.697:205): avc:  denied  { search } for 
> pid=1272 comm="awstats.pl" name="lib" dev="sda3" ino=269
> scontext=system_u:system_r:awstats_t:s0-s0:c0.c1023
> tcontext=system_u:object_r:var_lib_t:s0 tclass=dir
> 
> does it work?

I've tried following:

cd /etc/selinux/targeted/modules/active/modules
grep awstat /var/log/audit/audit.log | grep "name..lib" | audit2allow -M awstatsfix
semodule -i awstatsfix.pp

and it failed with:

libsepol.module_package_read_offsets: wrong magic number for module package:  expected 0xf97cff8f, got 0x646f6d0a (No such file or directory).
libsemanage.semanage_load_module: Error while reading from module file /etc/selinux/targeted/modules/tmp/modules/awstatsfix.te. (No such file or directory).
semodule:  Failed!



Additionaly I've tried also:

grep awstat /var/log/audit/audit.log | audit2allow -M awstatsfix
semodule -i awstatsfix.pp

and again failure:

libsepol.module_package_read_offsets: wrong magic number for module package:  expected 0xf97cff8f, got 0x646f6d0a (No such file or directory).
libsemanage.semanage_load_module: Error while reading from module file /etc/selinux/targeted/modules/tmp/modules/awstatsfix.te. (No such file or directory).
semodule:  Failed!


Here my SElinux skills reached its peak so I'm not able to answer your question. :/

The same bug I observe on Fedora 20 fresh installation. 

I have www files in /srv/www directory. Some of them are owned by ordinary user.

Awstats worked fine in Fedora 18 and before. Starting with Fedora 19 awstats statistics is not updated from cron.

Same problem on Fedora 19 server running:


kernel 3.12.6-200.fc19.x86_64
awstats-7.1.1-2.fc19.noarch
selinux-policy-targeted-3.12.1-74.16.fc19.noarch

# sestatus 
SELinux status:                 enabled
SELinuxfs mount:                /sys/fs/selinux
SELinux root directory:         /etc/selinux
Loaded policy name:             targeted
Current mode:                   enforcing
Mode from config file:          enforcing
Policy MLS status:              enabled
Policy deny_unknown status:     allowed
Max kernel policy version:      28


I've tried this and it works:


# semodule -DB
# ausearch -m avc -ts yesterday -te today
(when seeing output about awstats, rebuild the policy)
# semodule -B
# ausearch -m avc -ts yesterday -te today|grep awstats|grep AVC|grep -vE 'admin_home_t|proc_t' > avcawstats.txt
(see avcawstats.txt in attachment)
# cat avcawstats.txt | audit2allow -M awstats-cron-search-lib-fix
# semodule -i awstats-cron-search-lib-fix.pp


Then updates with cron works again
Thanks to you Peter, Miroslav and Karel for the temporary fix

Created attachment 848773 [details]
Output from grep command

Workaround:

a) login as root
b) crontab -e
c) put there following:

@hourly /usr/share/awstats/tools/awstats_updateall.pl now -configdir="/etc/awstats" -awstatsprog="/usr/share/awstats/wwwroot/cgi-bin/awstats.pl" >/dev/null

d) save
e) working as expected

(c) is essentially content of /etc/cron.hourly/awstats with "exec" stripped away.

Still occuring with selinux-policy-3.12.1-74.23.fc19.

Still occuring with selinux-policy-3.12.1-74.26.fc19.

This message is a notice that Fedora 19 is now at end of life. Fedora 
has stopped maintaining and issuing updates for Fedora 19. It is 
Fedora's policy to close all bug reports from releases that are no 
longer maintained. Approximately 4 (four) weeks from now this bug will
be closed as EOL if it remains open with a Fedora 'version' of '19'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 19 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

pls, can anyone retest and update the version eventually?

(I no longer have the original setup which led me to this bz)

F19 is still broken. F20+ is fixed.

Too late to do anything about F19.

(In reply to Michael Cronenworth from comment #19)
> F20+ is fixed.

ok, so closing then, thanks

> Too late to do anything about F19.

not too late to run `fedora-upgrade` ;-)