[Dovecot] Problem with lmtp director proxy

[Angel L. Mateo]

El 13/06/12 17:17, Timo Sirainen escribió:
> On Wed, 2012-06-13 at 16:57 +0200, Angel L. Mateo wrote:
>> 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
>
> That says proxy_refresh, not proxy_timeout.
>
>> 	but I have checked with newer errors, all I see in logs are "Connect
>> from" and "Disconnect from" messages. The logs "lmtp...Debug:" are not
>> produced any more (maybe because director has this information yet?)
>
> Director shouldn't affect it. There should still be auth input lines
> logged. doveconf -n?
>
	Ok, you were right. I was looking for logs at my log repository, which 
doesn't receive debug log. Nevertheless, the only auth lines I have 
found at the ones above, with the proxy_refresh=450. I haven't found any 
line with a timeout log in the proxies neither the backends

	So, at director servers the only logs I have are the one I have already 
sent. At the backend server, I have more logs, that are:

Jun 12 11:40:38 myotis34 dovecot: lmtp(16824): Debug: none: root=, 
index=, control=, inbox=, alt=
Jun 12 11:40:38 myotis34 dovecot: lmtp(16824): Connect from 155.54.211.186
Jun 12 11:40:38 myotis34 dovecot: lmtp(16824): Debug: auth input: user1 
home=<user1 home> uid=261853 gid=1001
Jun 12 11:40:38 myotis34 dovecot: lmtp(16824): Debug: auth input: 
<user2> home=<user2's home> uid=262339 gid=1001

...   (more recipients for the same message)

Jun 12 11:40:38 myotis34 dovecot: lmtp(16824): Debug: auth input: 
<myuser> home=<myuser's home> uid=255606 gid=1001
...   (more recipients for the same message)

Jun 12 11:41:08 myotis34 dovecot: lmtp(16824, <myuser>): Debug: 
Effective uid=255606, gid=1001, home=<myuser's home>
Jun 12 11:41:08 myotis34 dovecot: lmtp(16824, <myuser>): Debug: 
maildir++: root=<myuser's home>/Maildir, index=/var/indexes/<myuser>, 
control=, inbox=<myuser's home>/Maildir, alt=
Jun 12 11:41:08 myotis34 dovecot: lmtp(16824, <myuser>): Debug: sieve: 
include: sieve_global_dir is not set; it is currently not possible to 
include `:global' scripts.
Jun 12 11:41:08 myotis34 dovecot: lmtp(16824, <myuser>): Debug: 
wJ9BD7YM10+4QQAAG5O5Qg: sieve: using sieve path for user's script: 
<myuser's home>/.dovecot.sieve
Jun 12 11:41:08 myotis34 dovecot: lmtp(16824, <myuser>): Debug: 
wJ9BD7YM10+4QQAAG5O5Qg: sieve: opening script <myuser's home>/.dovecot.sieve
Jun 12 11:41:08 myotis34 dovecot: lmtp(16824, <myuser>): Debug: 
wJ9BD7YM10+4QQAAG5O5Qg: sieve: script binary <myuser's 
home>/.dovecot.svbin successfully loaded
Jun 12 11:41:08 myotis34 dovecot: lmtp(16824, <myuser>): Debug: 
wJ9BD7YM10+4QQAAG5O5Qg: sieve: binary save: not saving binary <myuser's 
home>/.dovecot.svbin, because it is already stored
Jun 12 11:41:08 myotis34 dovecot: lmtp(16824, <myuser>): Debug: 
wJ9BD7YM10+4QQAAG5O5Qg: sieve: executing script from <myuser's 
home>/.dovecot.svbin
Jun 12 11:41:10 myotis34 dovecot: lmtp(16824, <myuser>): 
wJ9BD7YM10+4QQAAG5O5Qg: 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)

	I have attached output of doveconf -n.

	What I have observed is that problem ocurrs when I have mails with lot 
of recipients, and happens to all recipients which data ends more than 
30 seconds after the connection was established. Maybe this timeout has 
to be counted since the begining of the data command, not the 
establishment of the tcp connection, or, if this is another timer, the 
first should be greater.
-------------- next part --------------
# 2.1.5: /etc/dovecot/dovecot.conf
# OS: Linux 3.2.0-24-generic x86_64 Ubuntu 12.04 LTS 
auth_cache_size = 20 M
auth_cache_ttl = 1 days
auth_debug = yes
auth_master_user_separator = *
auth_username_format = %n
auth_verbose = yes
default_process_limit = 1000
director_mail_servers = 155.54.211.161-155.54.211.164
director_servers = 155.54.211.185 155.54.211.186
disable_plaintext_auth = no
lmtp_proxy = yes
log_timestamp = %Y-%m-%d %H:%M:%S
mail_debug = yes
passdb {
  args = /etc/dovecot/master-users
  driver = passwd-file
  master = yes
  pass = yes
}
passdb {
  args = proxy=y nopassword=y
  driver = static
}
passdb {
  args = session=yes dovecot
  driver = pam
}
plugin {
  sieve = ~/.dovecot.sieve
  sieve_dir = ~/sieve
  sieve_extensions = +imapflags
  sieve_max_redirects = 15
}
service anvil {
  client_limit = 2003
}
service auth {
  client_limit = 3000
  unix_listener auth-userdb {
    mode = 0666
  }
}
service director {
  fifo_listener login/proxy-notify {
    mode = 0666
  }
  inet_listener {
    port = 9090
  }
  unix_listener director-userdb {
    mode = 0600
  }
  unix_listener login/director {
    mode = 0666
  }
}
service imap-login {
  executable = imap-login director
}
service imap {
  process_limit = 5120
  process_min_avail = 6
}
service lmtp {
  inet_listener lmtp {
    port = 24
  }
  process_min_avail = 10
}
service pop3-login {
  executable = pop3-login director
}
ssl = no
ssl_cert = </etc/ssl/certs/dovecot.pem
ssl_key = </etc/ssl/private/dovecot.pem
userdb {
  driver = prefetch
}
userdb {
  args = /etc/dovecot/dovecot-ldap.conf.ext
  driver = ldap
}
protocol lmtp {
  auth_socket_path = director-userdb
}