docker-mailserver: SMTP only mode - SASL error
My Docker container configuration is the following:
(...)
mail:
image: tvial/docker-mailserver:latest
hostname: www
domainname: redacted.cloud
container_name: mail
ports:
- "25:25"
- "143:143"
- "587:587"
- "993:993"
volumes:
- maildata:/var/mail
- mailstate:/var/mail-state
- maillogs:/var/log/mail
- ./prod/mailserver:/tmp/docker-mailserver
- ./nginx/certs:/etc/letsencrypt/live/:ro
environment:
- ENABLE_SPAMASSASSIN=0
- ENABLE_CLAMAV=0
- ENABLE_FAIL2BAN=0
- ENABLE_POSTGREY=0
- ONE_DIR=1
- DMS_DEBUG=0
- SMTP_ONLY=1
- SSL_TYPE=letsencrypt
cap_add:
- NET_ADMIN
- SYS_PTRACE
networks:
- djangonetwork
restart: always
(...)
I have also run the following commands from the instructions before starting it for the first time:
./setup.sh email add noreply@redacted.cloud noreply
./setup.sh config dkim
Here’s what I have in logs of the container after trying to send a mail from the added address above:
ubuntu@redacted.cloud:~/web_app_tracker$ docker-compose -f docker-compose.prod.yml logs -f mail
Attaching to mail
2020-11-12 00:23:59,901 CRIT Supervisor is running as root. Privileges were not dropped because no user is specified in the config file. If you intend to run as root, you can set user=root in the config file to avoid this message.
2020-11-12 00:23:59,902 INFO Included extra file "/etc/supervisor/conf.d/saslauth.conf" during parsing
2020-11-12 00:23:59,902 INFO Included extra file "/etc/supervisor/conf.d/supervisor-app.conf" during parsing
2020-11-12 00:23:59,923 INFO RPC interface 'supervisor' initialized
2020-11-12 00:23:59,924 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2020-11-12 00:23:59,924 INFO supervisord started with pid 1
2020-11-12 00:24:00,927 INFO spawned: 'mailserver' with pid 8
2020-11-12 00:24:00,996 INFO success: mailserver entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
#
#
# docker-mailserver
#
#
Initializing setup
Checking configuration
Configuring mail server
Warning Spamassassin is disabled. You can enable it with 'ENABLE_SPAMASSASSIN=1'
Warning Clamav is disabled. You can enable it with 'ENABLE_CLAMAV=1'
find: '/var/mail-state/lib-amavis': No such file or directory
Starting Misc
Starting mail server
2020-11-12 00:24:08,855 INFO spawned: 'cron' with pid 146
2020-11-12 00:24:08,856 INFO success: cron entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
cron: started
2020-11-12 00:24:09,126 INFO spawned: 'rsyslog' with pid 148
2020-11-12 00:24:09,128 INFO success: rsyslog entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
rsyslog: started
2020-11-12 00:24:09,452 INFO spawned: 'opendkim' with pid 152
2020-11-12 00:24:09,452 INFO success: opendkim entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
opendkim: started
2020-11-12 00:24:09,822 INFO spawned: 'opendmarc' with pid 160
2020-11-12 00:24:09,828 INFO success: opendmarc entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
opendmarc: started
2020-11-12 00:24:10,148 INFO spawned: 'postfix' with pid 167
2020-11-12 00:24:10,149 INFO success: postfix entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
postfix: started
2020-11-12 00:24:10,661 INFO spawned: 'changedetector' with pid 194
2020-11-12 00:24:10,661 INFO success: changedetector entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
changedetector: started
2020-11-12 00:24:11,133 INFO spawned: 'amavis' with pid 207
2020-11-12 00:24:11,142 INFO success: amavis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
amavis: started
#
# www.redacted.cloud is up and running
#
Nov 12 00:24:12 www amavis[207]: logging initialized, log level 2, syslog: amavis.mail
Nov 12 00:24:12 www amavis[207]: sd_notify (no socket): STATUS=Config files have been read, modules loaded.
Nov 12 00:24:12 www amavis[207]: starting. /usr/sbin/amavisd-new at www.redacted.cloud amavisd-new-2.11.0 (20160426), Unicode aware
Nov 12 00:24:12 www amavis[207]: perl=5.028001, user=, EUID: 112 (112); group=, EGID: 114 114 (114 114)
Nov 12 00:24:13 www amavis[207]: INFO: no optional modules: unicore::lib::Nt::De.pl Unix::Getrusage
Nov 12 00:24:13 www amavis[207]: socket module IO::Socket::IP, protocol families available: INET
Nov 12 00:24:13 www amavis[207]: will bind to /var/lib/amavis/amavisd.sock|unix, 127.0.0.1:10024/tcp
Nov 12 00:24:13 www amavis[207]: sd_notify (no socket): STATUS=Transferring control to Net::Server.
Nov 12 00:24:13 www amavis[207]: sd_notify (no socket): STATUS=Preparing to bind sockets.
Nov 12 00:24:13 www amavis[207]: Net::Server: 2020/11/12-00:24:13 Amavis (type Net::Server::PreForkSimple) starting! pid(207)
Nov 12 00:24:13 www amavis[207]: Net::Server: Binding to UNIX socket file "/var/lib/amavis/amavisd.sock"
Nov 12 00:24:13 www amavis[207]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1 with IPv4
Nov 12 00:24:13 www amavis[207]: sd_notify (no socket): STATUS=Sockets bound, checking user and group.
Nov 12 00:24:13 www amavis[207]: Net::Server: Group Not Defined. Defaulting to EGID '114 114'
Nov 12 00:24:13 www amavis[207]: Net::Server: User Not Defined. Defaulting to EUID '112'
Nov 12 00:24:13 www amavis[207]: sd_notify (no socket): STATUS=The rest of pre-fork init, finding helper programs.
Nov 12 00:24:13 www amavis[207]: config files read: /usr/share/amavis/conf.d/10-debian_scripts, /usr/share/amavis/conf.d/20-package, /etc/amavis/conf.d/01-debian, /etc/amavis/conf.d/05-domain_id, /etc/amavis/conf.d/05-node_id, /etc/amavis/conf.d/15-av_scanners, /etc/amavis/conf.d/15-content_filter_mode, /etc/amavis/conf.d/20-debian_defaults, /etc/amavis/conf.d/25-amavis_helpers, /etc/amavis/conf.d/30-template_localization, /etc/amavis/conf.d/49-docker-mailserver, /etc/amavis/conf.d/50-user, /etc/amavis/conf.d/60-dms_default_config, /etc/amavis/conf.d/61-dms_auto_generated, /etc/amavis/conf.d/62-improve_privacy_remove_headers
Nov 12 00:24:13 www amavis[207]: Module Amavis::Conf 2.412
Nov 12 00:24:13 www amavis[207]: Module Archive::Zip 1.64
Nov 12 00:24:13 www amavis[207]: Module BerkeleyDB 0.55
Nov 12 00:24:13 www amavis[207]: Module Compress::Raw::Zlib 2.076
Nov 12 00:24:13 www amavis[207]: Module Compress::Zlib 2.074
Nov 12 00:24:13 www amavis[207]: Module Digest::MD5 2.55
Nov 12 00:24:13 www amavis[207]: Module Digest::SHA 6.01
Nov 12 00:24:13 www amavis[207]: Module Encode 2.97
Nov 12 00:24:13 www amavis[207]: Module File::Temp 0.2304
Nov 12 00:24:13 www amavis[207]: Module IO::Socket::IP 0.39
Nov 12 00:24:13 www amavis[207]: Module MIME::Entity 5.509
Nov 12 00:24:13 www amavis[207]: Module MIME::Parser 5.509
Nov 12 00:24:13 www amavis[207]: Module MIME::Tools 5.509
Nov 12 00:24:13 www amavis[207]: Module Mail::Header 2.18
Nov 12 00:24:13 www amavis[207]: Module Mail::Internet 2.18
Nov 12 00:24:13 www amavis[207]: Module Net::LibIDN 0.12
Nov 12 00:24:13 www amavis[207]: Module Net::Server 2.009
Nov 12 00:24:13 www amavis[207]: Module Scalar::Util 1.5
Nov 12 00:24:13 www amavis[207]: Module Socket 2.027
Nov 12 00:24:13 www amavis[207]: Module Time::HiRes 1.9759
Nov 12 00:24:13 www amavis[207]: Module Unix::Syslog 1.1
Nov 12 00:24:13 www amavis[207]: Amavis::ZMQ code NOT loaded
Nov 12 00:24:13 www amavis[207]: Amavis::DB code loaded
Nov 12 00:24:13 www amavis[207]: SQL base code NOT loaded
Nov 12 00:24:13 www amavis[207]: SQL::Log code NOT loaded
Nov 12 00:24:13 www amavis[207]: SQL::Quarantine NOT loaded
Nov 12 00:24:13 www amavis[207]: Lookup::SQL code NOT loaded
Nov 12 00:24:13 www amavis[207]: Lookup::LDAP code NOT loaded
Nov 12 00:24:13 www amavis[207]: AM.PDP-in proto code loaded
Nov 12 00:24:13 www amavis[207]: SMTP-in proto code loaded
Nov 12 00:24:13 www amavis[207]: Courier proto code NOT loaded
Nov 12 00:24:13 www amavis[207]: SMTP-out proto code loaded
Nov 12 00:24:13 www amavis[207]: Pipe-out proto code NOT loaded
Nov 12 00:24:13 www amavis[207]: BSMTP-out proto code NOT loaded
Nov 12 00:24:13 www amavis[207]: Local-out proto code loaded
Nov 12 00:24:13 www amavis[207]: OS_Fingerprint code NOT loaded
Nov 12 00:24:13 www amavis[207]: ANTI-VIRUS code NOT loaded
Nov 12 00:24:13 www amavis[207]: ANTI-SPAM code NOT loaded
Nov 12 00:24:13 www amavis[207]: ANTI-SPAM-EXT code NOT loaded
Nov 12 00:24:13 www amavis[207]: ANTI-SPAM-C code NOT loaded
Nov 12 00:24:13 www amavis[207]: ANTI-SPAM-SA code NOT loaded
Nov 12 00:24:13 www amavis[207]: Unpackers code loaded
Nov 12 00:24:13 www amavis[207]: DKIM code NOT loaded
Nov 12 00:24:13 www amavis[207]: Tools code NOT loaded
Nov 12 00:24:13 www amavis[207]: Found $file at /usr/bin/file
Nov 12 00:24:13 www amavis[207]: Found $altermime at /usr/bin/altermime
Nov 12 00:24:13 www amavis[207]: Internal decoder for .mail
Nov 12 00:24:13 www amavis[207]: Found decoder for .Z at /bin/uncompress
Nov 12 00:24:13 www amavis[207]: Found decoder for .gz at /bin/gzip -d
Nov 12 00:24:13 www amavis[207]: Internal decoder for .gz (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .bz2 at /bin/bzip2 -d
Nov 12 00:24:13 www amavis[207]: Found decoder for .xz at /usr/bin/xz -dc
Nov 12 00:24:13 www amavis[207]: Found decoder for .lzma at /usr/bin/xz -dc --format=lzma
Nov 12 00:24:13 www amavis[207]: Found decoder for .lrz at /usr/bin/lrzip -q -k -d -o -
Nov 12 00:24:13 www amavis[207]: Found decoder for .lzo at /usr/bin/lzop -d
Nov 12 00:24:13 www amavis[207]: Found decoder for .lz4 at /usr/bin/lz4c -d
Nov 12 00:24:13 www amavis[207]: Found decoder for .rpm at /usr/bin/rpm2cpio
Nov 12 00:24:13 www amavis[207]: Found decoder for .cpio at /bin/pax
Nov 12 00:24:13 www amavis[207]: Found decoder for .tar at /bin/pax
Nov 12 00:24:13 www amavis[207]: Found decoder for .deb at /usr/bin/ar
Nov 12 00:24:13 www amavis[207]: Found decoder for .rar at /usr/bin/unrar-free
Nov 12 00:24:13 www amavis[207]: Found decoder for .arj at /usr/bin/arj
Nov 12 00:24:13 www amavis[207]: Found decoder for .arc at /usr/bin/nomarch
Nov 12 00:24:13 www amavis[207]: No ext program for .zoo, tried: zoo
Nov 12 00:24:13 www amavis[207]: No ext program for .doc, tried: ripole
Nov 12 00:24:13 www amavis[207]: Found decoder for .cab at /usr/bin/cabextract
Nov 12 00:24:13 www amavis[207]: Internal decoder for .tnef
Nov 12 00:24:13 www amavis[207]: Found decoder for .zip at /usr/bin/7za
Nov 12 00:24:13 www amavis[207]: Found decoder for .kmz at /usr/bin/7za
Nov 12 00:24:13 www amavis[207]: Internal decoder for .zip (backup, not used)
Nov 12 00:24:13 www amavis[207]: Internal decoder for .kmz (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .7z at /usr/bin/7zr
Nov 12 00:24:13 www amavis[207]: Found decoder for .gz at /usr/bin/7za (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .bz2 at /usr/bin/7za (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .Z at /usr/bin/7za (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .tar at /usr/bin/7za (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .xz at /usr/bin/7z (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .lzma at /usr/bin/7z (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .jar at /usr/bin/7z
Nov 12 00:24:13 www amavis[207]: Found decoder for .cpio at /usr/bin/7z (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .arj at /usr/bin/7z (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .rar at /usr/bin/7z (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .swf at /usr/bin/7z
Nov 12 00:24:13 www amavis[207]: Found decoder for .lha at /usr/bin/7z
Nov 12 00:24:13 www amavis[207]: Found decoder for .iso at /usr/bin/7z
Nov 12 00:24:13 www amavis[207]: Found decoder for .cab at /usr/bin/7z (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .deb at /usr/bin/7z (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .rpm at /usr/bin/7z (backup, not used)
Nov 12 00:24:13 www amavis[207]: Found decoder for .exe at /usr/bin/unrar-free; /usr/bin/arj
Nov 12 00:24:13 www amavis[207]: No decoder for .F
Nov 12 00:24:13 www amavis[207]: No decoder for .doc
Nov 12 00:24:13 www amavis[207]: No decoder for .zoo
Nov 12 00:24:13 www amavis[207]: Deleting db files in /var/lib/amavis/db
Nov 12 00:24:13 www amavis[207]: Creating db in /var/lib/amavis/db/; BerkeleyDB 0.55, libdb 5.3
Nov 12 00:24:13 www amavis[207]: sd_notify (no socket): READY=1\nSTATUS=Initialization done.
Nov 12 00:24:13 www amavis[207]: sd_notify (no socket): STATUS=Starting child process(es), ready for work.
Nov 12 00:24:17 www postfix/master[816]: daemon started -- version 3.4.14, configuration /etc/postfix
Nov 12 00:25:05 www postfix/submission/smtpd[1014]: error: open database /etc/postfix/vmailbox: No such file or directory
Nov 12 00:25:05 www postfix/submission/smtpd[1014]: connect from web_app_tracker_backend_1.web_app_tracker_djangonetwork[172.29.0.5]
Nov 12 00:25:05 www postfix/submission/smtpd[1014]: Anonymous TLS connection established from web_app_tracker_backend_1.web_app_tracker_djangonetwork[172.29.0.5]: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256
Nov 12 00:25:05 www postfix/submission/smtpd[1014]: warning: SASL: Connect to private/auth failed: No such file or directory
Nov 12 00:25:05 www postfix/submission/smtpd[1014]: fatal: no SASL authentication mechanisms
Nov 12 00:25:06 www postfix/master[816]: warning: process /usr/lib/postfix/sbin/smtpd pid 1014 exit status 1
Nov 12 00:25:06 www postfix/master[816]: warning: /usr/lib/postfix/sbin/smtpd: bad command startup -- throttling
Nov 12 00:26:46 www postfix/anvil[1021]: statistics: max connection rate 1/60s for (submission:172.29.0.5) at Nov 12 00:25:05
Nov 12 00:26:46 www postfix/anvil[1021]: statistics: max connection count 1 for (submission:172.29.0.5) at Nov 12 00:25:05
Nov 12 00:26:46 www postfix/anvil[1021]: statistics: max cache size 1 at Nov 12 00:25:05
2020-11-12 00:34:44,900 INFO waiting for postfix to stop
2020-11-12 00:34:46,900 INFO waiting for postfix to stop
2020-11-12 00:34:48,080 INFO reaped unknown pid 816
2020-11-12 00:34:48,080 INFO reaped unknown pid 818
2020-11-12 00:34:48,080 INFO reaped unknown pid 819
2020-11-12 00:34:48,081 INFO reaped unknown pid 1020
Nov 12 00:34:48 www postfix/master[816]: terminating on signal 15
2020-11-12 00:34:48,103 INFO stopped: postfix (exit status 0)
2020-11-12 00:34:48,107 INFO spawned: 'postfix' with pid 3608
2020-11-12 00:34:48,108 INFO success: postfix entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
Nov 12 00:34:49 www postfix/master[4240]: daemon started -- version 3.4.14, configuration /etc/postfix
2020-11-12 00:35:17,511 INFO waiting for postfix to stop
2020-11-12 00:35:19,511 INFO waiting for postfix to stop
2020-11-12 00:35:19,849 INFO reaped unknown pid 4240
2020-11-12 00:35:19,849 INFO reaped unknown pid 4242
2020-11-12 00:35:19,849 INFO reaped unknown pid 4243
Nov 12 00:35:19 www postfix/master[4240]: terminating on signal 15
2020-11-12 00:35:19,869 INFO stopped: postfix (exit status 0)
2020-11-12 00:35:19,873 INFO spawned: 'postfix' with pid 4415
2020-11-12 00:35:19,873 INFO success: postfix entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
Nov 12 00:35:21 www postfix/master[5047]: daemon started -- version 3.4.14, configuration /etc/postfix
2020-11-12 00:35:33,769 WARN received SIGTERM indicating exit request
2020-11-12 00:35:33,769 INFO waiting for rsyslog, postfix, cron, amavis, changedetector, opendkim, opendmarc, mailserver to die
2020-11-12 00:35:33,770 INFO stopped: mailserver (terminated by SIGTERM)
2020-11-12 00:35:35,911 INFO stopped: opendmarc (exit status 0)
2020-11-12 00:35:36,913 INFO waiting for rsyslog, postfix, cron, amavis, changedetector, opendkim to die
2020-11-12 00:35:39,922 INFO waiting for rsyslog, postfix, cron, amavis, changedetector, opendkim to die
2020-11-12 00:35:40,936 INFO stopped: opendkim (exit status 0)
2020-11-12 00:35:42,939 INFO waiting for rsyslog, postfix, cron, amavis, changedetector to die
2020-11-12 00:35:42,939 INFO stopped: changedetector (terminated by SIGTERM)
2020-11-12 00:35:43,163 INFO stopped: amavis (exit status 0)
2020-11-12 00:35:43,186 INFO reaped unknown pid 377
2020-11-12 00:35:43,186 INFO reaped unknown pid 378
2020-11-12 00:35:43,187 INFO stopped: cron (terminated by SIGTERM)
2020-11-12 00:35:43,444 INFO reaped unknown pid 5142
2020-11-12 00:35:46,453 INFO waiting for rsyslog, postfix to die
2020-11-12 00:35:47,134 INFO reaped unknown pid 5047
2020-11-12 00:35:47,134 INFO reaped unknown pid 5049
2020-11-12 00:35:47,134 INFO reaped unknown pid 5050
2020-11-12 00:35:47,183 INFO stopped: postfix (exit status 0)
2020-11-12 00:35:47,210 INFO stopped: rsyslog (exit status 0)
2020-11-12 00:35:56,555 CRIT Supervisor is running as root. Privileges were not dropped because no user is specified in the config file. If you intend to run as root, you can set user=root in the config file to avoid this message.
2020-11-12 00:35:56,555 INFO Included extra file "/etc/supervisor/conf.d/saslauth.conf" during parsing
2020-11-12 00:35:56,556 INFO Included extra file "/etc/supervisor/conf.d/supervisor-app.conf" during parsing
2020-11-12 00:35:56,577 INFO RPC interface 'supervisor' initialized
2020-11-12 00:35:56,583 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2020-11-12 00:35:56,583 INFO supervisord started with pid 1
2020-11-12 00:35:57,585 INFO spawned: 'mailserver' with pid 8
2020-11-12 00:35:57,638 INFO success: mailserver entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
#
#
# docker-mailserver
#
#
Initializing setup
Checking configuration
Configuring mail server
Nameservers 127.0.0.11
Warning Spamassassin is disabled. You can enable it with 'ENABLE_SPAMASSASSIN=1'
Warning Clamav is disabled. You can enable it with 'ENABLE_CLAMAV=1'
sed: can't read /etc/cron.daily/spamassassin: No such file or directory
Starting Misc
Starting mail server
2020-11-12 00:36:01,666 INFO spawned: 'cron' with pid 132
2020-11-12 00:36:01,666 INFO success: cron entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
cron: started
2020-11-12 00:36:01,801 INFO spawned: 'rsyslog' with pid 134
2020-11-12 00:36:01,802 INFO success: rsyslog entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
rsyslog: started
2020-11-12 00:36:01,940 INFO spawned: 'opendkim' with pid 138
2020-11-12 00:36:01,941 INFO success: opendkim entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
opendkim: started
2020-11-12 00:36:02,091 INFO spawned: 'opendmarc' with pid 146
2020-11-12 00:36:02,091 INFO success: opendmarc entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
opendmarc: started
2020-11-12 00:36:02,223 INFO spawned: 'postfix' with pid 153
2020-11-12 00:36:02,223 INFO success: postfix entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
postfix: started
2020-11-12 00:36:02,366 INFO spawned: 'changedetector' with pid 162
2020-11-12 00:36:02,366 INFO success: changedetector entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
changedetector: started
2020-11-12 00:36:02,504 INFO spawned: 'amavis' with pid 167
2020-11-12 00:36:02,504 INFO success: amavis entered RUNNING state, process has stayed up for > than 0 seconds (startsecs)
amavis: started
#
# www.redacted.cloud is up and running
#
Nov 12 00:36:03 www amavis[167]: logging initialized, log level 2, syslog: amavis.mail
Nov 12 00:36:03 www amavis[167]: sd_notify (no socket): STATUS=Config files have been read, modules loaded.
Nov 12 00:36:03 www amavis[167]: starting. /usr/sbin/amavisd-new at www.redacted.cloud amavisd-new-2.11.0 (20160426), Unicode aware
Nov 12 00:36:03 www amavis[167]: perl=5.028001, user=, EUID: 112 (112); group=, EGID: 114 114 (114 114)
Nov 12 00:36:03 www amavis[167]: INFO: no optional modules: unicore::lib::Nt::De.pl Unix::Getrusage
Nov 12 00:36:03 www amavis[167]: socket module IO::Socket::IP, protocol families available: INET
Nov 12 00:36:03 www amavis[167]: will bind to /var/lib/amavis/amavisd.sock|unix, 127.0.0.1:10024/tcp
Nov 12 00:36:03 www amavis[167]: sd_notify (no socket): STATUS=Transferring control to Net::Server.
Nov 12 00:36:03 www amavis[167]: sd_notify (no socket): STATUS=Preparing to bind sockets.
Nov 12 00:36:03 www amavis[167]: Net::Server: 2020/11/12-00:36:03 Amavis (type Net::Server::PreForkSimple) starting! pid(167)
Nov 12 00:36:03 www amavis[167]: Net::Server: Binding to UNIX socket file "/var/lib/amavis/amavisd.sock"
Nov 12 00:36:03 www amavis[167]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1 with IPv4
Nov 12 00:36:03 www amavis[167]: sd_notify (no socket): STATUS=Sockets bound, checking user and group.
Nov 12 00:36:03 www amavis[167]: Net::Server: Group Not Defined. Defaulting to EGID '114 114'
Nov 12 00:36:03 www amavis[167]: Net::Server: User Not Defined. Defaulting to EUID '112'
Nov 12 00:36:03 www amavis[167]: sd_notify (no socket): STATUS=The rest of pre-fork init, finding helper programs.
Nov 12 00:36:03 www amavis[167]: config files read: /usr/share/amavis/conf.d/10-debian_scripts, /usr/share/amavis/conf.d/20-package, /etc/amavis/conf.d/01-debian, /etc/amavis/conf.d/05-domain_id, /etc/amavis/conf.d/05-node_id, /etc/amavis/conf.d/15-av_scanners, /etc/amavis/conf.d/15-content_filter_mode, /etc/amavis/conf.d/20-debian_defaults, /etc/amavis/conf.d/25-amavis_helpers, /etc/amavis/conf.d/30-template_localization, /etc/amavis/conf.d/49-docker-mailserver, /etc/amavis/conf.d/50-user, /etc/amavis/conf.d/60-dms_default_config, /etc/amavis/conf.d/61-dms_auto_generated, /etc/amavis/conf.d/62-improve_privacy_remove_headers
Nov 12 00:36:03 www amavis[167]: Module Amavis::Conf 2.412
Nov 12 00:36:03 www amavis[167]: Module Archive::Zip 1.64
Nov 12 00:36:03 www amavis[167]: Module BerkeleyDB 0.55
Nov 12 00:36:03 www amavis[167]: Module Compress::Raw::Zlib 2.076
Nov 12 00:36:03 www amavis[167]: Module Compress::Zlib 2.074
Nov 12 00:36:03 www amavis[167]: Module Digest::MD5 2.55
Nov 12 00:36:03 www amavis[167]: Module Digest::SHA 6.01
Nov 12 00:36:03 www amavis[167]: Module Encode 2.97
Nov 12 00:36:03 www amavis[167]: Module File::Temp 0.2304
Nov 12 00:36:03 www amavis[167]: Module IO::Socket::IP 0.39
Nov 12 00:36:03 www amavis[167]: Module MIME::Entity 5.509
Nov 12 00:36:03 www amavis[167]: Module MIME::Parser 5.509
Nov 12 00:36:03 www amavis[167]: Module MIME::Tools 5.509
Nov 12 00:36:03 www amavis[167]: Module Mail::Header 2.18
Nov 12 00:36:03 www amavis[167]: Module Mail::Internet 2.18
Nov 12 00:36:03 www amavis[167]: Module Net::LibIDN 0.12
Nov 12 00:36:03 www amavis[167]: Module Net::Server 2.009
Nov 12 00:36:03 www amavis[167]: Module Scalar::Util 1.5
Nov 12 00:36:03 www amavis[167]: Module Socket 2.027
Nov 12 00:36:03 www amavis[167]: Module Time::HiRes 1.9759
Nov 12 00:36:03 www amavis[167]: Module Unix::Syslog 1.1
Nov 12 00:36:03 www amavis[167]: Amavis::ZMQ code NOT loaded
Nov 12 00:36:03 www amavis[167]: Amavis::DB code loaded
Nov 12 00:36:03 www amavis[167]: SQL base code NOT loaded
Nov 12 00:36:03 www amavis[167]: SQL::Log code NOT loaded
Nov 12 00:36:03 www amavis[167]: SQL::Quarantine NOT loaded
Nov 12 00:36:03 www amavis[167]: Lookup::SQL code NOT loaded
Nov 12 00:36:03 www amavis[167]: Lookup::LDAP code NOT loaded
Nov 12 00:36:03 www amavis[167]: AM.PDP-in proto code loaded
Nov 12 00:36:03 www amavis[167]: SMTP-in proto code loaded
Nov 12 00:36:03 www amavis[167]: Courier proto code NOT loaded
Nov 12 00:36:03 www amavis[167]: SMTP-out proto code loaded
Nov 12 00:36:03 www amavis[167]: Pipe-out proto code NOT loaded
Nov 12 00:36:03 www amavis[167]: BSMTP-out proto code NOT loaded
Nov 12 00:36:03 www amavis[167]: Local-out proto code loaded
Nov 12 00:36:03 www amavis[167]: OS_Fingerprint code NOT loaded
Nov 12 00:36:03 www amavis[167]: ANTI-VIRUS code NOT loaded
Nov 12 00:36:03 www amavis[167]: ANTI-SPAM code NOT loaded
Nov 12 00:36:03 www amavis[167]: ANTI-SPAM-EXT code NOT loaded
Nov 12 00:36:03 www amavis[167]: ANTI-SPAM-C code NOT loaded
Nov 12 00:36:03 www amavis[167]: ANTI-SPAM-SA code NOT loaded
Nov 12 00:36:03 www amavis[167]: Unpackers code loaded
Nov 12 00:36:03 www amavis[167]: DKIM code NOT loaded
Nov 12 00:36:03 www amavis[167]: Tools code NOT loaded
Nov 12 00:36:03 www amavis[167]: Found $file at /usr/bin/file
Nov 12 00:36:03 www amavis[167]: Found $altermime at /usr/bin/altermime
Nov 12 00:36:03 www amavis[167]: Internal decoder for .mail
Nov 12 00:36:03 www amavis[167]: Found decoder for .Z at /bin/uncompress
Nov 12 00:36:03 www amavis[167]: Found decoder for .gz at /bin/gzip -d
Nov 12 00:36:03 www amavis[167]: Internal decoder for .gz (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .bz2 at /bin/bzip2 -d
Nov 12 00:36:03 www amavis[167]: Found decoder for .xz at /usr/bin/xz -dc
Nov 12 00:36:03 www amavis[167]: Found decoder for .lzma at /usr/bin/xz -dc --format=lzma
Nov 12 00:36:03 www amavis[167]: Found decoder for .lrz at /usr/bin/lrzip -q -k -d -o -
Nov 12 00:36:03 www amavis[167]: Found decoder for .lzo at /usr/bin/lzop -d
Nov 12 00:36:03 www amavis[167]: Found decoder for .lz4 at /usr/bin/lz4c -d
Nov 12 00:36:03 www amavis[167]: Found decoder for .rpm at /usr/bin/rpm2cpio
Nov 12 00:36:03 www amavis[167]: Found decoder for .cpio at /bin/pax
Nov 12 00:36:03 www amavis[167]: Found decoder for .tar at /bin/pax
Nov 12 00:36:03 www amavis[167]: Found decoder for .deb at /usr/bin/ar
Nov 12 00:36:03 www amavis[167]: Found decoder for .rar at /usr/bin/unrar-free
Nov 12 00:36:03 www amavis[167]: Found decoder for .arj at /usr/bin/arj
Nov 12 00:36:03 www amavis[167]: Found decoder for .arc at /usr/bin/nomarch
Nov 12 00:36:03 www amavis[167]: No ext program for .zoo, tried: zoo
Nov 12 00:36:03 www amavis[167]: No ext program for .doc, tried: ripole
Nov 12 00:36:03 www amavis[167]: Found decoder for .cab at /usr/bin/cabextract
Nov 12 00:36:03 www amavis[167]: Internal decoder for .tnef
Nov 12 00:36:03 www amavis[167]: Found decoder for .zip at /usr/bin/7za
Nov 12 00:36:03 www amavis[167]: Found decoder for .kmz at /usr/bin/7za
Nov 12 00:36:03 www amavis[167]: Internal decoder for .zip (backup, not used)
Nov 12 00:36:03 www amavis[167]: Internal decoder for .kmz (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .7z at /usr/bin/7zr
Nov 12 00:36:03 www amavis[167]: Found decoder for .gz at /usr/bin/7za (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .bz2 at /usr/bin/7za (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .Z at /usr/bin/7za (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .tar at /usr/bin/7za (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .xz at /usr/bin/7z (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .lzma at /usr/bin/7z (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .jar at /usr/bin/7z
Nov 12 00:36:03 www amavis[167]: Found decoder for .cpio at /usr/bin/7z (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .arj at /usr/bin/7z (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .rar at /usr/bin/7z (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .swf at /usr/bin/7z
Nov 12 00:36:03 www amavis[167]: Found decoder for .lha at /usr/bin/7z
Nov 12 00:36:03 www amavis[167]: Found decoder for .iso at /usr/bin/7z
Nov 12 00:36:03 www amavis[167]: Found decoder for .cab at /usr/bin/7z (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .deb at /usr/bin/7z (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .rpm at /usr/bin/7z (backup, not used)
Nov 12 00:36:03 www amavis[167]: Found decoder for .exe at /usr/bin/unrar-free; /usr/bin/arj
Nov 12 00:36:03 www amavis[167]: No decoder for .F
Nov 12 00:36:03 www amavis[167]: No decoder for .doc
Nov 12 00:36:03 www amavis[167]: No decoder for .zoo
Nov 12 00:36:03 www amavis[167]: Deleting db files __db.001,snmp.db,__db.003,__db.002,nanny.db in /var/lib/amavis/db
Nov 12 00:36:03 www amavis[167]: Creating db in /var/lib/amavis/db/; BerkeleyDB 0.55, libdb 5.3
Nov 12 00:36:03 www amavis[167]: sd_notify (no socket): READY=1\nSTATUS=Initialization done.
Nov 12 00:36:03 www amavis[167]: sd_notify (no socket): STATUS=Starting child process(es), ready for work.
Nov 12 00:36:04 www postfix/master[796]: daemon started -- version 3.4.14, configuration /etc/postfix
Nov 12 00:38:47 www postfix/submission/smtpd[1484]: connect from web_app_tracker_backend_1.web_app_tracker_djangonetwork[172.29.0.7]
Nov 12 00:38:47 www postfix/submission/smtpd[1484]: Anonymous TLS connection established from web_app_tracker_backend_1.web_app_tracker_djangonetwork[172.29.0.7]: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256
Nov 12 00:38:47 www postfix/submission/smtpd[1484]: warning: SASL: Connect to private/auth failed: No such file or directory
Nov 12 00:38:47 www postfix/submission/smtpd[1484]: fatal: no SASL authentication mechanisms
Nov 12 00:38:48 www postfix/master[796]: warning: process /usr/lib/postfix/sbin/smtpd pid 1484 exit status 1
Nov 12 00:38:48 www postfix/master[796]: warning: /usr/lib/postfix/sbin/smtpd: bad command startup -- throttling
I’ve also checked if SASL auth is enabled in any case, but it doesn’t seem like so:
ubuntu@redacted.cloud:~/web_app_tracker$ docker-compose -f docker-compose.prod.yml exec mail postconf -d | grep "sasl_auth_enable"
lmtp_sasl_auth_enable = no
smtp_sasl_auth_enable = no
smtpd_sasl_auth_enable = no
Can anyone help me around this, it seems like a bug? Thank you in advance.
About this issue
- Original URL
- State: closed
- Created 4 years ago
- Comments: 39 (22 by maintainers)
I understand now; I thought you wanted to use SASL.
I guess the error originates from:
@erik-wramner @casparklein do you have any ideas?
In the meantime, I’d suggest trying the following:
configfolder and start with a blank configuration anewmailserver.envin compose:und try again (with blank configuration)
PS: I didn’t know
.cloudwas a valid TLD. Is it?