Skip to content

Amavis socket permissions error #1146

Closed
Closed
Amavis socket permissions error#1146
Labels
service/security/amavis
@jakehamilton

Description

@jakehamilton
jakehamilton
opened on Mar 22, 2019

The server fails to start up because there seems to be some permissions issues with /var/lib/amavis/amavisd.sock. It also looks like postfix runs into errors with its lock file as well.

Context

I was trying to spin up an instance of the mail server, but am unable to because of these errors.

It should be noted that the issue with amavisd.sock still occurs when ENABLE_CLAMAV=0.

Seemingly permissions based, but you never know. Here is an excerpt from the logs:

Service Log 
o1rvi6r Mar 22 13:41:22 77fe137209c3 amavis[8242]: (!)Net::Server: 2019/03/22-13:41:22 Can't connect to UNIX socket at file /var/lib/amavis/amavisd.sock [Permission denied]\n at line 70 in file /usr/share/perl5/Net/Server/Proto/UNIX.pm
o1rvi6r 2019-03-22 13:41:22,669 INFO spawned: 'clamav' with pid 8412
o1rvi6r 2019-03-22 13:41:22,730 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:22,737 INFO exited: clamav (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:23,488 INFO spawned: 'clamav' with pid 8537
o1rvi6r 2019-03-22 13:41:23,490 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:23,491 INFO exited: amavis (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:23,526 INFO spawned: 'amavis' with pid 8544
o1rvi6r 2019-03-22 13:41:23,529 INFO success: amavis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:23,533 INFO exited: clamav (exit status 1; not expected)
o1rvi6r Mar 22 13:41:23 77fe137209c3 amavis[8397]: starting. /usr/sbin/amavisd-new at intergalactic.dev amavisd-new-2.10.1 (20141025), Unicode aware
o1rvi6r Mar 22 13:41:23 77fe137209c3 amavis[8397]: (!)Net::Server: 2019/03/22-13:41:23 Can't connect to UNIX socket at file /var/lib/amavis/amavisd.sock [Permission denied]\n at line 70 in file /usr/share/perl5/Net/Server/Proto/UNIX.pm
o1rvi6r 2019-03-22 13:41:23,669 INFO spawned: 'clamav' with pid 8568
o1rvi6r 2019-03-22 13:41:23,730 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:23,735 INFO exited: clamav (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:24,612 INFO spawned: 'clamav' with pid 8694
o1rvi6r 2019-03-22 13:41:24,613 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:24,614 INFO exited: amavis (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:24,649 INFO spawned: 'amavis' with pid 8699
o1rvi6r 2019-03-22 13:41:24,657 INFO success: amavis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:24,660 INFO exited: clamav (exit status 1; not expected)
o1rvi6r Mar 22 13:41:24 77fe137209c3 amavis[8544]: starting. /usr/sbin/amavisd-new at intergalactic.dev amavisd-new-2.10.1 (20141025), Unicode aware
o1rvi6r Mar 22 13:41:24 77fe137209c3 amavis[8544]: (!)Net::Server: 2019/03/22-13:41:24 Can't connect to UNIX socket at file /var/lib/amavis/amavisd.sock [Permission denied]\n at line 70 in file /usr/share/perl5/Net/Server/Proto/UNIX.pm
o1rvi6r 2019-03-22 13:41:24,669 INFO spawned: 'clamav' with pid 8702
o1rvi6r 2019-03-22 13:41:24,728 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:24,740 INFO exited: clamav (exit status 1; not expected)
-o1rvi6r 2019-03-22 13:41:25,609 INFO spawned: 'clamav' with pid 8843
o1rvi6r 2019-03-22 13:41:25,611 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:25,612 INFO exited: amavis (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:25,655 INFO spawned: 'amavis' with pid 8850
o1rvi6r 2019-03-22 13:41:25,657 INFO success: amavis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:25,661 INFO exited: clamav (exit status 1; not expected)
o1rvi6r Mar 22 13:41:25 77fe137209c3 amavis[8699]: starting. /usr/sbin/amavisd-new at intergalactic.dev amavisd-new-2.10.1 (20141025), Unicode aware
o1rvi6r Mar 22 13:41:25 77fe137209c3 amavis[8699]: (!)Net::Server: 2019/03/22-13:41:25 Can't connect to UNIX socket at file /var/lib/amavis/amavisd.sock [Permission denied]\n at line 70 in file /usr/share/perl5/Net/Server/Proto/UNIX.pm
o1rvi6r 2019-03-22 13:41:25,669 INFO spawned: 'clamav' with pid 8852
o1rvi6r 2019-03-22 13:41:25,742 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:25,747 INFO exited: clamav (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:26,558 INFO spawned: 'clamav' with pid 8956
o1rvi6r 2019-03-22 13:41:26,613 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:26,616 INFO exited: clamav (exit status 1; not expected)
o1rvi6r Mar 22 13:41:26 77fe137209c3 postfix/master[8954]: fatal: open lock file /var/lib/postfix/master.lock: cannot open file: Permission denied
o1rvi6r 2019-03-22 13:41:26,669 INFO spawned: 'clamav' with pid 8960
o1rvi6r 2019-03-22 13:41:26,718 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:26,721 INFO exited: clamav (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:26,778 INFO spawned: 'clamav' with pid 8961
o1rvi6r 2019-03-22 13:41:26,779 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:26,780 INFO exited: amavis (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:26,803 INFO spawned: 'amavis' with pid 8962
o1rvi6r 2019-03-22 13:41:26,807 INFO success: amavis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:26,807 INFO exited: clamav (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:26,808 INFO spawned: 'clamav' with pid 8963
o1rvi6r 2019-03-22 13:41:26,852 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:26,859 INFO exited: clamav (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:30,199 INFO spawned: 'clamav' with pid 9015

As well, here is the compose file I'm using to deploy the service:

docker-compose.yml 
version: '3.7'

services:
  mail:
    image: tvial/docker-mailserver
    ports:
      - target: 25
        published: 25
        protocol: tcp
        mode: host
      - target: 587
        published: 587
        protocol: tcp
        mode: host
      - target: 993
        published: 993
        protocol: tcp
        mode: host
      - target: 995
        published: 995
        protocol: tcp
        mode: host
    volumes:
      - data:/var/mail
      - state:/var/mail-state
      - config:/tmp/docker-mailserver
      - letsencrypt:/etc/letsencrypt
    environment:
      - ENABLE_CLAMAV=1
      - ONE_DIR=1
      - OVERRIDE_HOSTNAME=example.com
      - OVERRIDE_DOMAINNAME=example.com
      - [email protected]
      - SPOOF_PROTECTION=1
      - PERMIT_DOCKER=network
      - SSL_TYPE=letsencrypt
    networks:
      - internal
    deploy:
      placement:
        constraints:
          - "node.role==worker"

volumes:
  data:
    driver: rexray
  state:
    driver: rexray
  config:
    driver: rexray
  letsencrypt:
    driver: rexray

networks:
  internal:
  proxy:
    external: true

Users, SSL, and DNS have already been configured and I don't think they're the issue. Though, I can provide information on that if we think there's any correlation.

Expected Behavior

Mail server should start given the compose file above.

Actual Behavior

The server fails to start and several processes keep restarting after failing.

Possible Fix

Not sure, but perhaps permission modifications? I tried already making permissions on amavisd.sock more permissive, but had no luck.

Steps to Reproduce

  1. Copy the above docker-compose.yml file, changing the volume drivers to be appropriate for your system (for simplicity, just removing the driver: rexray line is good enough) and either providing certs in the letsencrypt volume or disabling SSL for this example. You can also remove the proxy network as Docker will complain otherwise.
  2. Deploy the service with either docker stack deploy -c ./docker-compose.yml mail or docker-compose up. My experience comes from deploying the stack to a swarm.
  3. Watch the logs on the service (in swarm docker service logs -f mail_mail)

Your Environment

  • Amount of RAM available: 1GB
  • Mailserver version used: latest tag
  • Docker version used: 18.06.1-ce and 18.09.2
  • Environment settings relevant to the config:
environment:
      - ENABLE_CLAMAV=1
      - ONE_DIR=1
      - OVERRIDE_HOSTNAME=example.com
      - OVERRIDE_DOMAINNAME=example.com
      - [email protected]
      - SPOOF_PROTECTION=1
      - PERMIT_DOCKER=network
      - SSL_TYPE=letsencrypt
  • Any relevant stack traces ("Full trace" preferred):
Service Logs 
o1rvi6r Mar 22 13:41:22 77fe137209c3 amavis[8242]: (!)Net::Server: 2019/03/22-13:41:22 Can't connect to UNIX socket at file /var/lib/amavis/amavisd.sock [Permission denied]\n at line 70 in file /usr/share/perl5/Net/Server/Proto/UNIX.pm
o1rvi6r 2019-03-22 13:41:22,669 INFO spawned: 'clamav' with pid 8412
o1rvi6r 2019-03-22 13:41:22,730 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:22,737 INFO exited: clamav (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:23,488 INFO spawned: 'clamav' with pid 8537
o1rvi6r 2019-03-22 13:41:23,490 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:23,491 INFO exited: amavis (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:23,526 INFO spawned: 'amavis' with pid 8544
o1rvi6r 2019-03-22 13:41:23,529 INFO success: amavis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:23,533 INFO exited: clamav (exit status 1; not expected)
o1rvi6r Mar 22 13:41:23 77fe137209c3 amavis[8397]: starting. /usr/sbin/amavisd-new at intergalactic.dev amavisd-new-2.10.1 (20141025), Unicode aware
o1rvi6r Mar 22 13:41:23 77fe137209c3 amavis[8397]: (!)Net::Server: 2019/03/22-13:41:23 Can't connect to UNIX socket at file /var/lib/amavis/amavisd.sock [Permission denied]\n at line 70 in file /usr/share/perl5/Net/Server/Proto/UNIX.pm
o1rvi6r 2019-03-22 13:41:23,669 INFO spawned: 'clamav' with pid 8568
o1rvi6r 2019-03-22 13:41:23,730 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:23,735 INFO exited: clamav (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:24,612 INFO spawned: 'clamav' with pid 8694
o1rvi6r 2019-03-22 13:41:24,613 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:24,614 INFO exited: amavis (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:24,649 INFO spawned: 'amavis' with pid 8699
o1rvi6r 2019-03-22 13:41:24,657 INFO success: amavis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:24,660 INFO exited: clamav (exit status 1; not expected)
o1rvi6r Mar 22 13:41:24 77fe137209c3 amavis[8544]: starting. /usr/sbin/amavisd-new at intergalactic.dev amavisd-new-2.10.1 (20141025), Unicode aware
o1rvi6r Mar 22 13:41:24 77fe137209c3 amavis[8544]: (!)Net::Server: 2019/03/22-13:41:24 Can't connect to UNIX socket at file /var/lib/amavis/amavisd.sock [Permission denied]\n at line 70 in file /usr/share/perl5/Net/Server/Proto/UNIX.pm
o1rvi6r 2019-03-22 13:41:24,669 INFO spawned: 'clamav' with pid 8702
o1rvi6r 2019-03-22 13:41:24,728 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:24,740 INFO exited: clamav (exit status 1; not expected)
-o1rvi6r 2019-03-22 13:41:25,609 INFO spawned: 'clamav' with pid 8843
o1rvi6r 2019-03-22 13:41:25,611 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:25,612 INFO exited: amavis (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:25,655 INFO spawned: 'amavis' with pid 8850
o1rvi6r 2019-03-22 13:41:25,657 INFO success: amavis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:25,661 INFO exited: clamav (exit status 1; not expected)
o1rvi6r Mar 22 13:41:25 77fe137209c3 amavis[8699]: starting. /usr/sbin/amavisd-new at intergalactic.dev amavisd-new-2.10.1 (20141025), Unicode aware
o1rvi6r Mar 22 13:41:25 77fe137209c3 amavis[8699]: (!)Net::Server: 2019/03/22-13:41:25 Can't connect to UNIX socket at file /var/lib/amavis/amavisd.sock [Permission denied]\n at line 70 in file /usr/share/perl5/Net/Server/Proto/UNIX.pm
o1rvi6r 2019-03-22 13:41:25,669 INFO spawned: 'clamav' with pid 8852
o1rvi6r 2019-03-22 13:41:25,742 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:25,747 INFO exited: clamav (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:26,558 INFO spawned: 'clamav' with pid 8956
o1rvi6r 2019-03-22 13:41:26,613 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:26,616 INFO exited: clamav (exit status 1; not expected)
o1rvi6r Mar 22 13:41:26 77fe137209c3 postfix/master[8954]: fatal: open lock file /var/lib/postfix/master.lock: cannot open file: Permission denied
o1rvi6r 2019-03-22 13:41:26,669 INFO spawned: 'clamav' with pid 8960
o1rvi6r 2019-03-22 13:41:26,718 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:26,721 INFO exited: clamav (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:26,778 INFO spawned: 'clamav' with pid 8961
o1rvi6r 2019-03-22 13:41:26,779 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:26,780 INFO exited: amavis (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:26,803 INFO spawned: 'amavis' with pid 8962
o1rvi6r 2019-03-22 13:41:26,807 INFO success: amavis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:26,807 INFO exited: clamav (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:26,808 INFO spawned: 'clamav' with pid 8963
o1rvi6r 2019-03-22 13:41:26,852 INFO success: clamav entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
o1rvi6r 2019-03-22 13:41:26,859 INFO exited: clamav (exit status 1; not expected)
o1rvi6r 2019-03-22 13:41:30,199 INFO spawned: 'clamav' with pid 9015

Finally...

Thank you for all the hard work thus far! ❤️

Metadata

Metadata

Assignees

No one assigned

    Labels

    service/security/amavis

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions