Amavisd is not starting Can't open PID

Discussion in 'Installation/Configuration' started by Zague, Sep 27, 2022.

  1. Zague

    Zague Member

    Hello guys;
    This morning my server running Centos 7.9 and ISPConfig Version: 3.2.8p1 had amavisd daemon down with this message
    Code:
    Sep 27 09:54:06 mxserver4 systemd: Starting Amavis mail content checker...
    Sep 27 09:54:07 mxserver4 systemd: Can't open PID file /run/amavisd/amavisd.pid (yet?) after start: No such file or directory
    Sep 27 09:54:07 mxserver4 systemd: Daemon never wrote its PID file. Failing.
    Sep 27 09:54:07 mxserver4 systemd: Failed to start Amavis mail content checker.
    Sep 27 09:54:07 mxserver4 systemd: Unit amavisd.service entered failed state.
    Sep 27 09:54:07 mxserver4 systemd: amavisd.service failed.
    Sep 27 09:54:08 mxserver4 systemd: amavisd.service holdoff time over, scheduling restart.
    Sep 27 09:54:08 mxserver4 systemd: Stopped Amavis mail content checker.
    Sep 27 09:54:08 mxserver4 systemd: start request repeated too quickly for amavisd.service
    Sep 27 09:54:08 mxserver4 systemd: Failed to start Amavis mail content checker.
    Sep 27 09:54:08 mxserver4 systemd: Unit amavisd.service entered failed state.
    Sep 27 09:54:08 mxserver4 systemd: amavisd.service failed.
    The path of the file exist:
    Code:
    ls -alF /run/|grep amavisd
    drwxr-xr-x   2 amavis   amavis       40 Sep 27 09:54 amavisd/
    drwxrwx---   2 amavis   clamupdate   80 Sep 27 09:54 clamd.amavisd/
    Also I have tried to run amavis in debug mode, then I got:
    Code:
    # amavisd -c /etc/amavisd/amavisd.conf debug
    Sep 27 10:21:15.882  /sbin/amavisd[5284]: logging initialized, log level 0, syslog: amavis.mail
    Sep 27 10:21:15.882  /sbin/amavisd[5284]: sd_notify (no socket): STATUS=Config files have been read, modules loaded.
    Sep 27 10:21:15.883  /sbin/amavisd[5284]: starting. /sbin/amavisd at  amavisd-new-2.12.0 (20190725), Unicode aware, LC_ALL="C", LANG="en_US.UTF-8", LC_TIME="es_MX.UTF-8"
    Sep 27 10:21:15.883  /sbin/amavisd[5284]: perl=5.016003, user=, EUID: 993 (993);  group=, EGID: 990 990 (990 990)
    Sep 27 10:21:15.954  /sbin/amavisd[5284]: INFO: no optional modules: unicore::lib::Nt::De.pl Unix::Getrusage
    Sep 27 10:21:15.954  /sbin/amavisd[5284]: SpamControl: attempting to load scanner SpamAssassin, module Amavis::SpamControl::SpamAssassin
    Sep 27 10:21:15.954  /sbin/amavisd[5284]: SpamControl: scanner SpamAssassin, module Amavis::SpamControl::SpamAssassin
    Sep 27 10:21:16.232  /sbin/amavisd[5284]: INFO: SA version: 3.4.0, 3.004000, no optional modules: Net::CIDR::Lite Image::Info Image::Info::GIF Image::Info::JPEG Image::Info::PNG Image::Info::BMP Image::Info::TIFF
    Sep 27 10:21:16.232  /sbin/amavisd[5284]: SpamControl: init_pre_chroot on SpamAssassin done
    Sep 27 10:21:16.232  /sbin/amavisd[5284]: socket module IO::Socket::IP, protocol families available: INET, INET6
    Sep 27 10:21:16.233  /sbin/amavisd[5284]: will bind to /var/spool/amavisd/amavisd.sock|unix, 127.0.0.1:10024/tcp, [::1]:10024/tcp, 127.0.0.1:10026/tcp, [::1]:10026/tcp
    Sep 27 10:21:16.233  /sbin/amavisd[5284]: sd_notify (no socket): STATUS=Transferring control to Net::Server.
    Sep 27 10:21:16.234  /sbin/amavisd[5284]: sd_notify (no socket): STATUS=Preparing to bind sockets.
    Sep 27 10:21:16.234  /sbin/amavisd[5284]: Net::Server: 2022/09/27-10:21:16 Amavis (type Net::Server::PreForkSimple) starting! pid(5284)
    Sep 27 10:21:16.238  /sbin/amavisd[5284]: Net::Server: Binding to UNIX socket file "/var/spool/amavisd/amavisd.sock"
    Sep 27 10:21:16.238  /sbin/amavisd[5284]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1 with IPv4
    Sep 27 10:21:16.239  /sbin/amavisd[5284]: Net::Server: Binding to TCP port 10024 on host ::1 with IPv6
    Sep 27 10:21:16.239  /sbin/amavisd[5284]: (!)Net::Server: 2022/09/27-10:21:16 Can't connect to TCP port 10024 on ::1 [Cannot assign requested address]\n  at line 68 in file /usr/share/perl5/vendor_perl/Net/Server/Proto/TCP.pm
    Sep 27 10:21:16.239  /sbin/amavisd[5284]: sd_notify (no socket): STOPPING=1\nSTATUS=Server rundown, notifying child processes.
    Sep 27 10:21:16.239  /sbin/amavisd[5284]: Net::Server: 2022/09/27-10:21:16 Server closing!
    Sep 27 10:21:16.239  /sbin/amavisd[5284]: sd_notify (no socket): STATUS=Child processes have been stopped.
    I sent command netstat -tulpn|grep 10024 to see if something was using 10024 port, but nothing is binding on it
    it seems that daemon is not writing the pid file.
    Any ideas?
    Thank you very much for your time
     
    Last edited: Sep 27, 2022
  2. till

    till Super Moderator Staff Member ISPConfig Developer

    The server was working fine before? Did it happen after a reboot?
     
  3. Zague

    Zague Member

    Hello I found the issue and the fix.
    The issue was the amavis was not able to bind 10024 to ipv6 interface (
    Net::Server: 2022/09/27-10:21:16 Can't connect to TCP port 10024 on ::1)
    to fix it I have added this line $inet_socket_bind = '127.0.0.1'; to /etc/amavisd/amavisd.conf
    restart amavis service and it works
     
    till likes this.
  4. Zague

    Zague Member

    Till it was working before and I have tried reboot, checking with my team, the ipv6 was enable yesterday and I didn't know.
    Thanks to log and google research I was able to fix it.
    Thank you for your time Till.
     

Share This Page