postfix, procmail and SELinux - No Go

Marc Schwartz (via MN) mschwartz at mn.rr.com
Tue Jun 6 19:37:24 UTC 2006


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






More information about the fedora-selinux-list mailing list