Amavisd does not start

[Chris Jones]

Alexander Dalloz wrote:
> Chris Jones schrieb:
>
>> Alexander Dalloz wrote:
>>
>>>> ... and here is the log fragment for that start:
>>>> Jul 20 18:27:41 bilbo amavis[7120]: starting.  /usr/sbin/amavisd at 
>>>> bilbo.stow-jones.local amavisd-new-2.4.1 (20060508), Unicode aware, 
>>>> LANG=en_US.UTF-8
>>>> Jul 20 18:27:41 bilbo amavis[7120]: Perl version               
>>>> 5.008008
>>>
>>>
>>> Nothing more appears at amavisd start time? Normally quite a few 
>>> tests would run, about the Perl environment / helper modules, 
>>> anti-virus scanners, spamassassin ...
>>>
>> No. That is all that occurs.
>
> Ok. Not good. Then amavisd ends at a very early point.
>
>>> Time to get a hand at /etc/amavisd.conf. It has an option to not use 
>>> sylog for logging but an own file. Use that in combination with a 
>>> higher debug level.
>>
>> $DO_SYSLOG = 1;              # log via syslogd (preferred)
>>
>> What level should I set to increase the logging?
>
> The maximum debug level is "5". Be not shocked to see a lot of 
> information, but that is its purpose.
>
>>> Do you have SELinux being enforced?
>>
>> Yes
>
> Then for a quick test I would switch into permissive mode, to see if 
> that is the culprit. You too could have a look at /var/log/messages or 
> if auditd runs at /var/log/audit/audit.log to watch auth for amavisd 
> related avc / audit messages.
I already had audit switched on (to solve a previous issue some weeks 
ago). Here is the result of an attempt to stop amavisd having 
successfully started it following Justin's suggestion.

type=AVC msg=audit(1153425626.139:348): avc:  denied  { read write } 
for  pid=8158 comm="amavisd" name="1" dev=devpts ino=3 
scontext=user_u:system_r:amavis_t:s0 
tcontext=user_u:object_r:devpts_t:s0 tclass=chr_file
type=AVC msg=audit(1153425626.139:348): avc:  denied  { read write } 
for  pid=8158 comm="amavisd" name="1" dev=devpts ino=3 
scontext=user_u:system_r:amavis_t:s0 
tcontext=user_u:object_r:devpts_t:s0 tclass=chr_file
type=AVC msg=audit(1153425626.139:348): avc:  denied  { read write } 
for  pid=8158 comm="amavisd" name="1" dev=devpts ino=3 
scontext=user_u:system_r:amavis_t:s0 
tcontext=user_u:object_r:devpts_t:s0 tclass=chr_file
type=AVC msg=audit(1153425626.139:348): avc:  denied  { read write } 
for  pid=8158 comm="amavisd" name="1" dev=devpts ino=3 
scontext=user_u:system_r:amavis_t:s0 
tcontext=user_u:object_r:devpts_t:s0 tclass=chr_file
type=SYSCALL msg=audit(1153425626.139:348): arch=c000003e syscall=59 
success=yes exit=0 a0=6ee2d0 a1=6c9d00 a2=6c89a0 a3=8 items=3 pid=8158 
auid=500 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 
comm="amavisd" exe="/usr/bin/perl"
type=AVC_PATH msg=audit(1153425626.139:348):  path="/dev/pts/1"
type=AVC_PATH msg=audit(1153425626.139:348):  path="/dev/pts/1"
type=AVC_PATH msg=audit(1153425626.139:348):  path="/dev/pts/1"
type=CWD msg=audit(1153425626.139:348):  cwd="/"
type=PATH msg=audit(1153425626.139:348): item=0 name="/usr/sbin/amavisd" 
flags=101  inode=23835933 dev=fd:00 mode=0100755 ouid=0 ogid=0 rdev=00:00
type=PATH msg=audit(1153425626.139:348): item=1 flags=101  
inode=23828297 dev=fd:00 mode=0100755 ouid=0 ogid=0 rdev=00:00
type=PATH msg=audit(1153425626.139:348): item=2 flags=101  
inode=23003181 dev=fd:00 mode=0100755 ouid=0 ogid=0 rdev=00:00
type=AVC msg=audit(1153425626.147:349): avc:  denied  { search } for  
pid=8158 comm="amavisd" scontext=user_u:system_r:amavis_t:s0 
tcontext=system_u:object_r:sysctl_kernel_t:s0 tclass=dir
type=SYSCALL msg=audit(1153425626.147:349): arch=c000003e syscall=156 
success=no exit=-1 a0=7fffffbc93e0 a1=0 a2=0 a3=347f347cc0 items=0 
pid=8158 auid=500 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 
fsgid=0 comm="amavisd" exe="/usr/bin/perl"
type=AVC msg=audit(1153425627.555:350): avc:  denied  { getattr } for  
pid=8158 comm="amavisd" name="amavisd.pid" dev=dm-0 ino=34767186 
scontext=user_u:system_r:amavis_t:s0 
tcontext=user_u:object_r:var_run_t:s0 tclass=file
type=SYSCALL msg=audit(1153425627.555:350): arch=c000003e syscall=4 
success=no exit=-13 a0=8c5fe0 a1=504140 a2=504140 a3=0 items=1 pid=8158 
auid=500 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 
comm="amavisd" exe="/usr/bin/perl"
type=AVC_PATH msg=audit(1153425627.555:350):  
path="/var/run/amavisd/amavisd.pid"
type=CWD msg=audit(1153425627.555:350):  cwd="/"
type=PATH msg=audit(1153425627.555:350): item=0 
name="/var/run/amavisd/amavisd.pid" flags=1  inode=34767186 dev=fd:00 
mode=0100640 ouid=101 ogid=501 rdev=00:00

It does look as though this has something to do with SELinux being set 
to Enforcing.

I have now set SELinux to permissive and (lo and behold) the commands 
'service amavisd start' and 'service amavisd stop' both work as intended.

Is this behaviour when SELinux is set to Enforcing correct? Or is this a 
bug that needs to be addressed?

Following on from this, and based upon the fact that my FC5 box is only 
a personal "toy" system so that I can learn Linux properly, should I be 
concerned about SELinux being set to "permissive"?

Apologies for all the (stupid) questions, but even after about two years 
playing with Linux, I still consider myself a novice.

-- 
Chris Jones