Sporadically deferred mail, followed by 456 Address temporarily unavailable

Norbert Harrer <[email protected]>
Newsgroups gmane.mail.imap.courier.general
Message-ID <[email protected]>
Hi.

I am using the Courier mail server on Debian 11:

 > dpkg -l | grep courier
ii  courier-authdaemon 0.71.1-2                                     
amd64        Courier authentication daemon
ii  courier-authlib 0.71.1-2                                     
amd64        Courier authentication library
ii  courier-authlib-mysql 0.71.1-2                                     
amd64        MySQL support for the Courier authentication library
ii  courier-authlib-userdb 0.71.1-2                                     
amd64        userdb support for the Courier authentication library
ii  courier-base 1.0.16-3                                     
amd64        Courier mail server - base system
ii  courier-doc 1.0.16-3                                     
all          Courier mail server - additional documentation
ii  courier-imap 5.0.13+1.0.16-3                              
amd64        Courier mail server - IMAP server
ii  courier-mta 1.0.16-3                                     
amd64        Courier mail server - ESMTP daemon
ii  courier-pcp 1.0.16-3                                     
amd64        Courier mail server - PCP server
ii  courier-pop 1.0.16-3                                     
amd64        Courier mail server - POP3 server
ii  courier-webadmin 1.0.16-3                                     
amd64        Courier mail server - web-based administration frontend
ii  libcourier-unicode4:amd64 
2.1.2-2                                      amd64        Courier 
Unicode library (shared runtime library)


Every couple of months, an email gets deferred. It happens very rarely. 
Here is the log (I redacted sensitive names with dots):

Oct 12 17:19:18 stargate courieresmtpd: 
started,ip=[::ffff:209.85.167.72],port=[53547]
Oct 12 17:19:19 stargate courierd: 
newmsg,id=000000000214519A.0000000065280E76.002FCD48: dns; 
mail-lf1-f72.google.com (mail-lf1-f72.google.com [::ffff:209.85.167.72])
Oct 12 17:19:19 stargate courierd: 
started,id=000000000214519A.0000000065280E76.002FCD48,from=<[email protected]>,module=local,host=nh.....!!109!114!/var/courier/nh.....!!,addr=<nh.....>
Oct 12 17:19:19 stargate courierd: Waiting.  shutdown time=none, wakeup 
time=none, queuedelivering=1, inprogress=1
Oct 12 17:19:19 stargate courieresmtpd: ip=[::ffff:209.85.167.72], 
Unexpected SSL connection shutdown.
Oct 12 17:19:19 stargate maildrop[3132753]: maildrop started: From: 
......... <[email protected]>, To: s....... Alle 
<[email protected]>, Subject: Letzter Aufruf für's s....... Skifahren, 
Message-ID: 000000000214519A.0000000065280E76.002FCD48; Thu, 12 Oct 2023 
17:19:18 +0200, Maildir: /var/courier/nh...../Maildir
Oct 12 17:19:19 stargate courierlocal: 
id=000000000214519A.0000000065280E76.002FCD48,from=<[email protected]>,addr=<[email protected]>: 
maildrop: authlib: groupid=114
Oct 12 17:19:19 stargate courierlocal: 
id=000000000214519A.0000000065280E76.002FCD48,from=<[email protected]>,addr=<[email protected]>,status: 
deferred
Oct 12 17:19:19 stargate courierd: 
completed,id=000000000214519A.0000000065280E76.002FCD48
Oct 12 17:19:19 stargate courierd: Waiting.  shutdown time=Thu Oct 12 
17:28:32 2023, wakeup time=Thu Oct 12 17:24:19 2023, queuedelivering=1, 
inprogress=0


However, the mail is still delivered locally. Then I find the same log 
messages for the same mail ID nine more times in the log:

Oct 12 17:24:03 stargate courieresmtpd: 
started,ip=[::ffff:141.98.11.68],port=[43698]
Oct 12 17:24:19 stargate courierd: 
started,id=000000000214519A.0000000065280E76.002FCD48,from=<[email protected]>,module=local,host=nh.....!!109!114!/var/courier/nh.....!!,addr=<nh.....>
Oct 12 17:24:19 stargate courierd: Waiting.  shutdown time=none, wakeup 
time=none, queuedelivering=1, inprogress=1
Oct 12 17:24:19 stargate maildrop[3133169]: maildrop started: From: 
......... <[email protected]>, To: s....... Alle 
<[email protected]>, Subject: Letzter Aufruf für's s....... Skifahren, 
Message-ID: 000000000214519A.0000000065280E76.002FCD48; Thu, 12 Oct 2023 
17:19:18 +0200, Maildir: /var/courier/nh...../Maildir
Oct 12 17:24:19 stargate courierlocal: 
id=000000000214519A.0000000065280E76.002FCD48,from=<[email protected]>,addr=<[email protected]>: 
maildrop: authlib: groupid=114
Oct 12 17:24:19 stargate courierlocal: 
id=000000000214519A.0000000065280E76.002FCD48,from=<[email protected]>,addr=<[email protected]>,status: 
deferred
Oct 12 17:24:19 stargate courierd: 
completed,id=000000000214519A.0000000065280E76.002FCD48
Oct 12 17:24:19 stargate courierd: Waiting.  shutdown time=Thu Oct 12 
17:29:19 2023, wakeup time=Thu Oct 12 17:29:19 2023, queuedelivering=1, 
inprogress=0


This typically occurs in 5-minute and one-hour intervals. After 10 
attempts, the mail server seems to give up and doesn't accept any more 
mails. This includes other e-mails as well:

Oct 12 20:04:47 stargate courieresmtpd: 
started,ip=[::ffff:209.85.221.71],port=[45134]
Oct 12 20:04:47 stargate courieresmtpd: 
error,relay=::ffff:209.85.221.71,port=45134,from=<[email protected]>,to=<[email protected]>: 
456 Address temporarily unavailable.
Oct 12 20:04:47 stargate courieresmtpd: 
error,relay=::ffff:209.85.221.71,port=45134,msg="502 ESMTP command 
error",cmd: DATA
Oct 12 20:04:47 stargate courieresmtpd: ip=[::ffff:209.85.221.71], 
Unexpected SSL connection shutdown.


When I check with 'mailq,' I see that this mail is somehow stuck, and I 
can cancel it:

 > mailq
Size             Queue 
ID                                                    Date
User From
Status           Recipient
---------------- ---------------------------------------------------------
11.7K 000000000214519A.0000000065280E76.002FCD48                  Oct 12 
17:19
courier [email protected]
[email protected]

     1 messages.

 >  cancelmsg 000000000214519A.0000000065280E76.002FCD48
Message scheduled for cancellation.


Even though the mail queue is now empty, it takes a couple of hours for 
courieresmtpd to stop sending 456s and receiving e-mails again.

My questions are:

1. How can I find out more about the problem? I've read in this group 
that deferred mails can have many causes, and the preceding message 
should indicate the issue. However, my untrained eye can't spot anything 
suspicious.
2. How can I force courier to recover faster once the troublesome mail 
is removed from the queue? I've tried executing 'courier clear all' and 
restarted all services, but it still took a couple of hours for it to 
accept mails again.

I would be grateful for any tips people could provide.

Thanks,
Norbert

_______________________________________________
courier-users mailing list
[email protected]
Unsubscribe: https://lists.sourceforge.net/lists/listinfo/courier-users
lmpx.com only provides a reader for public news (NNTP) servers. It is not affiliated with the servers or forums shown here and is not responsible for the content of articles, which is written by their respective authors.