Amavisd crashes immediately on start with little in the logs

Recently I was updating amavisd and other portions of the mail stack on one of my mail servers (running Gentoo Linux). This particular set of updates didn’t go as smoothly as I would have liked primarily due to the acct-user/amavis package being created on Thursday, 13 February 2020 as a part of the ongoing effort to standardise user accounts used within applications. Some other problems with the upgrade of amavisd (to version 2.12.0-r1) and the mail stack were that some dependencies were erroneously removed from the ebuild (bug 710842) and (though not directly related) permissions within the new amavis user’s home directory being inadequate for ClamAV to successfully run. I will address these problems and their respective fixes below.

Missing dependencies in 2.12.0-r1 (bug 710842)

Some of the Perl modules (since amavisd-new is written in Perl) were erroneously removed from the dependency list in version 2.12.0-r1. The fix here was to simply reinstall the modules manually, which in my case entailed:

emerge -av MIME-tools Net-Server Mail-DKIM MailTools Net-LibIDN

However, my situation required one additional module that wasn’t mentioned in the bug, and was discovered when trying to manually start amavisd because of this error message:

# /usr/sbin/amavisd
Problem in Amavis::Unpackers code: Can't locate Archive/Zip.pm in @INC (you may need to install the Archive::Zip module) (@INC contains: /etc/perl /usr/local/lib64/perl5/5.30.1/x86_64-linux /usr/local/lib64/perl5/5.30.1 /usr/lib64/perl5/vendor_perl/5.30.1/x86_64-linux /usr/lib64/perl5/vendor_perl/5.30.1 /usr/local/lib64/perl5 /usr/lib64/perl5/vendor_perl/5.30.0/x86_64-linux /usr/lib64/perl5/vendor_perl/5.30.0 /usr/lib64/perl5/vendor_perl/5.28.0 /usr/lib64/perl5/vendor_perl/5.26.2 /usr/lib64/perl5/vendor_perl/5.26.1 /usr/lib64/perl5/vendor_perl/5.24.0 /usr/lib64/perl5/vendor_perl /usr/lib64/perl5/5.30.1/x86_64-linux /usr/lib64/perl5/5.30.1) at (eval 101) line 47.
BEGIN failed--compilation aborted at (eval 101) line 47.

That one was also simple enough to solve by installing dev-perl/Archive-Zip:

emerge -av dev-perl/Archive-Zip

Fortunately, this ‘missing dependencies’ problem was fixed with version 2.12.0-r2.

Changes in the ‘amavis’ user’s home directory

With the addition of the acct-user/amavis package, a few things changes about the default setup for the ‘amavis’ user. When installing that package, Portage warns about some steps that need to be implemented in order to make amavis work again after migrating its home directory from /var/amavis/ to /var/lib/amavishome. Even after following those steps, I saw the following error message when starting amavis:

Feb 27 00:08:31 [amavis] socket module IO::Socket::IP, protocol families available: INET, INET6
Feb 27 00:08:31 [amavis] will bind to /var/amavis/amavisd.sock|unix, 127.0.0.1:10024/tcp, [::1]:10024/tcp
Feb 27 00:08:31 [amavis] sd_notify (no socket): STATUS=Transferring control to Net::Server.
Feb 27 00:08:31 [amavis] sd_notify (no socket): STATUS=Preparing to bind sockets.
Feb 27 00:08:31 [amavis] Net::Server: 2020/02/27-00:08:31 Amavis (type Net::Server::PreForkSimple) starting! pid(1738)
Feb 27 00:08:31 [amavis] Net::Server: Binding to UNIX socket file "/var/amavis/amavisd.sock"
Feb 27 00:08:31 [amavis] (!)Net::Server: 2020/02/27-00:08:31 Can't connect to UNIX socket at file /var/amavis/amavisd.sock [No such file or directory]\n  at line 66 in file /usr/lib64/perl5/vendor_perl/5.30.1/Net/Server/Proto/UNIX.pm
Feb 27 00:08:31 [amavis] sd_notify (no socket): STOPPING=1\nSTATUS=Server rundown, notifying child processes.
Feb 27 00:08:31 [amavis] Net::Server: 2020/02/27-00:08:31 Server closing!
Feb 27 00:08:31 [amavis] sd_notify (no socket): STATUS=Child processes have been stopped.

In that error message, I noticed that there were still references to /var/amavis/ instead of the new /var/lib/amavishome/ directory, so I updated it using the $MYHOME variable in /etc/amavisd.conf:

# grep -e '^$MYHOME' /etc/amavisd.conf 
$MYHOME = '/var/lib/amavishome';   # a convenient default for other settings, -H

Thereafter, the start-up logs indicated that it was binding to a UNIX socket in the correct home directory:

Feb 27 00:12:15 [amavis] socket module IO::Socket::IP, protocol families available: INET, INET6
Feb 27 00:12:15 [amavis] will bind to /var/lib/amavishome/amavisd.sock|unix, 127.0.0.1:10024/tcp, [::1]:10024/tcp
Feb 27 00:12:15 [amavis] sd_notify (no socket): STATUS=Transferring control to Net::Server.
Feb 27 00:12:15 [amavis] sd_notify (no socket): STATUS=Preparing to bind sockets.
Feb 27 00:12:15 [amavis] Net::Server: 2020/02/27-00:12:15 Amavis (type Net::Server::PreForkSimple) starting! pid(1952)
Feb 27 00:12:15 [amavis] Net::Server: Binding to UNIX socket file "/var/lib/amavishome/amavisd.sock"
Feb 27 00:12:15 [amavis] Net::Server: Binding to TCP port 10024 on host 127.0.0.1 with IPv4
Feb 27 00:12:15 [amavis] Net::Server: Binding to TCP port 10024 on host ::1 with IPv6

ClamAV permissions within the amavis home directory:

Though this error wasn’t directly related to the upgrades (and had likely existed for quite some time beforehand), I only just now noticed it whilst combing through the logs (the first error is from my system’s mail log, and the second error is from the clamd log):

Feb 27 00:15:10 [amavis] (01980-01) run_av (ClamAV-clamd) result: /var/lib/amavishome/tmp/amavis-20200227T001510-01980-zrKbp28h/parts: lstat() failed: Permission denied. ERROR\n
Feb 27 00:15:10 [amavis] (01980-01) (!)run_av (ClamAV-clamd) FAILED - unexpected , output="/var/lib/amavishome/tmp/amavis-20200227T001510-01980-zrKbp28h/parts: lstat() failed: Permission denied. ERROR\n"
Feb 27 00:15:10 [amavis] (01980-01) (!)ClamAV-clamd av-scanner FAILED: CODE(0x5611198fa5d8) unexpected , output="/var/lib/amavishome/tmp/amavis-20200227T001510-01980-zrKbp28h/parts: lstat() failed: Permission denied. ERROR\n" at (eval 85) line 951.
# grep 'lstat' /var/log/clamav/clamd.log
Wed Feb 26 23:26:53 2020 -> WARNING: lstat() failed on: /var/amavis/tmp/amavis-20200226T180007-00529-S1gbY8cd/parts
Wed Feb 26 23:28:32 2020 -> WARNING: lstat() failed on: /var/amavis/tmp/amavis-20200226T180038-00592-FK2_Uj2T/parts
Wed Feb 26 23:31:30 2020 -> WARNING: lstat() failed on: /var/amavis/tmp/amavis-20200226T165427-32346-V4WeP0YX/parts
Thu Feb 27 00:15:10 2020 -> WARNING: lstat() failed on: /var/lib/amavishome/tmp/amavis-20200227T001510-01980-zrKbp28h/parts
Thu Feb 27 00:26:21 2020 -> WARNING: lstat() failed on: /var/lib/amavishome/tmp/amavis-20200227T002621-01981-l36mWT4P/parts
Thu Feb 27 00:26:30 2020 -> WARNING: lstat() failed on: /var/lib/amavishome/tmp/amavis-20200227T002630-01982-k0qgJdjl/parts
Thu Feb 27 00:29:12 2020 -> WARNING: lstat() failed on: /var/lib/amavishome/tmp/amavis-20200227T002912-01983-G57aKCmK/parts
Thu Feb 27 00:31:55 2020 -> WARNING: lstat() failed on: /var/lib/amavishome/tmp/amavis-20200227T003155-01984-M9r9r1Gc/parts
Thu Feb 27 00:33:07 2020 -> WARNING: lstat() failed on: /var/lib/amavishome/tmp/amavis-20200227T003307-01985-8n_wS6pQ/parts
Thu Feb 27 00:40:20 2020 -> WARNING: lstat() failed on: /var/lib/amavishome/tmp/amavis-20200227T004020-01986-gH4PrFAk/parts
Thu Feb 27 00:45:45 2020 -> WARNING: lstat() failed on: /var/lib/amavishome/tmp/amavis-20200227T004545-01987-J4YGuNbw/parts

These errors were fixed by 1) adding the ‘clamav’ user to the ‘amavis’ group, 2) setting g+w permissions on the /var/lib/amavishome/tmp/ directory, and 3) restarting clamd and amavisd

# gpasswd -a clamav amavis
Adding user clamav to group amavis

# ls -alh /var/lib/amavishome/ | grep tmp
drwxr-xr-x 141 amavis amavis  12K Feb 27 00:46 tmp

# chmod 775 /var/lib/amavishome/tmp

# ls -alh /var/lib/amavishome/ | grep tmp
drwxrwxr-x 141 amavis amavis  12K Feb 27 00:46 tmp

# /etc/init.d/clamd restart && /etc/init.d/amavisd restart

Now ClamAV is readily able to access files under /var/lib/amavishome/tmp/:

Feb 27 01:00:12 [amavis] (03346-01) ClamAV-clamd: Connecting to socket  /var/run/clamav/clamd.sock
Feb 27 01:00:12 [amavis] (03346-01) new socket by IO::Socket::UNIX to /var/run/clamav/clamd.sock, timeout set to 10
Feb 27 01:00:12 [amavis] (03346-01) connected to /var/run/clamav/clamd.sock successfully
Feb 27 01:00:12 [amavis] (03346-01) ClamAV-clamd: Sending CONTSCAN /var/lib/amavishome/tmp/amavis-20200227T010012-03346-YjbUpYOk/parts\n to socket /var/run/clamav/clamd.sock

Hopefully, if you run into these errors, you will be able to take this information and apply it to your particular mail stack.

Cheers,

Zach

Vim pulling in xorg dependencies in Gentoo

Today I went to update one of my Gentoo servers, and noticed that it wanted to pull in a bunch of xorg dependencies. This is a simple music server without any type of graphical environment, so I don’t really want any xorg libraries or other GUI components installed. Looking through the full output, I couldn’t see a direct reason that these components were now requirements.

To troubleshoot, I started adding packages to /etc/portage/package.mask, starting with cairo (which was the package directly requesting the ‘X’ USE flag be enabled). That didn’t get me very far as it still just indicated that GTK+ needed to be installed. After following the dependency chain for a bit, I noticed that something was pulling in libcanberra and found that the default USE flags now include ‘sound’ and that vim now had it enabled. It looks like this USE flag was added between vim-8.1.1486 and vim-8.1.1846.

For my needs, the most straightforward solution was to just remove the ‘sound’ USE flag from vim by adding the following to /etc/portage/package.use:

# grep vim /etc/portage/package.use 
app-editors/vim -sound

Adobe Flash and Firefox 68+ in Gentoo Linux

Though many sites have abandoned Adobe Flash in favour of HTML5 these days, there are still some legacy applications (e.g. older versions of VMWare’s vSphere web client) that depend on it. Recent versions of Firefox in Linux (68+) started failing to load Flash content for me, and it took some digging to find out why. First off, I noticed that the content wouldn’t load even on Adobe’s Flash test page. Second off, I found that the plugin wasn’t listed in Firefox’s about:plugins page.

So, I realised that the problem was due to the Adobe Flash plugin not integrating properly with Firefox. I use Gentoo Linux, so these instructions may not directly apply to other distributions, but I would imagine that the directory structures are at least similar. To start, I made sure that I had installed the www-plugins/adobe-flash ebuild with the ‘npapi’ USE flag enabled:

$ eix adobe-flash
[I] www-plugins/adobe-flash
     Available versions:  (22) 32.0.0.238^ms
       {+nsplugin +ppapi ABI_MIPS="n32 n64 o32" ABI_RISCV="lp64 lp64d" ABI_S390="32 64" ABI_X86="32 64 x32"}
     Installed versions:  32.0.0.238(22)^ms(03:13:05 22/08/19)(nsplugin -ppapi ABI_MIPS="-n32 -n64 -o32" ABI_RISCV="-lp64 -lp64d" ABI_S390="-32 -64" ABI_X86="64 -32 -x32")
     Homepage:            https://www.adobe.com/products/flashplayer.html https://get.adobe.com/flashplayer/ https://helpx.adobe.com/security/products/flash-player.html
     Description:         Adobe Flash Player

That ebuild installs the libflashplayer.so (shared object) in the /usr/lib64/nsbrowser/plugins/ directory by default.

However, through some digging, I found that Firefox 68+ was looking in another directory for the plugin (in my particular situation, that directory was /usr/lib64/mozilla/plugins/, which actually didn’t exist on my system). Seeing as the target directory didn’t exist, I had to firstly create it, and then I decided to symlink the shared object there so that future updates to the www-plugins/adobe-flash package would work without any further manual intervention:

mkdir -p /usr/lib64/mozilla/plugins/
cd $_
ln -s /usr/lib64/nsbrowser/plugins/libflashplayer.so .

After restarting Firefox, the Adobe Flash test page started working as did other sites that use Flash. So, though your particular Linux distribution, version of Firefox, and version of Adobe Flash may require the use of different directories than the ones I referenced above, I hope that these instructions can help you troubleshoot the problem with Adobe Flash not showing in the Firefox about:plugins page.