lejmr / iredmail-docker

iRedmail docker container
https://hub.docker.com/repository/docker/lejmr/iredmail
133 stars 59 forks source link

Mail delivery report does not work #16

Closed TitanFighter closed 5 years ago

TitanFighter commented 6 years ago

In case of fresh installation of iRedMail without Docker the delivery report system works out of the box. In case of Docker I see the next log:

Feb 26 13:53:14 314f2e0e024a postfix/submission/smtpd[2841]: connect from localhost[127.0.0.1] Feb 26 13:53:14 314f2e0e024a postfix/submission/smtpd[2841]: Anonymous TLS connection established from localhost[127.0.0.1]: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits) Feb 26 13:53:14 314f2e0e024a postfix/submission/smtpd[2841]: 5FB89BCBAB: client=localhost[127.0.0.1], sasl_method=LOGIN, sasl_username=postmaster@mydomain.com Feb 26 13:53:14 314f2e0e024a postfix/cleanup[2846]: 5FB89BCBAB: message-id=5b07c534f808c88e6ec17b2e7d0ed945@mydomain.com Feb 26 13:53:14 314f2e0e024a postfix/qmgr[361]: 5FB89BCBAB: from=postmaster@mydomain.com, size=688, nrcpt=1 (queue active) Feb 26 13:53:14 314f2e0e024a roundcube: <9ci216oe> User postmaster@mydomain.com [31.43.102.240]; Message for postmaster@mydomain.com; 250: 2.0.0 Ok: queued as 5FB89BCBAB Feb 26 13:53:14 314f2e0e024a postfix/submission/smtpd[2841]: disconnect from localhost[127.0.0.1] ehlo=2 starttls=1 auth=1 mail=1 rcpt=1 data=1 quit=1 commands=8 Feb 26 13:53:14 314f2e0e024a postfix/10025/smtpd[2858]: connect from localhost[127.0.0.1] Feb 26 13:53:14 314f2e0e024a postfix/10025/smtpd[2858]: AFC15BCBB5: client=localhost[127.0.0.1] Feb 26 13:53:14 314f2e0e024a postfix/cleanup[2846]: AFC15BCBB5: message-id=5b07c534f808c88e6ec17b2e7d0ed945@mydomain.com Feb 26 13:53:14 314f2e0e024a postfix/qmgr[361]: AFC15BCBB5: from=postmaster@mydomain.com, size=1776, nrcpt=1 (queue active) Feb 26 13:53:14 314f2e0e024a postfix/10025/smtpd[2858]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5 Feb 26 13:53:14 314f2e0e024a amavis[630]: (00630-02) Passed CLEAN {RelayedInternal}, ORIGINATING/MYNETS LOCAL [127.0.0.1]:53636 postmaster@mydomain.com -> postmaster@mydomain.com, Queue-ID: 5FB89BCBAB, Message-ID: 5b07c534f808c88e6ec17b2e7d0ed945@mydomain.com, mail_id: Ne1UtIHtmLps, Hits: 1.313, size: 688, queued_as: AFC15BCBB5, dkim_new=dkim:mydomain.com, 281 ms, Tests: [ALL_TRUSTED=-1,DKIM_ADSP_ALL=1.1,TVD_RCVD_SINGLE=1.213] Feb 26 13:53:14 314f2e0e024a postfix/amavis/smtp[2851]: 5FB89BCBAB: to=postmaster@mydomain.com, relay=127.0.0.1[127.0.0.1]:10026, delay=0.4, delays=0.07/0/0.02/0.31, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as AFC15BCBB5) Feb 26 13:53:14 314f2e0e024a postfix/qmgr[361]: 5FB89BCBAB: removed Feb 26 13:53:14 314f2e0e024a postfix/bounce[2911]: fatal: open file trace AFC15BCBB5: Permission denied Feb 26 13:53:15 314f2e0e024a postfix/pipe[2315]: warning: write/read private/trace socket: Success Feb 26 13:53:15 314f2e0e024a postfix/pipe[2315]: warning: AFC15BCBB5: trace service failure Feb 26 13:53:15 314f2e0e024a postfix/master[359]: warning: process /usr/lib/postfix/sbin/bounce pid 2911 exit status 1 Feb 26 13:53:15 314f2e0e024a postfix/pipe[2315]: AFC15BCBB5: to=postmaster@mydomain.com, relay=dovecot, delay=1.1, delays=0/0.01/0/1.1, dsn=4.3.0, status=deferred (AFC15BCBB5: trace service failed)

When delivery report works, logs look like:

Feb 26 14:11:21 mail postfix/submission/smtpd[2219]: connect from localhost[127.0.0.1] Feb 26 14:11:21 mail postfix/submission/smtpd[2219]: Anonymous TLS connection established from localhost[127.0.0.1]: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits) Feb 26 14:11:21 mail postfix/submission/smtpd[2219]: 162A3413FA: client=localhost[127.0.0.1], sasl_method=LOGIN, sasl_username=postmaster@mydomain.com Feb 26 14:11:21 mail postfix/cleanup[2231]: 162A3413FA: message-id=92f542ad2560554beffe043b6912eae2@mydomain.com Feb 26 14:11:21 mail roundcube: User postmaster@mydomain.com [31.43.102.240]; Message for test_user@bigmir.net; 250: 2.0.0 Ok: queued as 162A3413FA Feb 26 14:11:21 mail postfix/qmgr[2063]: 162A3413FA: from=postmaster@mydomain.com, size=533, nrcpt=1 (queue active) Feb 26 14:11:21 mail postfix/submission/smtpd[2219]: disconnect from localhost[127.0.0.1] ehlo=2 starttls=1 auth=1 mail=1 rcpt=1 data=1 quit=1 commands=8 Feb 26 14:11:21 mail postfix/10025/smtpd[2246]: connect from localhost[127.0.0.1] Feb 26 14:11:21 mail postfix/10025/smtpd[2246]: 6247541401: client=localhost[127.0.0.1] Feb 26 14:11:21 mail postfix/cleanup[2231]: 6247541401: message-id=92f542ad2560554beffe043b6912eae2@mydomain.com Feb 26 14:11:21 mail postfix/qmgr[2063]: 6247541401: from=postmaster@mydomain.com, size=1612, nrcpt=1 (queue active) Feb 26 14:11:21 mail postfix/10025/smtpd[2246]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5 Feb 26 14:11:21 mail amavis[2096]: (02096-01) Passed CLEAN {RelayedInternal}, ORIGINATING/MYNETS LOCAL [127.0.0.1]:33218 postmaster@mydomain.com -> test_user@bigmir.net, Queue-ID: 162A3413FA, Message-ID: <92f542ad2560554$ Feb 26 14:11:21 mail postfix/amavis/smtp[2236]: 162A3413FA: to=test_user@bigmir.net, relay=127.0.0.1[127.0.0.1]:10026, delay=0.42, delays=0.12/0.01/0.03/0.26, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:$ Feb 26 14:11:21 mail postfix/qmgr[2063]: 162A3413FA: removed Feb 26 14:11:22 mail postfix/smtp[2418]: 6247541401: to=test_user@bigmir.net, relay=mx5.bigmir.net[213.186.116.118]:25, delay=0.68, delays=0.01/0.05/0.33/0.28, dsn=2.0.0, status=sent (250 OK id=1eqIYr-00018L-VU) Feb 26 14:11:22 mail postfix/cleanup[2231]: 1250041400: message-id=20180226131122.1250041400@mail.mydomain.com Feb 26 14:11:22 mail postfix/qmgr[2063]: 1250041400: from=<>, size=3535, nrcpt=1 (queue active) Feb 26 14:11:22 mail postfix/bounce[2249]: 6247541401: sender delivery status notification: 1250041400 Feb 26 14:11:22 mail postfix/qmgr[2063]: 6247541401: removed Feb 26 14:11:22 mail postfix/pipe[2247]: 1250041400: to=postmaster@mydomain.com, relay=dovecot, delay=0.09, delays=0.01/0/0/0.08, dsn=2.0.0, status=sent (delivered via dovecot service) Feb 26 14:11:22 mail postfix/qmgr[2063]: 1250041400: removed

Docker and non-docker tests were done on the same system. Every time were used the same iso of Ubuntu 16.04. All tests were done with a fresh OS installation. I made about 10 tests.

twelsby commented 6 years ago

I can't seem to reproduce this error.

I notice that in your docker test you sent the email to yourself but in the non-docker test you sent it to a real email account. It seems like this might be due to this i.e. in the docker test postfix is trying to send the email to a mail domain that does not actually exist (unless you happen to own mydomain.com). Try running the docker test again and sending it to the real email address.

The other thing I would try is running docker without the --privileged option. I think this might be causing problems with SELinux or AppArmour on your host system. I always run docker without the --privileged option, it doesn't seem to need it here.

TitanFighter commented 6 years ago

@twelsby Thanks for the reply. I will double check it in few days.

Regarding this:

I notice that in your docker test you sent the email to yourself but in the non-docker test you sent it to a real email account. .... Try running the docker test again and sending it to the real email address.

I would appreciate if you can check on your instance to send email to yourself. Do you receive report in this case?

twelsby commented 6 years ago

I did originally check, but with my real domain email and did not encounter error. I have created a test container with a fake domain and it also does not give an error, so I guess it can't be that alone, although I would still try using a real domain.

Have you tried running without privileged mode?

TitanFighter commented 6 years ago

Just checked again with a fresh server, with real domain and without privileged mode. Tried to send to myself and to email with different domain - still same issue :( Test is done on Ubuntu 16.04 Server.

Also, because of this new test I found another issue (which I also had when I created this ticket), which can have relation to this one - the same email can be sent few times.

twelsby commented 6 years ago

What version of docker are you using? What command are you using to run it? Are you doing any customization of the container i.e. editing configuration files or bind mounting external configuration files? Are you starting with empty volumes? (I presume yes since you are using a clean install)

For what its worth, I am running 16.04.4 LTS, with kernel 4.4.0-116-generic. I am using docker 18.03.0-ce as a pre-built binary, which is installed via the apt repository download.docker.com.

I am not running from a clean install of ubuntu, so I can't control for the configuration. I do have a native installation of iRedMail running on it, though it is not active and I do not use a direct bind mount to any files from the existing iRedMail installation, so in theory it should not affect things.

I don't think your second issue is really a separate issue. I would say something is preventing postfix from identifying that the mail was successfully sent, so it is just trying again. Maybe bash into the container and play around with the postfix queue.

TitanFighter commented 6 years ago

Everything the same: docker 18.03.0-ce, 16.04.4 LTS, with kernel 4.4.0-116-generic.

I use the command from README with your recommendation to remove privileged

docker run -p 80:80 -p 443:443 \
           -e "DOMAIN=myrealdomain.com" -e "HOSTNAME=mail" \
           -e "MYSQL_ROOT_PASSWORD=password" \
           -e "SOGO_WORKERS=1" \
           -e "TIMEZONE=Europe/Prague" \
           -e "POSTMASTER_PASSWORD={PLAIN}password" \
           -e "IREDAPD_PLUGINS=['reject_null_sender', 'reject_sender_login_mismatch', 'greylisting', 'throttle', 'amavisd_wblist', 'sql_alias_access_policy']" \
           -v /var/www/iredmail/mysql:/var/lib/mysql \
           -v /var/www/iredmail/vmail:/var/vmail \
           -v /var/www/iredmail/clamav:/var/lib/clamav \
           --name=iredmail lejmr/iredmail:mysql-latest

Interesting, but if I do not use docker and iredmail is installed directly on host, everything is ok, so it seems that my problem somehow has a relation to docker or host<->docker :) Unfortunately right now I do not have time to play with postfix, because I am under the pressure of 2 projects. I wanted to use dockered version of iredmail because in this case I could install anything else on the same server next to iredmail, but as I do not have much time to play with it right now, my workaround is a server specially reserved for iredmail, which costs just 2 euro\month :)

TitanFighter commented 5 years ago

Checked the current version of iredmail-docker. Mail Delivery Report (Delivery Status Notification) works.

The differences between tests in April and today are:

  1. Ubuntu 16.04 -> 18.04;
  2. Docker 18.03.0-ce -> 18.09.0-ce;
  3. Updated iredmail-docker itself;
  4. Changes in command:
    • docker run -p 80:80 -p 443:443 \ -> docker run --privileged -p 80:80 -p 443:443 \
    • -e "DOMAIN=myrealdomain.com" -e "HOSTNAME=mail" \ -> -h myrealdomain.com \