dovecot - Mar 2011 - dovecot LDA: "temporary failure"

This really has me stumped and desperate.  I upgraded Debian from 5
to 6 (squeeze) and now Dovecot LDA fails.  I have checked permissions
and the usual.  Postfix SMTP, Dovecot POP3 and Dovecot IMAP work.
Having to upgrade MySQL from 5.0 to 5.1 made me question that.  Logging is
of little help.  I have turned on logging for LDA to a separate file.

When I try to run the deliver command it returns nothing and appears to do
nothing:

~$ cat /etc/hosts | /usr/lib/dovecot/deliver -f root at localhost -d
dkoski@[domainhidden].com
$

..but then I don't know what to expect.

The log files are owned by dovecot.  I tried chmod'ing them to 777 in
desperation.

This was working before the upgrade to 1.2.15-4 from 1.0.15-2.3+lenny1.

Postfix reports this stuff:

Mar 17 22:37:38 host-mail postfix/smtpd[22160]: connect from
mail.kosmosisland.com[63.228.175.169]
Mar 17 22:37:39 host-mail postfix/smtpd[22160]: 9D80C12AF610:
client=mail.kosmosisland.com[63.228.175.169]
Mar 17 22:37:39 host-mail postfix/cleanup[22163]: 9D80C12AF610:
message-id=<201103172237.29223.dkoski@[another-domainhidden].com>
Mar 17 22:37:39 host-mail postfix/qmgr[21877]: 9D80C12AF610:
from=<dkoski@[another-domainhidden].com>, size=1257, nrcpt=1 (queue
active)
Mar 17 22:37:39 host-mail postfix/smtpd[22160]: disconnect from
mail.kosmosisland.com[63.228.175.169]
Mar 17 22:37:42 host-mail postfix/smtpd[22168]: connect from
localhost[127.0.0.1]
Mar 17 22:37:42 host-mail postfix/smtpd[22168]: 480D912AF612:
client=mail.kosmosisland.com[63.228.175.169]
Mar 17 22:37:42 host-mail postfix/cleanup[22163]: 480D912AF612:
message-id=<201103172237.29223.dkoski@[another-domainhidden].com>
Mar 17 22:37:42 host-mail postfix/qmgr[21877]: 480D912AF612:
from=<dkoski@[another-domainhidden].com>, size=1873, nrcpt=1 (queue
active)
Mar 17 22:37:42 host-mail postfix/smtpd[22168]: disconnect from
localhost[127.0.0.1]
Mar 17 22:37:42 host-mail postfix/pipe[22169]: 480D912AF612:
to=<dkoski@[domainhidden].com>, relay=dovecot, delay=0.04,
delays=0.02/0.01/0/0.01, dsn=4.3.0, status=deferred (temporary failure)
Mar 17 22:37:42 host-mail postfix/smtp[22164]: 9D80C12AF610:
to=<dkoski@[domainhidden].com>, relay=127.0.0.1[127.0.0.1]:10024,
delay=3.4,
delays=0.84/0.01/0/2.5, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=11197-13, from
MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as
480D912AF612)
Mar 17 22:37:42 host-mail postfix/qmgr[21877]: 9D80C12AF610: removed

And /var/log/dovecot/deliver.info:

2011-03-17 22:43:43 auth(default): Info: new auth connection: pid=22232
2011-03-17 22:43:59 auth-worker(default): Info:
sql(dkoski@[domainhidden].com,127.0.0.1): query: SELECT email as user, password
FROM
view_users WHERE email='dkoski@[domainhidden].com';
2011-03-17 22:43:59 auth(default): Info: client out: OK 1      
user=dkoski@[domainhidden].com
2011-03-17 22:43:59 auth(default): Info: master in: REQUEST     73      22061  
1
2011-03-17 22:43:59 auth(default): Info: master out: USER       73     
dkoski@[domainhidden].com    uid=5000        gid=5000
home=/home/vmail/[domainhidden].com/dkoski
2011-03-17 22:44:00 auth(default): Info: new auth connection: pid=22234

I tried reinstalling the package dovecot-common.  I downloaded it on another
machine and compared the md5sum.

# postconf -n
alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
append_dot_mydomain = no
biff = no
config_directory = /etc/postfix
content_filter = smtp-amavis:[127.0.0.1]:10024
delay_warning_time = 1h
inet_interfaces = all
mailbox_size_limit = 0
mydestination = backup.host.localnet, backup.localnet, localhost.localnet,
localhost
myhostname = mail.[domainhidden].com
mynetworks = 192.168.1.0/24, 127.0.0.1
myorigin = /etc/mailname
recipient_delimiter = +
relayhost smtp_tls_session_cache_database =
btree:${queue_directory}/cache/smtp_scache
smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)
smtpd_recipient_restrictions = permit_mynetworks,      
permit_sasl_authenticated,      reject_unauth_pipelining,
reject_non_fqdn_recipient,      reject_unknown_recipient_domain,       
reject_unauth_destination
smtpd_sasl_auth_enable = yes
smtpd_sasl_path = private/auth
smtpd_sasl_type = dovecot
smtpd_sender_restrictions = permit_mynetworks,  permit_sasl_authenticated,   
reject_unknown_reverse_client_hostname,
reject_non_fqdn_sender, reject_unknown_sender_domain,   reject_rbl_client
b.barracudacentral.org,      reject_rbl_client zen.spamhaus.org,
reject_rbl_client cbl.abuseat.org,      reject_rbl_client dnsbl.njabl.org,     
reject_rbl_client combined.njabl.org,   reject_rbl_client
bl.spamcop.net,      reject_rbl_client spamguard.leadmon.net,       
reject_rbl_client korea.services.net,   reject_rbl_client
spamsources.fabel.dk, reject_rhsbl_sender rhsbl.ahbl.org
smtpd_tls_cert_file = /etc/ssl/certs/ssl-cert-snakeoil.pem
smtpd_tls_key_file = /etc/ssl/private/ssl-cert-snakeoil.key
smtpd_tls_session_cache_database = btree:${queue_directory}/cache/smtpd_scache
smtpd_use_tls = yes
virtual_alias_maps =
mysql:/etc/postfix/mysql-virtual-alias-maps.cf,mysql:/etc/postfix/mysql-email2email.cf
virtual_gid_maps = static:5000
virtual_mailbox_domains = mysql:/etc/postfix/mysql-virtual-mailbox-domains.cf
virtual_mailbox_maps = mysql:/etc/postfix/mysql-virtual-mailbox-maps.cf
virtual_transport = dovecot
virtual_uid_maps = static:5000

From master.cf:

dovecot   unix  -       n       n       -       -       pipe
    flags=DRhu user=vmail:vmail argv=/usr/lib/dovecot/deliver -d ${recipient}

# dovecot -n
# 1.2.15: /etc/dovecot/dovecot.conf
# OS: Linux 2.6.32-5-686 i686 Debian 6.0 ext3
log_path: /var/log/dovecot/deliver.err
info_log_path: /var/log/dovecot/deliver.info
log_timestamp: %Y-%m-%d %H:%M:%S
protocols: imap pop3
disable_plaintext_auth: no
login_dir: /var/run/dovecot/login
login_executable(default): /usr/lib/dovecot/imap-login
login_executable(imap): /usr/lib/dovecot/imap-login
login_executable(pop3): /usr/lib/dovecot/pop3-login
mail_privileged_group: mail
mail_location: maildir:/home/vmail/%d/%n/Maildir
mail_debug: yes
mbox_write_locks: fcntl dotlock
mail_executable(default): /usr/lib/dovecot/imap
mail_executable(imap): /usr/lib/dovecot/imap
mail_executable(pop3): /usr/lib/dovecot/pop3
mail_plugin_dir(default): /usr/lib/dovecot/modules/imap
mail_plugin_dir(imap): /usr/lib/dovecot/modules/imap
mail_plugin_dir(pop3): /usr/lib/dovecot/modules/pop3
lda:
  log_path: /var/log/dovecot/lda-deliver.err
  info_log_path: /var/log/dovecot/lda-deliver.info
  log_path: /home/vmail/dovecot-deliver.log
  auth_socket_path: /var/run/dovecot/auth-master
  postmaster_address: info@[another-domainhidden].com
  mail_plugins: cmusieve
  global_script_path: /home/vmail/globalsieverc
auth default:
  mechanisms: plain login
  verbose: yes
  debug: yes
  passdb:
    driver: sql
    args: /etc/dovecot/dovecot-sql.conf
  userdb:
    driver: static
    args: uid=5000 gid=5000 home=/home/vmail/%d/%n allow_all_users=yes
  socket:
    type: listen
    client:
      path: /var/spool/postfix/private/auth
      mode: 432
      user: postfix
      group: postfix
    master:
      path: /var/run/dovecot/auth-master
      mode: 384
      user: vmail

Regards,
David Koski
david at kosmosisland.com

Additional information:

I created a script to get the return code from deliver:

  1 #!/bin/bash
  2
  3 cat "cur/1300037582.P7332Q0M221160.brusco-mail:2,S" | 
/usr/lib/dovecot/deliver -f dkoski at somedomain.com -d dkoski at
domainhidden.com
  4
  5 case $? in
  6     0) echo "0"
  7     ;;
  8     64) echo "64"
  9     ;;
 10     67) echo "67"
 11     ;;
 12     78) echo "78"
 13     ;;
 14     77) echo "77"
 15     ;;
 16     75) echo "75"
 17     ;;
 18     *) echo "unknown"
 19 esac
 20

The file it is cat'ing is a valid email in an Maildir/cur file.  It returns
75
(EX_TEMP_FAIL) every time, even run as root.  The logs reveal:

/var/log/dovecot/lda-deliver:

2011-03-17 23:35:39 deliver(dkoski at somedomain2.com): Info: Loading modules 
from directory: /usr/lib/dovecot/modules/lda

/var/log/dovecot/deliver.info:
(nothing)

/var/log/dovecot/deliver.err:
(nothing)

I tried the script on another machine with Dovecot 1.0.15-2.3+lenny1 with 
success if I run as root.

Regards,
David Koski
dkoski at sutinen.com
> This really has me stumped and desperate.  I upgraded Debian from 5...
<snip>

Forget it.  I must have been crosseyed.  Someone had put the log file in a 
non-standard place /home/vmail/dovecot-deliver.log.  It told all.  A plugin 
cmusieve was not found, possibly depreciated?

I learned how to make the deliver command line work. ;)

Sorry,
David Koski
dkoski at sutinen.com
> Additional information:
> 
> I created a script to get the return code from deliver:
> 
>   1 #!/bin/bash
>   2
>   3 cat "cur/1300037582.P7332Q0M221160.brusco-mail:2,S" |
> /usr/lib/dovecot/deliver -f dkoski at somedomain.com -d
> dkoski at domainhidden.com 4
>   5 case $? in
>   6     0) echo "0"
>   7     ;;
>   8     64) echo "64"
>   9     ;;
>  10     67) echo "67"
>  11     ;;
>  12     78) echo "78"
>  13     ;;
>  14     77) echo "77"
>  15     ;;
>  16     75) echo "75"
>  17     ;;
>  18     *) echo "unknown"
>  19 esac
>  20
> 
> The file it is cat'ing is a valid email in an Maildir/cur file.  It
returns
> 75 (EX_TEMP_FAIL) every time, even run as root.  The logs reveal:
> 
> /var/log/dovecot/lda-deliver:
> 
> 2011-03-17 23:35:39 deliver(dkoski at somedomain2.com): Info: Loading
modules
> from directory: /usr/lib/dovecot/modules/lda
> 
> /var/log/dovecot/deliver.info:
> (nothing)
> 
> /var/log/dovecot/deliver.err:
> (nothing)
> 
> I tried the script on another machine with Dovecot 1.0.15-2.3+lenny1 with
> success if I run as root.
> 
> Regards,
> David Koski
> dkoski at sutinen.com
> 
> > This really has me stumped and desperate.  I upgraded Debian from 5...
> 
> <snip>