1

I was facing the problem that postfix could not deliver emails to my home-directory. I have a running Ubuntu 14.04 server and due to some problem with encrypted home-drive postfix was not able to access my Maildir.

In mail.log I got the following error:

Apr  4 09:51:35 server postfix/smtpd[13658]: connect from localhost[127.0.0.1]
Apr  4 09:51:35 server postfix/smtpd[13658]: 6FE354360A18: client=localhost[127.0.0.1]
Apr  4 09:51:35 server postfix/cleanup[13661]: 6FE354360A18: message-id=<57021a4f72db3_e5d5127d8cc173209@hermes-1.mail>
Apr  4 09:51:36 server postfix/smtpd[13658]: disconnect from localhost[127.0.0.1]
Apr  4 09:51:36 server postfix/qmgr[2085]: 6FE354360A18: from=<mailrobot@xing.com>, size=87170, nrcpt=1 (queue active)
Apr  4 09:51:36 server postfix/local[13664]: warning: maildir access problem for UID/GID=1000/1000: create maildir file /home/user/Maildir/tmp/1459756296.P13664.server: Permission denied
Apr  4 09:51:36 server postfix/local[13664]: warning: perhaps you need to create the maildirs in advance
Apr  4 09:51:36 server postfix/local[13664]: 6FE354360A18: to=<andreas@localhost>, relay=local, delay=0.95, delays=0.88/0.01/0/0.06, dsn=5.2.0, status=bounced (maildir delivery failed: create maildir file /home/user/Maildir/tmp/1459756296.P13664.server: Permission denied)
Apr  4 09:51:36 server postfix/cleanup[13661]: 668984360A1A: message-id=<20160404075136.668984360A1A@server>
Apr  4 09:51:36 server postfix/bounce[13665]: 6FE354360A18: sender non-delivery notification: 668984360A1A
Apr  4 09:51:36 server postfix/qmgr[2085]: 668984360A1A: from=<>, size=4544, nrcpt=1 (queue active)
Apr  4 09:51:36 server postfix/qmgr[2085]: 6FE354360A18: removed
Apr  4 09:51:36 server postfix/smtp[13666]: 668984360A1A: to=<mailrobot@xing.com>, relay=smtp.otherserver.org:587, delay=0.54, delays=0.19/0.05/0.23/0.07, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as C979113D0138)
Apr  4 09:51:36 server postfix/qmgr[2085]: 668984360A1A: removed

I rebooted the server and hoped to find the emails which were sent in the meantime in /var/mail/xxx but there was only a zero byte file with my username.

Does this mean that the emails which I received in the meantime are lost? How can I configure that emails are saved?

EDIT: mailq shows empty mail queue. EDIT2: added more log output

mercury
  • 41
  • 3

2 Answers2

2

It should be in the mail queue

Send a simple email

# echo "Hello world" | swaks -4 --server smtp.example.net --from alex.hha@gmail.com --to sf-768072@example.net --h-Subject "Test message" --body -
=== Trying smtp.example.net:25...
=== Connected to smtp.example.net.
<-  220 smtp.example.net ESMTP Postfix
 -> EHLO tl-resin-node1.example.net
<-  250-smtp.example.net
<-  250-PIPELINING
<-  250-SIZE 10240000
<-  250-VRFY
<-  250-ETRN
<-  250-AUTH LOGIN PLAIN
<-  250-ENHANCEDSTATUSCODES
<-  250-8BITMIME
<-  250 DSN
 -> MAIL FROM:<alex.hha@gmail.com>
<-  250 2.1.0 Ok
 -> RCPT TO:<sf-768072@example.net>
<-  250 2.1.5 Ok
 -> DATA
<-  354 End data with <CR><LF>.<CR><LF>
 -> Date: Tue, 05 Apr 2016 03:45:43 -0400
 -> To: sf-768072@example.net
 -> From: alex.hha@gmail.com
 -> Subject: Test message
 -> X-Mailer: swaks v20130209.0 jetmore.org/john/code/swaks/
 ->
 -> Hello world
 ->
 ->
 -> .
<-  250 2.0.0 Ok: queued as 581271C1811
 -> QUIT
<-  221 2.0.0 Bye
=== Connection closed with remote host.

Check maillog on the smtp.example.net

# cat /var/log/maillog | grep 581271C1811
Apr  5 07:45:41 ci postfix/smtpd[31639]: 581271C1811: client=smtp.example.com[192.168.88.130]
Apr  5 07:45:41 ci postfix/cleanup[31642]: 581271C1811: message-id=<>
Apr  5 07:45:41 ci postfix/qmgr[31633]: 581271C1811: from=<alex.hha@gmail.com>, size=389, nrcpt=1 (queue active)
Apr  5 07:45:41 ci postfix/virtual[31643]: 581271C1811: to=<sf-768072@example.net>, relay=virtual, delay=0.07, delays=0.02/0.01/0/0.04, dsn=4.2.0, status=deferred (maildir delivery failed: create maildir file /var/mail/virtual/example.net/sf-768072@example.net/tmp/1459842341.P31643.ci.example.net: Permission denied)

Check maillog

# postqueue -p
-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
581271C1811      389 Tue Apr  5 07:45:41  alex.hha@gmail.com
(maildir delivery failed: create maildir file /var/mail/virtual/example.net/sf-768072@example.net/tmp/1459842341.P31643.ci.example.net: Permission denied)
                                         sf-768072@example.net

-- 1 Kbytes in 1 Request.

Fix the permissions

# ls -la
total 16
drwxr-xr-x  4 alex alex 4096 Mar 18 14:32 .
drwxrwxr-x. 3 root mail 4096 Apr  2 03:35 ..
drwx------  3 virtual virtual 4096 Mar 15 09:18 example.com
drwx------  3 root    virtual 4096 Mar 18 14:32 example.net

# chown virtual:virtual example.net

Flush the mail queue and check maillog again

# postqueue -f

Apr  5 07:49:01 ci postfix/anvil[31640]: statistics: max cache size 1 at Apr  5 07:45:41
Apr  5 07:49:29 ci postfix/qmgr[31633]: 581271C1811: from=<alex.hha@gmail.com>, size=389, nrcpt=1 (queue active)
Apr  5 07:49:29 ci postfix/virtual[31894]: 581271C1811: to=<sf-768072@example.net>, relay=virtual, delay=228, delays=228/0.02/0/0.06, dsn=2.0.0, status=sent (delivered to maildir)
Apr  5 07:49:29 ci postfix/qmgr[31633]: 581271C1811: removed
ALex_hha
  • 7,025
  • 1
  • 23
  • 39
  • I am using a different SMTP for relaying so this example cannot be applied here - sorry. – mercury Apr 05 '16 at 16:46
  • It doesn't matter. By default these emails should be in the mail queue. Because error code was 4xx - it means that error is temporary and mail server should keep such emails in mail queue. – ALex_hha Apr 05 '16 at 20:56
  • But "postqueue -f" did not deliver mails :-( – mercury Apr 06 '16 at 16:12
1

TLDR: By default behaviour of postfix, your email was bounced (i.e. your sender will get non-delivery message) and postfix won't keep the email even in the queue.


Based on both logs from mercury and ALex_hha, I can concluded that there are different behavior when mail was delivered by virtual daemon (ALex_hha case) or local daemon (mercury case). When virtual daemon can't deliver email because of permission issue, it will use defer the email (soft bounce), so the email stays in queue.

Apr 5 07:45:41 ci postfix/virtual[31643]: 581271C1811: to=<sf-768072@example.net>, relay=virtual, delay=0.07, delays=0.02/0.01/0/0.04, dsn=4.2.0, status=deferred (maildir delivery failed: create maildir file /var/mail/virtual/example.net/sf-768072@example.net/tmp/1459842341.P31643.ci.example.net: Permission denied)

In the other case, local daemon will bounced the email (hard bounce) so the email doesn't stay in queue.

Apr 4 09:51:36 server postfix/local[13664]: 6FE354360A18: to=<andreas@localhost>, relay=local, delay=0.95, delays=0.88/0.01/0/0.06, dsn=5.2.0, status=bounced (maildir delivery failed: create maildir file /home/user/Maildir/tmp/1459756296.P13664.server: Permission denied)

This behavior can also viewed when you peek in source of virtual/maildir.c and local/maildir.c in line with dsb_simple function.

local/maildir.c

    dsb_simple(why, mbox_dsn(errno, "5.2.0"),
           "create maildir file %s: %m", tmpfile);

virtual/maildir.c

    dsb_simple(why, mbox_dsn(errno, "4.2.0"),
           "create maildir file %s: %m", tmpfile);

How can I prevent hard bounce in this case?

AFAIK based on above source code, this behavior was unconfigurable via postfix main.cf. But try to set soft_bounce = yes, but beware of the global effect when you enable this feature.

masegaloeh
  • 17,978
  • 9
  • 56
  • 104