Amavisd does not start
Paul Howarth
paul at city-fan.org
Fri Jul 21 09:53:16 UTC 2006
Chris Jones wrote:
> 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?
It is a bug, probably due to changes in SELinux; I suspect that the
current amavis would have worked with older SELinux policies.
> 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"?
You could view it as a good opportunity to start learning about SELinux :-)
Probably the best place to raise this and get it fixed would be
fedora-selinux-list. You might also want to have a go at fixing it
yourself, and if you succeed, you could mention that when you post to
the SELinux list.
Here's a brief intro to fixing SELinux problems in FC5:
http://www.city-fan.org/tips/BuildSeLinuxPolicyModules
Paul.
More information about the users
mailing list