dovecot - Jun 2012 - Problem with lmtp director proxy

Hi,

	I have a timeout problem only when I have heavy load in my system. I 
have two director servers directing to 4 backend servers.

	The problem is when my smtp relays tries to deliver mail to my users 
via lmtp (proxied with director).

	In the smtp logs I have:

Jun 12 11:41:18 xenon13 postfix/lmtp[4248]: 4433E5D5A0: 
to=<myuser at um.es>, relay=pop.um.es[155.54.212.106]:24, delay=31, 
delays=0.41/0.06/0/30, dsn=4.4.0, status=deferred (host 
pop.um.es[155.54.212.106] said: 451 4.4.0 Remote server not answering 
(timeout while waiting for reply to DATA reply) (in reply to end of DATA 
command))

	If I look for this connection in the director servers I have:

Jun 12 11:40:39 myotis41 dovecot: lmtp(6595): Connect from 155.54.212.167
Jun 12 11:40:39 myotis41 dovecot: lmtp(6595): Debug: auth input: 
user=user1 proxy host=155.54.211.163 proxy_refresh=450
Jun 12 11:40:39 myotis41 dovecot: lmtp(6595): Debug: auth input: 
user=user2 proxy host=155.54.211.163 proxy_refresh=450
....  (more users, a total of 34 recipients)
Jun 12 11:40:39 myotis41 dovecot: lmtp(6595): Debug: auth input: 
user=myuser proxy host=155.54.211.164 proxy_refresh=450
...
Jun 12 11:41:09 myotis41 dovecot: lmtp(6595): Disconnect from 
155.54.212.167: Client quit (in reset)

	and in one of the final server (the one for the user in question):

Jun 12 11:40:38 myotis34 dovecot: lmtp(16824): Connect from 155.54.211.186
Jun 12 11:40:38 myotis34 dovecot: lmtp(16824, <user1>): wJ9BD7YM10
+4QQAAG5O5Qg: sieve: 
msgid=<182283367.48.1339494011054.JavaMail.tomcat at sakai-prod4>: stored 
mail into mailbox 'INBOX'
...
Jun 12 11:41:10 myotis34 dovecot: lmtp(16824, <myuser>): wJ9BD7YM10+4QQA
AG5O5Qg: sieve: 
msgid=<182283367.48.1339494011054.JavaMail.tomcat at sakai-prod4>: stored 
mail into mailbox 'INBOX'
...
Jun 12 11:41:11 myotis34 dovecot: lmtp(16824): Disconnect from 
155.54.211.186: Connection closed (in reset)

	So the mail seems to be correctly delivered in about 30 seconds. All my 
postfix timeouts are bigger than this time:

lmtp_connect_timeout = 0s
lmtp_connection_cache_time_limit = 2s
lmtp_connection_reuse_time_limit = 300s
lmtp_data_done_timeout = 600s
lmtp_data_init_timeout = 120s
lmtp_data_xfer_timeout = 180s
lmtp_lhlo_timeout = 300s
lmtp_mail_timeout = 300s
lmtp_pix_workaround_delay_time = 10s
lmtp_pix_workaround_threshold_time = 500s
lmtp_quit_timeout = 300s
lmtp_rcpt_timeout = 300s
lmtp_rset_timeout = 20s
lmtp_sasl_auth_cache_time = 90d
lmtp_starttls_timeout = 300s
lmtp_tls_session_cache_timeout = 3600s
lmtp_xforward_timeout = 300s

	So... why do I have this error?

	As a side effect this mail was delivered twice in the user's  mailbox, 
this is one and the other when postfix retries again.

	Any help? Thank you


-- 
Angel L. Mateo Mart?nez
Secci?n de Telem?tica
?rea de Tecnolog?as de la Informaci?n       _o)
y las Comunicaciones Aplicadas (ATICA)      / \\
http://www.um.es/atica                    _(___V
Tfo: 868887590
Fax: 868888337

On Tue, Jun 12, 2012 at 12:23:28PM +0200, Angel L. Mateo
wrote:
> I have two director servers directing to 4 backend servers.
Which dovecot version are you running on your directors and backends?

We're running 2.0.14 plus the below linked patches and have not
since this problem since applying the last one.


	http://hg.dovecot.org/dovecot-2.0/raw-rev/8de8752b2e94
	http://hg.dovecot.org/dovecot-2.0/rev/71084b799a6c


  -jf

Hi,

	I have checked in almost every error I had that the error is produced 
whenever happens a timeout of 30 seconds between opening the connection 
between the director and backend server and the final delivery of the 
message in the user's mailbox.

	When I have mails with just a few of recipients, I have no problem 
because this 30 seconds timeout is never reached. But when I have mails 
with more recipients and my storage has workload it is sometimes reached.

	But I haven't found any configuration for this 30 seconds timeout. What 
could it be this option? Because I have configured proxy_timeout=120 in 
proxy configuration:

pass_attrs = 
irisMailbox=userdb_mail,homeDirectory=userdb_home,uidNumber=userdb_uid,gidNumber=userdb_gid,=proxy=y,=proxy_timeout=120,irisMailHost=host


	Looking for this timeout in the code, I have found these defines:

director/director.c:#define DIRECTOR_RECONNECT_TIMEOUT_MSECS (30*1000)
director/director.c:#define DIRECTOR_USER_MOVE_TIMEOUT_MSECS (30*1000)
director/director-connection.c:#define 
DIRECTOR_CONNECTION_SEND_USERS_TIMEOUT_MSECS (30*1000)
director/director-connection.c:#define 
DIRECTOR_CONNECTION_DONE_TIMEOUT_MSECS (30*1000)
director/director-request.c:#define DIRECTOR_REQUEST_TIMEOUT_SECS 30

lmtp/commands.c:#define LMTP_PROXY_DEFAULT_TIMEOUT_MSECS (1000*30)

	Could it be one of these timeouts? In this case... is there any way to 
configure it without changing code?

-- 
Angel L. Mateo Mart?nez
Secci?n de Telem?tica
?rea de Tecnolog?as de la Informaci?n       _o)
y las Comunicaciones Aplicadas (ATICA)      / \\
http://www.um.es/atica                    _(___V
Tfo: 868887590
Fax: 868888337