[Dovecot] dovecot 2.0 -> 2.2.1 sieve problem

[Trever L. Adams]

On 05/15/2013 09:18 AM, Timo Sirainen wrote:
> On 15.5.2013, at 18.05, Trever L. Adams <trever at middleearth.sapphiresunday.org> wrote:
>
>> I have been racking my brain trying to figure out why some may not see
>> what I am seeing. The only odd part of my configuration that others may
>> not have is:
>>
>> import_environment = TZ KRB5CCNAME=...
>>
>> This was added, if I remember right, at the request of myself and
>> another so that LDAP configuration could identify with GSSAPI base
>> kerberos. I do use it.
> Can't really be related.
>
>> userdb {
>>  args = /etc/dovecot/dovecot-ldap.conf.ext
>>  driver = ldap
>> }
> What does this file contain?

hosts = DOMAIN
base = dc=middleearth,dc=sapphiresunday,dc=org
ldap_version = 3
user_attrs =  userPrincipalName=user
user_filter =
(&(objectClass=person)(|(mail=%u)(sAMAccountName=%u)(userPrincipalName=%u)))
dn = MX$@DOMAIN
sasl_bind = yes
sasl_mech = GSSAPI
sasl_realm = DOMAIN
#sasl_authz_id = MX$@DOMAIN
# For using doveadm -A:
iterate_attrs = userPrincipalName=user
iterate_filter = (objectClass=person)

This configuration works for everything but sieve. It used to work for
everything.
>
> What do you get in logs with auth_debug=yes and mail_debug=yes?
>
>

with auth_debug=yes and mail_debug=yes

May 15 09:20:17 MX postfix/cleanup[13965]: 695311409F9:
message-id=<20130515152017.695311409F9 at MX.DOMAIN>
May 15 09:20:17 MX opendkim[650]: 695311409F9: DKIM-Signature header
added (s=default, d=DOMAIN)
May 15 09:20:17 MX postfix/qmgr[759]: 695311409F9: from=<root at DOMAIN>,
size=562, nrcpt=1 (queue active)
May 15 09:20:17 MX dovecot: lmtp(14233): Debug: none: root=, index=,
indexpvt=, control=, inbox=, alt=
May 15 09:20:17 MX dovecot: lmtp(14233): Connect from local
May 15 09:20:17 MX dovecot: lmtp(14233): Debug: Loading modules from
directory: /usr/lib64/dovecot
May 15 09:20:17 MX dovecot: lmtp(14233): Debug: Module loaded:
/usr/lib64/dovecot/lib90_sieve_plugin.so
May 15 09:20:17 MX dovecot: auth: Debug: Loading modules from directory:
/usr/lib64/dovecot/auth
May 15 09:20:17 MX dovecot: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libdriver_sqlite.so
May 15 09:20:17 MX dovecot: auth: Debug: Loading modules from directory:
/usr/lib64/dovecot/auth
May 15 09:20:17 MX dovecot: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libmech_gssapi.so
May 15 09:20:17 MX dovecot: auth: Debug: Loading modules from directory:
/usr/lib64/dovecot/auth
May 15 09:20:17 MX dovecot: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libauthdb_ldap.so
May 15 09:20:17 MX dovecot: auth: Debug: Read auth token secret from
/var/run/dovecot/auth-token-secret.dat
May 15 09:20:17 MX dovecot: auth: Debug: master in:
USER#0111#011trever at DOMAIN#011service=lmtp
May 15 09:20:17 MX dovecot: auth: Debug: ldap(trever at DOMAIN): user
search: base=dc=middleearth,dc=sapphiresunday,dc=org scope=subtree
filter=(&(objectClass=person)(|(mail=trever at DOMAIN)(sAMAccountName=trever at DOMAIN)(userPrincipalName=trever at DOMAIN)))
fields=userPrincipalName
May 15 09:20:17 MX dovecot: auth: Debug: ldap(trever at DOMAIN): result:
userPrincipalName=trever at DOMAIN; userPrincipalName unused
May 15 09:20:17 MX dovecot: auth: Debug: auth(trever at DOMAIN): username
changed trever at DOMAIN -> trever at DOMAIN
May 15 09:20:17 MX dovecot: auth: Debug: ldap(trever at DOMAIN): result:
userPrincipalName=trever at DOMAIN
May 15 09:20:17 MX dovecot: auth: Debug: userdb out:
USER#0111#011trever at DOMAIN
May 15 09:20:17 MX dovecot: lmtp(14233): Debug: auth input: trever at DOMAIN
May 15 09:20:17 MX dovecot: lmtp(14233): Debug: changed username to
trever at DOMAIN
May 15 09:20:17 MX dovecot: lmtp(14233): Debug: Added userdb setting:
plugin/=yes
May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN): Debug: Effective
uid=500, gid=500, home=/home/vmail/DOMAIN/trever
May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN): Debug: Namespace
inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN): Debug:
maildir++: root=/home/vmail/DOMAIN/trever/Maildir, index=, indexpvt=,
control=, inbox=/home/vmail/DOMAIN/trever/Maildir, alt=
May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN): Debug:
qDM7HrGnk1GZNwAApwKjnA: sieve: executed before user's personal Sieve
script(1): (null)
May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN): Debug:
qDM7HrGnk1GZNwAApwKjnA: sieve: executed before user's personal Sieve
script(2): (null)

I don't think the above two lines are accurate that the scripts ran. I
have one that should stuff anything from heirloom mail client into a
folder (to test things) and it isn't working.

May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN): Debug:
qDM7HrGnk1GZNwAApwKjnA: sieve: using the following location for user's
Sieve script: /home/vmail/DOMAIN/trever/.dovecot.sieve;name=main script
May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN): Debug:
qDM7HrGnk1GZNwAApwKjnA: sieve: opening script (null)
May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN): Error:
qDM7HrGnk1GZNwAApwKjnA: sieve: binary open: failed to open: open((null))
failed: Bad address
May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN): Error:
qDM7HrGnk1GZNwAApwKjnA: sieve: failed to stat sieve script: stat((null))
failed: Bad address
May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN): Error:
qDM7HrGnk1GZNwAApwKjnA: sieve: parse failed
May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN): Error:
qDM7HrGnk1GZNwAApwKjnA: sieve: failed to open script (null)
May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN):
qDM7HrGnk1GZNwAApwKjnA: sieve:
msgid=<20130515152017.695311409F9 at MX.DOMAIN>: stored mail into mailbox
'INBOX'
May 15 09:20:17 MX dovecot: lmtp(14233, trever at DOMAIN): Error:
qDM7HrGnk1GZNwAApwKjnA: sieve: execution of script (null) failed, but
implicit keep was successful
May 15 09:20:17 MX postfix/lmtp[14023]: 695311409F9: to=<trever at DOMAIN>,
orig_to=<trever>,
relay=MX.DOMAIN[/var/spool/postfix/private/dovecot-lmtp], delay=0.43,
delays=0.25/0/0.01/0.17, dsn=2.0.0, status=sent (250 2.0.0
<trever at DOMAIN> qDM7HrGnk1GZNwAApwKjnA Saved)
May 15 09:20:17 MX dovecot: lmtp(14233): Disconnect from local:
Successful quit
May 15 09:20:17 MX postfix/qmgr[759]: 695311409F9: removed


Thank you,
Trever