On Tue, 2006-06-06 at 15:47 +0100, Paul Howarth wrote:
Marc Schwartz wrote:
>>>>> type=AVC msg=audit(1149203919.092:6): avc: denied { getattr } for
pid=2051 comm="sh" name="mailq.postfix.1.gz" dev=hdc7 ino=3132510
scontext=system_u:system_r:postfix_master_t:s0 tcontext=system_u:object_r:man_t:s0
tclass=file
>>>>> type=AVC_PATH msg=audit(1149203919.092:6):
path="/usr/share/man/man1/mailq.postfix.1.gz"
>>>>> type=CWD msg=audit(1149203919.092:6):
cwd="/var/spool/postfix"
>>>>> type=PATH msg=audit(1149203919.092:6): item=0
name="/usr/share/man/man1/mailq.postfix.1.gz" flags=1 inode=3132510 dev=16:07
mode=0100644 ouid=0 ogid=0 rdev=00:00
>>>> What does the postfix master program do? It appears to be having trouble
>>>> here reading the attributes of a manpage?!?!?
>>> I am truly confuzzled by this one. I have no idea why this occurred.
>
>> We'll not fix this one then, and wait to see if it happens again.
>
> OK. Note that it is still happening and is below in the updated output.
OK, can you see if you can figure out when it's happening, e.g. once per
email, just at server startup, when the mail queue is pushed etc.?
I'll take a look to see if it appears more than once. From the
experience yesterday, it is early on in the new log file, which I had
fully cleared and then re-booted. This would suggest a boot time event.
Indeed, as I check it now, it is there twice. Once from yesterday and
once, presumably from today, when I moved from home to office and
shutdown and then re-booted.
I don't suppose that any of the numbers in the parens in the avc msg
headers are date/time stamps by chance? If so, then I can definitively
correlate them to events.
>>> type=AVC msg=audit(1149352202.368:284): avc: denied {
read } for pid=8283 comm="clamassassin" name="meminfo" dev=proc
ino=-268435454 scontext=system_u:system_r:clamscan_t:s0
tcontext=system_u:object_r:proc_t:s0 tclass=file
>>> type=SYSCALL msg=audit(1149352202.368:284): arch=40000003 syscall=5
success=yes exit=3 a0=489093ef a1=0 a2=1b6 a3=9ced240 items=1 pid=8283 auid=4294967295
uid=500 gid=500 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500
comm="clamassassin" exe="/bin/bash"
>>> type=CWD msg=audit(1149352202.368:284): cwd="/home/marcs"
>>> type=PATH msg=audit(1149352202.368:284): item=0
name="/proc/meminfo" flags=101 inode=4026531842 dev=00:03 mode=0100444 ouid=0
ogid=0 rdev=00:00
>>> type=AVC msg=audit(1149352202.476:287): avc: denied { getattr } for
pid=8283 comm="clamassassin" name="meminfo" dev=proc ino=-268435454
scontext=system_u:system_r:clamscan_t:s0 tcontext=system_u:object_r:proc_t:s0 tclass=file
>>> type=SYSCALL msg=audit(1149352202.476:287): arch=40000003 syscall=197
success=yes exit=0 a0=3 a1=bfc0bae8 a2=4891eff4 a3=3 items=0 pid=8283 auid=4294967295
uid=500 gid=500 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500
comm="clamassassin" exe="/bin/bash"
>>> type=AVC_PATH msg=audit(1149352202.476:287):
path="/proc/meminfo"
>> clamassassin trying to read /proc/meminfo
>>
>> Any idea why?
>
> Not at all. A search of the script does not show any calls to read
> there, so perhaps it is clamscan, unless the audit trail would
> differentiate it...
It might be generic startup code for the script interpreter, which may
or may not be necessary. I found this in the lpd policy:
# bash wants access to /proc/meminfo
kernel_read_system_state(lpd_t)
On the other hand, in the yam policy we have:
# Python works fine without reading /proc/meminfo
kernel_dontaudit_read_system_state(yam_t)
Given this precedent, I'm inclined to dontaudit it if it still turns up
after the context change for clamassassin, and change it to allow if it
breaks when you eventually switch to enforcing mode.
From what I can see in the log, the /proc/meminfo related messages are
gone.
(snip)
>>> type=AVC msg=audit(1149352204.996:294): avc: denied { search } for
pid=8297 comm="pyzor" name="bin" dev=hdc7 ino=3112970
scontext=system_u:system_r:pyzor_t:s0 tcontext=system_u:object_r:bin_t:s0 tclass=dir
>>> type=SYSCALL msg=audit(1149352204.996:294): arch=40000003 syscall=5
success=yes exit=3 a0=bfed8edb a1=8000 a2=1b6 a3=9970008 items=1 pid=8297 auid=4294967295
uid=500 gid=0 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500
comm="pyzor" exe="/usr/bin/python"
>>> type=CWD msg=audit(1149352204.996:294): cwd="/"
>>> type=PATH msg=audit(1149352204.996:294): item=0
name="/usr/bin/pyzor" flags=101 inode=3140757 dev=16:07 mode=0100755 ouid=0
ogid=0 rdev=00:00
>> Pyzor trying to find something to run?
>
> Unsure. I don't know python and reviewing the code, there are calls
> below the script level that may be doing things that I would be hesitant
> to say that I fully comprehend. There may be a need to contact the
> author or the FE package maintainer on this one, unless you know python.
No python here unfortunately.
Does it make sense to communicate with the FE package maintainer on this
at all?
<snip>
>>> type=AVC msg=audit(1149352205.020:299): avc: denied {
getattr } for pid=8297 comm="pyzor" name="time" dev=hdc7 ino=3132233
scontext=system_u:system_r:pyzor_t:s0 tcontext=system_u:object_r:bin_t:s0 tclass=file
>>> type=SYSCALL msg=audit(1149352205.020:299): arch=40000003 syscall=195
success=yes exit=0 a0=bfed3bb7 a1=bfed3704 a2=4891eff4 a3=b7f439c0 items=1 pid=8297
auid=4294967295 uid=500 gid=0 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500
comm="pyzor" exe="/usr/bin/python"
>>> type=AVC_PATH msg=audit(1149352205.020:299):
path="/usr/bin/time"
>>> type=CWD msg=audit(1149352205.020:299): cwd="/"
>>> type=PATH msg=audit(1149352205.020:299): item=0
name="/usr/bin/time" flags=1 inode=3132233 dev=16:07 mode=0100755 ouid=0 ogid=0
rdev=00:00
>> pyzor trying to run /usr/bin/time. Any idea why? Allowing it to run
>> arbitrary binaries would be quite a concession.
>
> Not sure.
<snip of python timing code>
Not convinced anything there is responsible. We'll have to allow
it for
now and follow up later.
OK
<snip>
> type=AVC msg=audit(1149561389.767:5): avc: denied { getattr }
for pid=2141 comm="sh" name="mailq.postfix.1.gz" dev=hdc7 ino=3132510
scontext=system_u:system_r:postfix_master_t:s0 tcontext=system_u:object_r:man_t:s0
tclass=file
> type=SYSCALL msg=audit(1149561389.767:5): arch=40000003 syscall=195 success=yes
exit=0 a0=913bd10 a1=bffc8438 a2=4891eff4 a3=913c3c8 items=1 pid=2141 auid=4294967295
uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="sh"
exe="/bin/bash"
> type=AVC_PATH msg=audit(1149561389.767:5):
path="/usr/share/man/man1/mailq.postfix.1.gz"
> type=CWD msg=audit(1149561389.767:5): cwd="/var/spool/postfix"
> type=PATH msg=audit(1149561389.767:5): item=0
name="/usr/share/man/man1/mailq.postfix.1.gz" flags=1 inode=3132510 dev=16:07
mode=0100644 ouid=0 ogid=0 rdev=00:00
Don't know what's going on here but it's fairly harmless so we'll allow
it for now, pending further investigation.
OK
> type=AVC msg=audit(1149561396.952:6): avc: denied { append }
for pid=2196 comm="spamd" name="razor-agent.log" dev=hdc7 ino=829594
scontext=system_u:system_r:spamd_t:s0 tcontext=system_u:object_r:user_home_dir_t:s0
tclass=file
> type=SYSCALL msg=audit(1149561396.952:6): arch=40000003 syscall=5 success=yes exit=6
a0=aa50688 a1=8441 a2=1b6 a3=8441 items=1 pid=2196 auid=4294967295 uid=0 gid=0 euid=0
suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="spamd" exe="/usr/bin/perl"
> type=CWD msg=audit(1149561396.952:6): cwd="/"
> type=PATH msg=audit(1149561396.952:6): item=0
name="/root/.razor/razor-agent.log" flags=310 inode=829589 dev=16:07
mode=040755 ouid=0 ogid=0 rdev=00:00
Spamd appending to the razor log file. Do you have the
spamd_enable_home_dirs boolean set?
# getsebool spamd_enable_home_dirs
If it's not set, please set it:
# setsebool -P spamd_enable_home_dirs 1
Yep it was set already.
<snip>
> type=AVC msg=audit(1149561408.789:14): avc: denied { read
write } for pid=2419 comm="mingetty" name="utmp" dev=hdc5 ino=146250
scontext=system_u:system_r:getty_t:s0 tcontext=system_u:object_r:init_var_run_t:s0
tclass=file
> type=SYSCALL msg=audit(1149561408.789:14): arch=40000003 syscall=5 success=yes
exit=3 a0=48909fd4 a1=2 a2=804a000 a3=48909fda items=1 pid=2419 auid=4294967295 uid=0
gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="mingetty"
exe="/sbin/mingetty"
> type=CWD msg=audit(1149561408.789:14): cwd="/"
> type=PATH msg=audit(1149561408.789:14): item=0 name="/var/run/utmp"
flags=101 inode=146250 dev=16:05 mode=0100664 ouid=0 ogid=22 rdev=00:00
> type=AVC msg=audit(1149561408.789:15): avc: denied { lock } for pid=2419
comm="mingetty" name="utmp" dev=hdc5 ino=146250
scontext=system_u:system_r:getty_t:s0 tcontext=system_u:object_r:init_var_run_t:s0
tclass=file
> type=SYSCALL msg=audit(1149561408.789:15): arch=40000003 syscall=221 success=yes
exit=0 a0=3 a1=7 a2=bfc8fe3c a3=bfc8fdb0 items=0 pid=2419 auid=4294967295 uid=0 gid=0
euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="mingetty"
exe="/sbin/mingetty"
> type=AVC_PATH msg=audit(1149561408.789:15): path="/var/run/utmp"
No idea what these are, though if you're on the current policy
(selinux-policy-2.2.40-1.fc5) it would seem that your /var/run/utmp is
labelled incorrectly (init_var_run_t instead of initrc_var_run_t).
OK...this is weird. Why are both versions [still] installed, or at least
RPM thinks that they are?:
$ rpm -qa | grep selinux-policy
selinux-policy-targeted-2.2.23-15
selinux-policy-targeted-2.2.40-1.fc5
selinux-policy-2.2.23-15
selinux-policy-2.2.40-1.fc5
system_u:object_r:init_var_run_t /var/run/utmp
Funny, but again, running 'fixfiles check' did not report any errors.
Try:
# restorecon -v /var/run/utmp
Done.
system_u:object_r:initrc_var_run_t /var/run/utmp
> type=AVC msg=audit(1149561602.879:55): avc: denied { use } for
pid=5247 comm="clamscan" name="[14742]" dev=pipefs ino=14742
scontext=system_u:system_r:clamscan_t:s0 tcontext=system_u:system_r:postfix_local_t:s0
tclass=fd
> type=AVC msg=audit(1149561602.879:55): avc: denied { write } for pid=5247
comm="clamscan" name="[14742]" dev=pipefs ino=14742
scontext=system_u:system_r:clamscan_t:s0 tcontext=system_u:system_r:postfix_local_t:s0
tclass=fifo_file
> type=SYSCALL msg=audit(1149561602.879:55): arch=40000003 syscall=11 success=yes
exit=0 a0=8889c00 a1=8889210 a2=8889dd0 a3=8889d90 items=2 pid=5247 auid=4294967295
uid=500 gid=500 euid=500 suid=500 fsuid=500 egid=500 sgid=500 fsgid=500
comm="clamscan" exe="/usr/bin/clamscan"
> type=AVC_PATH msg=audit(1149561602.879:55): path="pipe:[14742]"
> type=AVC_PATH msg=audit(1149561602.879:55): path="pipe:[14742]"
> type=CWD msg=audit(1149561602.879:55): cwd="/home/marcs"
> type=PATH msg=audit(1149561602.879:55): item=0 name="/usr/bin/clamscan"
flags=101 inode=3123838 dev=16:07 mode=0100755 ouid=0 ogid=0 rdev=00:00
> type=PATH msg=audit(1149561602.879:55): item=1 flags=101 inode=754491 dev=16:07
mode=0100755 ouid=0 ogid=0 rdev=00:00
I wonder if output from postfix's local delivery process (sub-contracted
to procmail) is piped back into postfix-local? Added to module for now.
Not familiar with some of the low level stuff here. I would have to
defer to others.
Got all the policy updates installed, including your follow up on
myclam.te with the addition to the require clause:
# /usr/sbin/semodule -l
clamav 1.0.0
myclam 0.1.2
mydcc 0.1.2
mypostfix 0.1.0
mypyzor 0.1.2
procmail 0.5.0
So, here is the latest avclist output. Note that the razor man messages
are not here this time around. I did clear the log again and re-booted
prior to running this.
type=AVC msg=audit(1149621174.677:5): avc: denied { append } for pid=2100
comm="spamd" name="razor-agent.log" dev=hdc7 ino=829594
scontext=system_u:system_r:spamd_t:s0 tcontext=system_u:object_r:user_home_dir_t:s0
tclass=file
type=SYSCALL msg=audit(1149621174.677:5): arch=40000003 syscall=5 success=yes exit=6
a0=a68c6d0 a1=8441 a2=1b6 a3=8441 items=1 pid=2100 auid=4294967295 uid=0 gid=0 euid=0
suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="spamd" exe="/usr/bin/perl"
type=CWD msg=audit(1149621174.677:5): cwd="/"
type=PATH msg=audit(1149621174.677:5): item=0
name="/root/.razor/razor-agent.log" flags=310 inode=829589 dev=16:07
mode=040755 ouid=0 ogid=0 rdev=00:00
type=AVC msg=audit(1149621174.677:6): avc: denied { ioctl } for pid=2100
comm="spamd" name="razor-agent.log" dev=hdc7 ino=829594
scontext=system_u:system_r:spamd_t:s0 tcontext=system_u:object_r:user_home_dir_t:s0
tclass=file
type=SYSCALL msg=audit(1149621174.677:6): arch=40000003 syscall=54 success=no exit=-25
a0=6 a1=5401 a2=bf88db98 a3=bf88dbd8 items=0 pid=2100 auid=4294967295 uid=0 gid=0 euid=0
suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="spamd" exe="/usr/bin/perl"
type=AVC_PATH msg=audit(1149621174.677:6): path="/root/.razor/razor-agent.log"
type=AVC msg=audit(1149621174.677:7): avc: denied { getattr } for pid=2100
comm="spamd" name="razor-agent.log" dev=hdc7 ino=829594
scontext=system_u:system_r:spamd_t:s0 tcontext=system_u:object_r:user_home_dir_t:s0
tclass=file
type=SYSCALL msg=audit(1149621174.677:7): arch=40000003 syscall=197 success=yes exit=0
a0=6 a1=8fbd068 a2=4891eff4 a3=8fd3f64 items=0 pid=2100 auid=4294967295 uid=0 gid=0 euid=0
suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="spamd" exe="/usr/bin/perl"
type=AVC_PATH msg=audit(1149621174.677:7): path="/root/.razor/razor-agent.log"
type=AVC msg=audit(1149621174.685:8): avc: denied { read } for pid=2100
comm="spamd" name="servers.discovery.lst" dev=hdc7 ino=829591
scontext=system_u:system_r:spamd_t:s0 tcontext=system_u:object_r:user_home_dir_t:s0
tclass=file
type=SYSCALL msg=audit(1149621174.685:8): arch=40000003 syscall=5 success=yes exit=7
a0=a694a28 a1=8000 a2=0 a3=8000 items=1 pid=2100 auid=4294967295 uid=0 gid=0 euid=0 suid=0
fsuid=0 egid=0 sgid=0 fsgid=0 comm="spamd" exe="/usr/bin/perl"
type=CWD msg=audit(1149621174.685:8): cwd="/"
type=PATH msg=audit(1149621174.685:8): item=0
name="/root/.razor/servers.discovery.lst" flags=101 inode=829591 dev=16:07
mode=0100644 ouid=0 ogid=0 rdev=00:00
type=AVC msg=audit(1149621174.701:9): avc: denied { read } for pid=2100
comm="spamd" name=".razor" dev=hdc7 ino=829589
scontext=system_u:system_r:spamd_t:s0 tcontext=system_u:object_r:user_home_dir_t:s0
tclass=dir
type=SYSCALL msg=audit(1149621174.701:9): arch=40000003 syscall=5 success=yes exit=7
a0=a68c070 a1=18800 a2=0 a3=a0d99b8 items=1 pid=2100 auid=4294967295 uid=0 gid=0 euid=0
suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="spamd" exe="/usr/bin/perl"
type=CWD msg=audit(1149621174.701:9): cwd="/"
type=PATH msg=audit(1149621174.701:9): item=0 name="/root/.razor" flags=103
inode=829589 dev=16:07 mode=040755 ouid=0 ogid=0 rdev=00:00
type=AVC msg=audit(1149621186.790:10): avc: denied { read write } for pid=2322
comm="mingetty" name="utmp" dev=hdc5 ino=146250
scontext=system_u:system_r:getty_t:s0 tcontext=system_u:object_r:init_var_run_t:s0
tclass=file
type=SYSCALL msg=audit(1149621186.790:10): arch=40000003 syscall=5 success=yes exit=3
a0=48909fd4 a1=2 a2=804a000 a3=48909fda items=1 pid=2322 auid=4294967295 uid=0 gid=0
euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="mingetty"
exe="/sbin/mingetty"
type=CWD msg=audit(1149621186.790:10): cwd="/"
type=PATH msg=audit(1149621186.790:10): item=0 name="/var/run/utmp" flags=101
inode=146250 dev=16:05 mode=0100664 ouid=0 ogid=22 rdev=00:00
type=AVC msg=audit(1149621186.790:11): avc: denied { lock } for pid=2322
comm="mingetty" name="utmp" dev=hdc5 ino=146250
scontext=system_u:system_r:getty_t:s0 tcontext=system_u:object_r:init_var_run_t:s0
tclass=file
type=SYSCALL msg=audit(1149621186.790:11): arch=40000003 syscall=221 success=yes exit=0
a0=3 a1=7 a2=bfe651fc a3=bfe65170 items=0 pid=2322 auid=4294967295 uid=0 gid=0 euid=0
suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 comm="mingetty"
exe="/sbin/mingetty"
type=AVC_PATH msg=audit(1149621186.790:11): path="/var/run/utmp"
Regards,
Marc