Gentoo Websites Logo
Go to: Gentoo Home Documentation Forums Lists Bugs Planet Store Wiki Get Gentoo!
Bug 836768 - mail-filter/amavisd-new-2.12.2: not able to read dkim key files due to permission privilege
Summary: mail-filter/amavisd-new-2.12.2: not able to read dkim key files due to permis...
Status: RESOLVED CANTFIX
Alias: None
Product: Gentoo Linux
Classification: Unclassified
Component: Current packages (show other bugs)
Hardware: AMD64 Linux
: Normal normal (vote)
Assignee: Ralph Seichter
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2022-04-04 16:21 UTC by Joakim
Modified: 2022-04-08 12:44 UTC (History)
3 users (show)

See Also:
Package list:
Runtime testing required: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Joakim 2022-04-04 16:21:33 UTC
After updating amavisd-new to 2.12.2 all incoming mail is queued because amavisd never really starts (no process is created, even though it creates /run/amavisd.pid  



Reproducible: Always

Steps to Reproduce:
1.merc /usr/src # /etc/init.d/amavisd restart
 * Stopping amavisd ...
 * start-stop-daemon: no matching processes found                                                             [ ok ]
 * Starting amavisd ...                                                                                       [ ok ]
merc /usr/src # /etc/init.d/amavisd status
 * status: crashed
merc /usr/src # ls -l /run/amavisd.pid
-rw-r--r-- 1 root root 6 Apr  4 16:02 /run/amavisd.pid
2.merc /usr/src # ps aux | grep amavis
root     23235  0.0  0.0   8336  4788 pts/4    S+   15:36   0:00 nano /etc/amavisd.conf
postfix  23964  0.0  0.0  50968 10664 ?        S    16:04   0:00 smtp -n smtp-amavis -t unix -u -o smtp_data_done_timeout=1200 -o smtp_send_xforward_command=yes -o disable_dns_lookups=yes -o max_use=20
root     23993  0.0  0.0   6684  2172 pts/1    S+   16:05   0:00 grep --colour=auto amavis

in other words, no amavisd process

3.  # netstat -tap
also show no sign of amavisd's presence
Actual Results:  
all incoming mails are stuck in the mail queue as there is no mail filter to process them.

Expected Results:  
amavisd is expected to start and process incoming mail as it did before to update.
Nothing in the configuration was changed.


Indeed, I have rebuilt the whole system, not only for this reason, but it should ensure that everything is up-to-date.

# emerge --info
Portage 3.0.30 (python 3.9.12-final-0, default/linux/amd64/17.0, gcc-9.4.1, glibc-2.35-r2, 4.19.28-gentoo x86_64)
=================================================================
System uname: Linux-4.19.28-gentoo-x86_64-Intel-R-_Xeon-R-_CPU_E5450_@_3.00GHz-with-glibc2.35
KiB Mem:    32895140 total,   7732404 free
KiB Swap:    5011452 total,   5011452 free
Timestamp of repository gentoo: Sun, 03 Apr 2022 18:30:01 +0000
Head commit of repository gentoo: df0333a02c6363b79e61c79af858c5f58dd7e465
Timestamp of repository vmacs: Fri, 01 Apr 2022 15:37:41 +0000
Head commit of repository vmacs: 222be45278d8dcfc78f3c23b681a6be8c827fe3d

sh bash 5.1_p16
ld GNU ld (Gentoo 2.35.2 p1) 2.35.2
app-misc/pax-utils:        1.3.3::gentoo
app-shells/bash:           5.1_p16::gentoo
dev-lang/perl:             5.34.1::gentoo
dev-lang/python:           3.8.13::gentoo, 3.9.12::gentoo
dev-util/cmake:            3.23.0::gentoo
dev-util/meson:            0.61.4-r2::gentoo
sys-apps/baselayout:       2.8::gentoo
sys-apps/openrc:           0.44.10::gentoo
sys-apps/sandbox:          2.29::gentoo
sys-devel/autoconf:        2.69-r5::gentoo, 2.71-r1::gentoo
sys-devel/automake:        1.13.4-r2::gentoo, 1.16.5::gentoo
sys-devel/binutils:        2.35.2::gentoo, 2.36.1-r1::gentoo, 2.37_p1-r2::gentoo, 2.38-r1::gentoo
sys-devel/binutils-config: 5.4.1::gentoo
sys-devel/clang:           12.0.1::gentoo, 13.0.1::gentoo
sys-devel/gcc:             6.5.0-r3::gentoo, 8.5.0-r1::gentoo, 9.4.1_p20220317::gentoo
sys-devel/gcc-config:      2.5-r1::gentoo
sys-devel/libtool:         2.4.7::gentoo
sys-devel/llvm:            12.0.1::gentoo, 13.0.1::gentoo, 14.0.0::gentoo
sys-devel/make:            4.3::gentoo
sys-kernel/linux-headers:  5.17::gentoo (virtual/os-headers)
sys-libs/glibc:            2.35-r2::gentoo
Repositories:

gentoo
    location: /usr/portage
    sync-type: rsync
    sync-uri: rsync://rsync.gentoo.org/gentoo-portage
    priority: -1000
    sync-rsync-verify-max-age: 24
    sync-rsync-verify-metamanifest: yes
    sync-rsync-extra-opts:
    sync-rsync-verify-jobs: 1

vmacs
    location: /var/db/repos/vmacs
    sync-type: git
    sync-uri: https://github.com/gentoo-mirror/vmacs.git
    masters: gentoo

x-portage
    location: /usr/local/portage
    masters: gentoo
    priority: 0

ACCEPT_KEYWORDS="amd64 ~amd64"
ACCEPT_LICENSE="* -@EULA"
CBUILD="x86_64-pc-linux-gnu"
CFLAGS="-march=native -O2 -pipe"
CHOST="x86_64-pc-linux-gnu"
CONFIG_PROTECT="/etc /usr/share/gnupg/qualified.txt"
CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/env.d /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/php/apache2-php7.3/ext-active/ /etc/php/apache2-php7.4/ext-active/ /etc/php/cgi-php7.3/ext-active/ /etc/php/cgi-php7.4/ext-active/ /etc/php/cli-php7.3/ext-active/ /etc/php/cli-php7.4/ext-active/ /etc/php/fpm-php7.4/ext-active/ /etc/php/phpdbg-php7.4/ext-active/ /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo"
CXXFLAGS="-march=native -O2 -pipe"
DISTDIR="/usr/portage/distfiles"
ENV_UNSET="CARGO_HOME DBUS_SESSION_BUS_ADDRESS DISPLAY GOBIN GOPATH PERL5LIB PERL5OPT PERLPREFIX PERL_CORE PERL_MB_OPT PERL_MM_OPT XAUTHORITY XDG_CACHE_HOME XDG_CONFIG_HOME XDG_DATA_HOME XDG_RUNTIME_DIR"
FCFLAGS="-O2 -pipe"
FEATURES="assume-digests binpkg-docompress binpkg-dostrip binpkg-logs buildpkg-live config-protect-if-modified distlocks ebuild-locks fixlafiles ipc-sandbox merge-sync multilib-strict network-sandbox news parallel-fetch pid-sandbox preserve-libs protect-owned qa-unresolved-soname-deps sandbox sfperms strict unknown-features-warn unmerge-logs unmerge-orphans userfetch userpriv usersandbox usersync xattr"
FFLAGS="-O2 -pipe"
GENTOO_MIRRORS="http://gentoo.supp.name/ http://ftp.fi.muni.cz/pub/linux/gentoo/ rsync://ftp.fi.muni.cz/pub/linux/gentoo/ ftp://ftp.fi.muni.cz/pub/linux/gentoo/ http://mirror.dkm.cz/gentoo/ rsync://mirror.dkm.cz/gentoo/ ftp://mirror.dkm.cz/gentoo/ https://mirror.dkm.cz/gentoo/ ftp://gentoo.mirror.web4u.cz/ http://gentoo.mirror.web4u.cz/"
LANG="en_US"
LDFLAGS="-Wl,-O1 -Wl,--as-needed"
MAKEOPTS="-j9"
PKGDIR="/usr/portage/packages"
PORTAGE_CONFIGROOT="/"
PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --omit-dir-times --compress --force --whole-file --delete --stats --human-readable --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages --exclude=/.git"
PORTAGE_TMPDIR="/var/tmp"
SHELL="/bin/bash"
USE="acl amd64 apache2 bzip2 cli crypt dovecot-sasl dri fontconfig fortran fpm gd gdbm gnutls highlight iconv ithreads jpeg json libglvnd libtirpc logrotate multilib mysql ncurses nls nptl openmp openssl pam pcre png python readline seccomp sftp split-usr ssl subversion threads truetype unicode urandom vhosts xattr zlib" ABI_X86="64" ADA_TARGET="gnat_2020" APACHE2_MODULES="unique_id alias auth_basic authn_core authz_core auth_digest authn_file authz_groupfile authz_host authz_user cgid deflate dir expires filter headers http2 imagemap log_config logio mem_cache mime proxy proxy_fcgi rewrite setenvif so socache_shmcb status unixd" APACHE2_MPMS="event" CALLIGRA_FEATURES="karbon sheets words" COLLECTD_PLUGINS="df interface irq load memory rrdtool swap syslog" CPU_FLAGS_X86="mmx sse sse2" ELIBC="glibc" GPSD_PROTOCOLS="ashtech aivdm earthmate evermore fv18 garmin garmintxt gpsclock greis isync itrax mtk3301 nmea ntrip navcom oceanserver oldstyle oncore rtcm104v2 rtcm104v3 sirf skytraq superstar2 timing tsip tripmate tnt ublox ubx" INPUT_DEVICES="libinput" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LIBREOFFICE_EXTENSIONS="presenter-console presenter-minimizer" LUA_SINGLE_TARGET="lua5-1" LUA_TARGETS="lua5-1" OFFICE_IMPLEMENTATION="libreoffice" PHP_TARGETS="php7-4" POSTGRES_TARGETS="postgres12 postgres13" PYTHON_SINGLE_TARGET="python3_9" PYTHON_TARGETS="python3_9" RUBY_TARGETS="ruby26 ruby27" USERLAND="GNU" VIDEO_CARDS="amdgpu fbdev intel nouveau radeon radeonsi vesa dummy v4l" XTABLES_ADDONS="quota2 psd pknock lscan length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq proto steal rawnat logmark ipmark dhcpmac delude chaos account"
Unset:  ADDR2LINE, AR, ARFLAGS, AS, ASFLAGS, CC, CCLD, CONFIG_SHELL, CPP, CPPFLAGS, CTARGET, CXX, CXXFILT, ELFEDIT, EMERGE_DEFAULT_OPTS, EXTRA_ECONF, F77FLAGS, FC, GCOV, GPROF, INSTALL_MASK, LC_ALL, LD, LEX, LFLAGS, LIBTOOL, LINGUAS, MAKE, MAKEFLAGS, NM, OBJCOPY, OBJDUMP, PORTAGE_BINHOST, PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS, RANLIB, READELF, RUSTFLAGS, SIZE, STRINGS, STRIP, YACC, YFLAGS
Comment 1 Joakim 2022-04-04 16:36:27 UTC
more info:
# /etc/init.d/amavisd -v restart
 * Executing: /lib/rc/sh/openrc-run.sh /lib/rc/sh/openrc-run.sh /etc/init.d/amavisd stop
 * Stopping amavisd ...
 * Will stop /usr/sbin/amavisd
 * Will stop PID 26856
 * Will stop processes of `/usr/sbin/amavisd SIGKILL/60'
 * start-stop-daemon: no matching processes found                                                             [ ok ]
 * Executing: /lib/rc/sh/openrc-run.sh /lib/rc/sh/openrc-run.sh /etc/init.d/amavisd start
 * Starting amavisd ...
 * start-stop-daemon: fopen `/run/amavisd.pid': No such file or directory
 * Detaching to start `/usr/sbin/amavisd' ...                                                                 [ ok ]
Comment 2 Joakim 2022-04-04 16:44:21 UTC
This issue was originally brought up in the forum:

https://forums.gentoo.org/viewtopic-t-1147509-start-0-postdays-0-postorder-asc-highlight-.html

were user deagol suggested that " commenting out line 2238 from /usr/sbin/amavisd

elsif ($! != 0)  { die "Error reading config file \"$config_file\": $!" }"

and changing it to

"elsif "0 != 0""

solves the problem, but doubtful that's the real fix.
Comment 3 Joakim 2022-04-04 22:08:47 UTC
(In reply to Joakim from comment #2)
> This issue was originally brought up in the forum:
> 
> https://forums.gentoo.org/viewtopic-t-1147509-start-0-postdays-0-postorder-
> asc-highlight-.html
> 
> were user deagol suggested that " commenting out line 2238 from
> /usr/sbin/amavisd
> 
> elsif ($! != 0)  { die "Error reading config file \"$config_file\": $!" }"
> 
> and changing it to
> 
> "elsif "0 != 0""
> 
> solves the problem, but doubtful that's the real fix.

Actually, it doesn't. Not for me anyway.
Comment 4 Joakim 2022-04-04 22:22:59 UTC
So, I have tried for hours now to figure this out (as my mail queue keeps piling up), but hard to know where to start as it (amavisd) doesn't produce any log output. Not a single line.

The only thing visible in the logs (/var/log/mail/current) is this single line:

Apr 04 22:16:02 [/etc/init.d/amavisd] start-stop-daemon: no matching processes found

but I don't think that comes from amavisd itself but the startup script.

most available info afaik comes from

# /etc/init.d/amavisd -d start

but it rather confuses me than telling me something, but well hopefully it does to someone so here is the output:
+ sourcex -e /etc/rc.conf
+ '[' -e = -e ']'
+ shift
+ '[' -e /etc/rc.conf ']'
+ . /etc/rc.conf
++ rc_shell=/sbin/sulogin
++ unicode=YES
++ rc_tty_number=12
+ '[' -d /etc/rc.conf.d ']'
+ _conf_d=/etc/init.d/../conf.d
+ _c=amavisd
+ '[' -n amavisd -a amavisd '!=' amavisd ']'
+ unset _c
+ sourcex -e /etc/init.d/../conf.d/amavisd.default
+ '[' -e = -e ']'
+ shift
+ '[' -e /etc/init.d/../conf.d/amavisd.default ']'
+ return 1
+ sourcex -e /etc/init.d/../conf.d/amavisd
+ '[' -e = -e ']'
+ shift
+ '[' -e /etc/init.d/../conf.d/amavisd ']'
+ return 1
+ unset _conf_d
+ sourcex /lib/rc/sh/runit.sh
+ '[' /lib/rc/sh/runit.sh = -e ']'
+ . /lib/rc/sh/runit.sh
+ sourcex /lib/rc/sh/s6.sh
+ '[' /lib/rc/sh/s6.sh = -e ']'
+ . /lib/rc/sh/s6.sh
++ '[' -z '' ']'
++ s6_service_path=/var/svc.d/amavisd
+ sourcex /lib/rc/sh/start-stop-daemon.sh
+ '[' /lib/rc/sh/start-stop-daemon.sh = -e ']'
+ . /lib/rc/sh/start-stop-daemon.sh
+ sourcex /lib/rc/sh/supervise-daemon.sh
+ '[' /lib/rc/sh/supervise-daemon.sh = -e ']'
+ . /lib/rc/sh/supervise-daemon.sh
++ extra_commands='healthcheck unhealthy '
+ sourcex /etc/init.d/amavisd
+ '[' /etc/init.d/amavisd = -e ']'
+ . /etc/init.d/amavisd
++ extra_started_commands=reload
++ command=/usr/sbin/amavisd
++ pidfile=/run/amavisd.pid
++ command_args=foreground
++ command_background=true
++ retry='SIGTERM/15 SIGKILL/60'
+ yesno ''
+ '[' -z '' ']'
+ return 1
+ for _cmd in "$@"
+ '[' start '!=' status -a start '!=' describe ']'
+ '[' -n '' ']'
++ command -v cgroup_add_service
+ '[' cgroup_add_service = cgroup_add_service ']'
+ grep -qs /sys/fs/cgroup /proc/1/mountinfo
+ '[' -d /sys/fs/cgroup -a '!' -w /sys/fs/cgroup ']'
+ cgroup_add_service
+ for d in /sys/fs/cgroup/*
+ '[' -w /sys/fs/cgroup/net_cls/tasks ']'
+ printf %d 0
+ for d in /sys/fs/cgroup/*
+ '[' -w /sys/fs/cgroup/openrc/tasks ']'
+ printf %d 0
+ for d in /sys/fs/cgroup/*
+ '[' -w /sys/fs/cgroup/unified/tasks ']'
+ openrc_cgroup=/sys/fs/cgroup/openrc
+ '[' -d /sys/fs/cgroup/openrc ']'
+ cgroup=/sys/fs/cgroup/openrc/amavisd
+ mkdir -p /sys/fs/cgroup/openrc/amavisd
+ '[' -w /sys/fs/cgroup/openrc/amavisd/tasks ']'
+ printf %d 0
++ command -v cgroup_set_limits
+ '[' cgroup_set_limits = cgroup_set_limits ']'
+ cgroup_set_limits
+ local blkio=
+ '[' -n '' ']'
+ local cpu=
+ '[' -n '' ']'
+ local cpuacct=
+ '[' -n '' ']'
+ local cpuset=
+ '[' -n '' ']'
+ local devices=
+ '[' -n '' ']'
+ local hugetlb=
+ '[' -n '' ']'
+ local memory=
+ '[' -n '' ']'
+ local net_cls=
+ '[' -n '' ']'
+ local net_prio=
+ '[' -n '' ']'
+ local pids=
+ '[' -n '' ']'
+ return 0
++ command -v cgroup2_set_limits
+ '[' cgroup2_set_limits = cgroup2_set_limits ']'
+ '[' start = start ']'
+ cgroup2_set_limits
+ local cgroup_path
++ cgroup2_find_path
++ grep -qw cgroup2 /proc/filesystems
++ case "${rc_cgroup_mode:-hybrid}" in
++ printf /sys/fs/cgroup/unified
++ return 0
+ cgroup_path=/sys/fs/cgroup/unified
+ '[' -z /sys/fs/cgroup/unified ']'
+ mountinfo -q /sys/fs/cgroup/unified
+ rc_cgroup_path=/sys/fs/cgroup/unified/amavisd
+ '[' '!' -d /sys/fs/cgroup/unified/amavisd ']'
+ mkdir /sys/fs/cgroup/unified/amavisd
+ '[' -f /sys/fs/cgroup/unified/amavisd/cgroup.procs ']'
+ printf 0
+ '[' -z '' ']'
+ return 0
+ break
+ eval 'printf '\''%s\n'\'' '
++ printf '%s\n'
+ read _d
+ '[' -n '' ']'
+ read _d
+ '[' 0 -ne 0 ']'
+ unset _d
+ eval 'printf '\''%s\n'\'' '
++ printf '%s\n'
+ read _f
+ '[' -n '' ']'
+ read _f
+ '[' 0 -ne 0 ']'
+ unset _f
+ '[' -n '' ']'
+ '[' -n start ']'
+ '[' start = depend ']'
+ for _cmd in describe start stop status ${extra_commands:-$opts} $extra_started_commands $extra_stopped_commands
+ '[' describe = start ']'
+ for _cmd in describe start stop status ${extra_commands:-$opts} $extra_started_commands $extra_stopped_commands
+ '[' start = start ']'
++ command -v start
+ '[' start = start ']'
+ yesno
+ '[' -z '' ']'
+ return 1
+ for _cmd in $extra_started_commands
+ '[' reload = start ']'
+ for _cmd in $extra_stopped_commands
+ '[' cgroup_cleanup = start ']'
+ unset _cmd
+ case $1 in
+ verify_boot
+ '[' '!' -e /run/openrc/softlevel ']'
+ return 0
++ command -v start_pre
+ '[' '' = start_pre ']'
+ start
+ default_start
+ local func=ssd_start
+ case "$supervisor" in
+ ssd_start
+ '[' -z /usr/sbin/amavisd ']'
+ local _background=
+ ebegin 'Starting amavisd'
 * Starting amavisd ...
+ yesno true
+ '[' -z true ']'
+ case "$1" in
+ return 0
+ '[' -z /run/amavisd.pid ']'
+ '[' -n '' ']'
+ _background='--background --make-pidfile'
+ yesno ''
+ '[' -z '' ']'
+ return 1
+ '[' -n '' ']'
+ '[' -n '' ']'
+ eval start-stop-daemon --start --exec /usr/sbin/amavisd --pidfile /run/amavisd.pid --background --make-pidfile -- foreground
++ start-stop-daemon --start --exec /usr/sbin/amavisd --pidfile /run/amavisd.pid --background --make-pidfile -- foreground
+ eend 0 'Failed to start amavisd'                                                                            [ ok ]
+ service_set_value command /usr/sbin/amavisd
+ '[' -n '' ']'
+ '[' -n /run/amavisd.pid ']'
+ service_set_value pidfile /run/amavisd.pid
+ '[' -n '' ']'
+ return 0
++ command -v start_post
+ '[' '' = start_post ']'
++ command -v cgroup_cleanup
+ '[' cgroup_cleanup = cgroup_cleanup ']'
+ '[' start = stop ']'
++ command -v cgroup2_remove
+ '[' cgroup2_remove = cgroup2_remove ']'
+ '[' start = stop ']'
+ '[' -z /usr/sbin/amavisd ']'
+ shift
+ continue 2
+ '[' -n '' ']'
+ exit 0
Comment 5 Alexander Wetzel 2022-04-05 07:54:49 UTC
(In reply to Joakim from comment #2)
> This issue was originally brought up in the forum:
> 
> https://forums.gentoo.org/viewtopic-t-1147509-start-0-postdays-0-postorder-
> asc-highlight-.html
> 
> were user deagol suggested that " commenting out line 2238 from
> /usr/sbin/amavisd
> 
> elsif ($! != 0)  { die "Error reading config file \"$config_file\": $!" }"
> 
> and changing it to
> 
> "elsif "0 != 0""
> 
> solves the problem, but doubtful that's the real fix.

Please don't use that as a fix. That was a debug step to nail down the issue.
But when this works for you the correct fix must be:
  chgrp amavis /etc/amavisd.conf
  chmod 0640 /etc/amavisd.conf

Some remarks and ideas I did not bother to really follow up on:
It looks like the startup procedure changed somewhat in amavisd-new-2.12.2.
Older versions were able to read /etc/amavisd.conf owned and only readable by root. For new installations these permissions are set automatically. I'm pretty sure that was not the case back in 2014, when I installed amavisd.

Looks like up to 2.12.2 amavisd-new was still running as root when the config file was parsed and the "wrong" permissions were ok. Starting with 2.12.2 root gets dropped prior to parsing the config files and installations with the wrong permissions get issues.
Not nice but I would not rate that as a bug.
The bug here is, that for some reasons the correct error message is not printed out:
  Error reading config file /etc/amavisd.conf
Looks like the intend of the check I commented out for testing is to write out that statement. But for some reasons it's not working.
Comment 6 Alexander Wetzel 2022-04-05 08:30:44 UTC
(In reply to Alexander Wetzel from comment #5)

> The bug here is, that for some reasons the correct error message is not
> printed out:
>   Error reading config file /etc/amavisd.conf
> Looks like the intend of the check I commented out for testing is to write
> out that statement. But for some reasons it's not working.

One correction: amavisd is printing out the message.
Would be nice to get that on the screen when starting the service but also hardly a bug.
Comment 7 Joakim 2022-04-05 10:05:08 UTC
(In reply to Alexander Wetzel from comment #5)
> (In reply to Joakim from comment #2)
> > This issue was originally brought up in the forum:
> > 
> > https://forums.gentoo.org/viewtopic-t-1147509-start-0-postdays-0-postorder-
> > asc-highlight-.html
> > 
> > were user deagol suggested that " commenting out line 2238 from
> > /usr/sbin/amavisd
> > 
> > elsif ($! != 0)  { die "Error reading config file \"$config_file\": $!" }"
> > 
> > and changing it to
> > 
> > "elsif "0 != 0""
> > 
> > solves the problem, but doubtful that's the real fix.
> 
> Please don't use that as a fix. That was a debug step to nail down the issue.
> But when this works for you the correct fix must be:
>   chgrp amavis /etc/amavisd.conf
>   chmod 0640 /etc/amavisd.conf
> 

I was just testing the "fix" to see if it made any difference - it didn't.
Comment 8 Joakim 2022-04-05 10:17:59 UTC
(In reply to Alexander Wetzel from comment #6)
> (In reply to Alexander Wetzel from comment #5)
> 
> > The bug here is, that for some reasons the correct error message is not
> > printed out:
> >   Error reading config file /etc/amavisd.conf
> > Looks like the intend of the check I commented out for testing is to write
> > out that statement. But for some reasons it's not working.
> 
> One correction: amavisd is printing out the message.
> Would be nice to get that on the screen when starting the service but also
> hardly a bug.

Is the issue really the amavisd.conf file? E.g. in the debug output above, it's not included so does it even try to read it at all? If not that could be the reason no error message is produced, and no adding to the log file, because we simply don't get that far. Just brain storming here...

What sticks out to me is that it creates a pid but no process, but I have no clue how to debug such thing. In fact I don't know how I can test if it even starts to process /usr/sbin/amavisd
Comment 9 Joakim 2022-04-05 11:48:12 UTC
Ok I am trying to take another approach to this by looking at the time stamp in the mail queue (using webmin) for the first email rejected by postfix w/ 

"delivery temporarily suspended: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused"
 and 
"connect to 127.0.0.1[127.0.0.1]:10024: Connection refused" 

that's the 2 error messages that shows up in the mail log, but it's from postfix and I know that's because amasivd isn't running.

But looking at these timestamps and also checking in the emerge.log file I have reached the somewhat embarrassing conclusion that this may not be a bug in amavis after all. Indeed, amavisd-new-2.12.2 was first installed om 3 March and this issue started in the evening on the 31 March. I have then emerged it again only after that date. Fact remains though, emails are not delivered but queued up due to amavisd not starting/running.

I will dig deeper in the historic data to see if I can come up with a suspect, well basically dig out what was emerged ahead of mail deliveries stopped. So please don't close this bug just yet.
Comment 10 Joakim 2022-04-08 01:23:13 UTC
I have now updated the server, now running kernel 4.19.237 and also migrated to profile 17.1 (default) and recompiled everything - but it has changed nothing. amavisd still refuses to start, still no process but a pid file is left behind. I don't know if this can be seen as proof that there was a process for a fraction of a second that created that file or not. If so, that at least a sign it tries, but no log entry or clue to why it dies.

merc ~ # /etc/init.d/amavisd start
 * Starting amavisd ...                                                                           [ ok ]
merc ~ # /etc/init.d/amavisd status
 * status: crashed
merc ~ # /etc/init.d/amavisd restart
 * Stopping amavisd ...
 * start-stop-daemon: no matching processes found                                                 [ ok ]
 * Starting amavisd ...                                                                           [ ok ]


My mail sever has now been "down" for almost a week and mails are purged from the queue, which isn't good at all. So, is it possible to get some help with solving this? Whether it's a amavis bug or not, it has to be a bug/conflict somewhere as it was working and suddenly not, me doing nothing except for emerging updates. I have been through emerge.log and compared timestamps for last emails reaching Inbox and first getting stuck in the mail queue and it appears that the last package updated was glibc-2.35-r2, if that can be of any help. New emerge --info as system changed.

merc ~ # emerge --info
Portage 3.0.30 (python 3.9.12-final-0, default/linux/amd64/17.1, gcc-9.4.1, glibc-2.35-r2, 4.19.237-gentoo x86_64)
=================================================================
System uname: Linux-4.19.237-gentoo-x86_64-Intel-R-_Xeon-R-_CPU_E5450_@_3.00GHz-with-glibc2.35
KiB Mem:    32895064 total,  27365336 free
KiB Swap:    5011452 total,   5011452 free
Timestamp of repository gentoo: Thu, 07 Apr 2022 19:00:01 +0000
Head commit of repository gentoo: f5e1e0856c8c0fd62343a53590e2f29266a85d54
Timestamp of repository vmacs: Fri, 01 Apr 2022 15:37:41 +0000
Head commit of repository vmacs: 222be45278d8dcfc78f3c23b681a6be8c827fe3d

sh bash 5.1_p16
ld GNU ld (Gentoo 2.38 p3) 2.38
app-misc/pax-utils:        1.3.3::gentoo
app-shells/bash:           5.1_p16::gentoo
dev-lang/perl:             5.34.1::gentoo
dev-lang/python:           3.8.13::gentoo, 3.9.12::gentoo
dev-util/cmake:            3.23.0::gentoo
dev-util/meson:            0.61.4-r2::gentoo
sys-apps/baselayout:       2.8::gentoo
sys-apps/openrc:           0.44.10::gentoo
sys-apps/sandbox:          2.29::gentoo
sys-devel/autoconf:        2.71-r1::gentoo
sys-devel/automake:        1.16.5::gentoo
sys-devel/binutils:        2.38-r1::gentoo
sys-devel/binutils-config: 5.4.1::gentoo
sys-devel/gcc:             9.4.1_p20220317::gentoo
sys-devel/gcc-config:      2.5-r1::gentoo
sys-devel/libtool:         2.4.7::gentoo
sys-devel/make:            4.3::gentoo
sys-kernel/linux-headers:  5.17::gentoo (virtual/os-headers)
sys-libs/glibc:            2.35-r2::gentoo
Repositories:

gentoo
    location: /usr/portage
    sync-type: rsync
    sync-uri: rsync://rsync.gentoo.org/gentoo-portage
    priority: -1000
    sync-rsync-verify-jobs: 1
    sync-rsync-verify-metamanifest: yes
    sync-rsync-extra-opts:
    sync-rsync-verify-max-age: 24

vmacs
    location: /var/db/repos/vmacs
    sync-type: git
    sync-uri: https://github.com/gentoo-mirror/vmacs.git
    masters: gentoo

x-portage
    location: /usr/local/portage
    masters: gentoo
    priority: 0

ACCEPT_KEYWORDS="amd64 ~amd64"
ACCEPT_LICENSE="* -@EULA"
CBUILD="x86_64-pc-linux-gnu"
CFLAGS="-march=native -O2 -pipe"
CHOST="x86_64-pc-linux-gnu"
CONFIG_PROTECT="/etc /usr/share/gnupg/qualified.txt"
CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/env.d /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/php/apache2-php7.4/ext-active/ /etc/php/cgi-php7.4/ext-active/ /etc/php/cli-php7.4/ext-active/ /etc/php/fpm-php7.4/ext-active/ /etc/php/phpdbg-php7.4/ext-active/ /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo"
CXXFLAGS="-march=native -O2 -pipe"
DISTDIR="/usr/portage/distfiles"
ENV_UNSET="CARGO_HOME DBUS_SESSION_BUS_ADDRESS DISPLAY GOBIN GOPATH PERL5LIB PERL5OPT PERLPREFIX PERL_CORE PERL_MB_OPT PERL_MM_OPT XAUTHORITY XDG_CACHE_HOME XDG_CONFIG_HOME XDG_DATA_HOME XDG_RUNTIME_DIR"
FCFLAGS="-O2 -pipe"
FEATURES="assume-digests binpkg-docompress binpkg-dostrip binpkg-logs buildpkg-live config-protect-if-modified distlocks ebuild-locks fixlafiles ipc-sandbox merge-sync multilib-strict network-sandbox news parallel-fetch pid-sandbox preserve-libs protect-owned qa-unresolved-soname-deps sandbox sfperms strict unknown-features-warn unmerge-logs unmerge-orphans userfetch userpriv usersandbox usersync xattr"
FFLAGS="-O2 -pipe"
GENTOO_MIRRORS="http://gentoo.supp.name/ http://ftp.fi.muni.cz/pub/linux/gentoo/ rsync://ftp.fi.muni.cz/pub/linux/gentoo/ ftp://ftp.fi.muni.cz/pub/linux/gentoo/ http://mirror.dkm.cz/gentoo/ rsync://mirror.dkm.cz/gentoo/ ftp://mirror.dkm.cz/gentoo/ https://mirror.dkm.cz/gentoo/ ftp://gentoo.mirror.web4u.cz/ http://gentoo.mirror.web4u.cz/"
LANG="en_US"
LDFLAGS="-Wl,-O1 -Wl,--as-needed"
MAKEOPTS="-j9"
PKGDIR="/usr/portage/packages"
PORTAGE_CONFIGROOT="/"
PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --omit-dir-times --compress --force --whole-file --delete --stats --human-readable --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages --exclude=/.git"
PORTAGE_TMPDIR="/var/tmp"
SHELL="/bin/bash"
USE="acl amd64 apache2 bzip2 cli crypt dovecot-sasl dri fontconfig fortran fpm gd gdbm gnutls highlight iconv ithreads jpeg json libglvnd libtirpc logrotate multilib mysql ncurses nls nptl openmp openssl pam pcre png python readline seccomp sftp split-usr ssl subversion threads truetype unicode urandom vhosts xattr zlib" ABI_X86="64" ADA_TARGET="gnat_2020" APACHE2_MODULES="unique_id alias auth_basic authn_core authz_core auth_digest authn_file authz_groupfile authz_host authz_user cgid deflate dir expires filter headers http2 imagemap log_config logio mem_cache mime proxy proxy_fcgi rewrite setenvif so socache_shmcb status unixd" APACHE2_MPMS="event" CALLIGRA_FEATURES="karbon sheets words" COLLECTD_PLUGINS="df interface irq load memory rrdtool swap syslog" CPU_FLAGS_X86="mmx sse sse2" ELIBC="glibc" GPSD_PROTOCOLS="ashtech aivdm earthmate evermore fv18 garmin garmintxt gpsclock greis isync itrax mtk3301 nmea ntrip navcom oceanserver oldstyle oncore rtcm104v2 rtcm104v3 sirf skytraq superstar2 timing tsip tripmate tnt ublox ubx" INPUT_DEVICES="libinput" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LIBREOFFICE_EXTENSIONS="presenter-console presenter-minimizer" LUA_SINGLE_TARGET="lua5-1" LUA_TARGETS="lua5-1" OFFICE_IMPLEMENTATION="libreoffice" PHP_TARGETS="php7-4" POSTGRES_TARGETS="postgres12 postgres13" PYTHON_SINGLE_TARGET="python3_9" PYTHON_TARGETS="python3_9" RUBY_TARGETS="ruby26 ruby27" USERLAND="GNU" VIDEO_CARDS="amdgpu fbdev intel nouveau radeon radeonsi vesa dummy v4l" XTABLES_ADDONS="quota2 psd pknock lscan length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq proto steal rawnat logmark ipmark dhcpmac delude chaos account"
Unset:  ADDR2LINE, AR, ARFLAGS, AS, ASFLAGS, CC, CCLD, CONFIG_SHELL, CPP, CPPFLAGS, CTARGET, CXX, CXXFILT, ELFEDIT, EMERGE_DEFAULT_OPTS, EXTRA_ECONF, F77FLAGS, FC, GCOV, GPROF, INSTALL_MASK, LC_ALL, LD, LEX, LFLAGS, LIBTOOL, LINGUAS, MAKE, MAKEFLAGS, NM, OBJCOPY, OBJDUMP, PORTAGE_BINHOST, PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS, RANLIB, READELF, RUSTFLAGS, SIZE, STRINGS, STRIP, YACC, YFLAGS
Comment 11 Sam James archtester Gentoo Infrastructure gentoo-dev Security 2022-04-08 01:32:36 UTC
We tend to do user support on forums/IRC/the gentoo-user ML. It's possible the amavsid-new maintainer can help you but I suggest asking in #gentoo about the generic error and seeing if folks can help you get some more useful output at least.
Comment 12 Joakim 2022-04-08 08:00:09 UTC
(In reply to Sam James from comment #11)
> We tend to do user support on forums/IRC/the gentoo-user ML. It's possible
> the amavsid-new maintainer can help you but I suggest asking in #gentoo
> about the generic error and seeing if folks can help you get some more
> useful output at least.

So, in other words you are saying this isn't a bug. I been to the forum with this but maybe I made a mistake joining an ongoing (and apparently solved) issue as I had the same, well same output from postfix (due to missing amavisd). It's now clear to me that isn't the case. Obviously, the gentoo-user ML isn't an option for me and I'm too slow for IRC :-) so I will try the forum again opening my own topic.
Comment 13 Joakim 2022-04-08 08:50:52 UTC
Actually, I got some more useful output by bypassing the start script and run amavisd directly - why didn't I think of this before. 

Anyway, it gave me this:
Error in config file "/etc/amavisd.conf": Can't open PEM file /var/db/dkim/astrocalc-com.key.pem: Permission denied at /usr/sbin/amavisd line 639.

So from what I can understand, something external must have changed here related to this. Not quite sure what yet, but I will take it to the forums as I see now that this most likely isn't an amavisd bug. I just wanted to document it here, in case someone else looking for answers ending up here.
Comment 14 Joakim 2022-04-08 09:48:59 UTC
Maybe I closed this prematurely or well, I don't know but after commenting out this code in /etc/amavis.conf:

#$enable_dkim_verification = 1;  # enable DKIM signatures verification
#$enable_dkim_signing = 1;    # load DKIM signing code, keys defined by dkim_key

#dkim_key('astrocalc.com', 'mydkim',  '/var/db/dkim/astrocalc-com.key.pem', k=>'rsa');

amavisd now starts properly and the mails are flowing again. I will continue to investigate this on my own, but meanwhile I'm reopening this bug again as I think this now is more than a generic error.

So not sure what's happening here, but the PEM files are owned "root:root", which I think is as it should be, but obviously amavisd doesn't have privilege enough when it comes to read these files. That's how I understand it atm anyway.

As I reopen this it may also be proper to change the bug titel to something like "amavisd-2.12.2 is not able to read dkim key files due to permission privilege"
Comment 15 Ralph Seichter 2022-04-08 12:44:55 UTC
Chiming in as both the ebuild maintainer and as an amavisd developer team member.

I had no time to look at this report earlier, but amavisd being unable to access a DKIM key file which was explicitly defined in the dkim_key() array is definitely not a bug, neither of amavisd itself nor of the Gentoo ebuild. Both amavisd.conf and DKIM keys are only ever read (not written) by the amavisd processes, so whatever changed/set the wrong permissions is out of scope.

Closing the ticket.