Postfix - Dovecot SASL problem

[Petr Holub]

Hi,

I'm using mail/postfix with WITH_DOVECOT2=yes and mail/dovecot2 with MySQL
backend for users from FreeBSD ports:
dovecot-2.0.12
postfix-2.8.4,1

I'm unable to get SMTP authentication working using Dovecot SASL with
----
postfix/main.cf:
----
...
smtpd_sasl_type = dovecot
smtpd_sasl_path = private/auth
smtpd_sasl_auth_enable = yes
smtpd_sasl_security_options = noanonymous, noplaintext
smtpd_sasl_tls_security_options = noanonymous
...
----
dovecot/dovecot.conf
----
...
userdb {
  args = /usr/local/etc/dovecot/dovecot-mysql.conf
  driver = sql
}
passdb {
  args = /usr/local/etc/dovecot/dovecot-mysql.conf
  driver = sql
}
service auth {
  unix_listener /var/spool/postfix/private/auth {
    group = postfix
    mode = 0660
    user = postfix
  }
}
...
----
Postfix works fine if the SASL Auth is turned off. Dovecot works
fine per se for accessing mailboxes via POP3 and IMAP.

When attempting to use Dovecot for SMTP SASL auth, what I get is 
----
2011-08-18 23:31:57auth: Debug: Loading modules from directory: /usr/local/lib/dovecot/auth
Aug 18 23:31:57 mail postfix/smtpd[57411]: fatal: no SASL authentication mechanisms
2011-08-18 23:31:57auth: Debug: auth client connected (pid=57411)
Aug 18 23:31:58 mail postfix/master[57398]: warning: process /usr/local/libexec/postfix/smtpd pid
57411 exit status 1
Aug 18 23:31:58 mail postfix/master[57398]: warning: /usr/local/libexec/postfix/smtpd: bad command
startup -- throttling
----
even though postfix starts to talk to dovecot accroding to ktrace:
----
 57671 smtpd    CALL  connect(0xe,0x7fffffffd870,0x6a)
 57671 smtpd    STRU  struct sockaddr { AF_LOCAL, private/auth }
 57671 smtpd    NAMI  "private/auth"
 57671 smtpd    RET   connect 0
 57671 smtpd    CALL  fcntl(0xe,F_GETFL,0)
 57671 smtpd    RET   fcntl 6
 57671 smtpd    CALL  fcntl(0xe,F_SETFL,O_RDWR)
 57671 smtpd    RET   fcntl 0
 57671 smtpd    CALL  gettimeofday(0x801434770,0)
 57671 smtpd    RET   gettimeofday 0
 57671 smtpd    CALL  getpid
 57671 smtpd    RET   getpid 57671/0xe147
 57671 smtpd    CALL  poll(0x7fffffffd860,0x1,0x2710)
 57671 smtpd    RET   poll 1
 57671 smtpd    CALL  write(0xe,0x80144f010,0x17)
 57671 smtpd    GIO   fd 14 wrote 23 bytes
       "VERSION 1       0
        CPID    57671
       "
 57671 smtpd    RET   write 23/0x17
 57671 smtpd    CALL  gettimeofday(0x801434770,0)
 57671 smtpd    RET   gettimeofday 0
 57671 smtpd    CALL  poll(0x7fffffffd850,0x1,0x2710)
 57671 smtpd    RET   poll 1
 57671 smtpd    CALL  read(0xe,0x80144f010,0x1000)
 57671 smtpd    GIO   fd 14 read 117 bytes
       "VERSION 1       1
        MECH    PLAIN   plaintext
        MECH    LOGIN   plaintext
        SPID    57672
        CUID    1
        COOKIE  acc0b5dcc32aed19ae3e6823ad91bc42
        DONE
       "
 57671 smtpd    RET   read 117/0x75
 57671 smtpd    CALL  gettimeofday(0x801434770,0)
 57671 smtpd    RET   gettimeofday 0
 57671 smtpd    CALL  gettimeofday(0x7fffffffca80,0)
 57671 smtpd    RET   gettimeofday 0
 57671 smtpd    CALL  getpid
 57671 smtpd    RET   getpid 57671/0xe147
 57671 smtpd    CALL  sendto(0x7,0x7fffffffcac0,0x52,0,0,0)
 57671 smtpd    GIO   fd 7 wrote 82 bytes
       "<18>Aug 18 23:33:35 postfix/smtpd[57671]: fatal: no SASL authentication mechanisms"
 57671 smtpd    RET   sendto 82/0x52
----

Any ideas where could be the problem?

TIA,
Petr