dovecot - Jul 2015 - Dovecot/Pigeonhole Issue (UTC modtime instead of localtime)

Hi List,

We are using the following setup:

Dovecot-2.2.18
Pigeonhole-0.4.8  (for Dovecot-2.2)

After the mail is finally delivered via a fileinto by the Sieve filter
it gets an updated timestamp (modification time).
The server has localtime setup correctly IMO (UTC +0200), but still the
delivered mail is setup as being two hours old.

I think I found out that the function sieve_file_storage_update_mtime()
is the cause of this problem. But perhaps there has to be some kind of
setup, that tells pigeonhole to use the 2 hour offset of CEST.
I think to reset the mtime by utime(s) is a bit strange. It already gets
the correct modtime just by storing it in the filesystem.

Last version we used (0.2.5) did not have this poblem. So it must be
there for some reason?

Perhaps you can enlighten me.

Thanks for your time.

Greetings

-- 
Sitepark Gesellschaft f?r Informationsmanagement mbH
Rothenburg 14-16, 48143 M?nster

Telefon: +49 251 482655-0, Telefax: +49 251 482655-55
http://www.sitepark.com
http://www.facebook.com/sitepark

Gesch?ftsf?hrer: Thorsten Liebold
Amtsgericht M?nster, HRB 5017

Christoph Gr?ver schreef op 31-7-2015 om 16:01:
> We are using the following setup:
>
> Dovecot-2.2.18
> Pigeonhole-0.4.8  (for Dovecot-2.2)
>
> After the mail is finally delivered via a fileinto by the Sieve filter
> it gets an updated timestamp (modification time).
> The server has localtime setup correctly IMO (UTC +0200), but still the
> delivered mail is setup as being two hours old.
Hmm. Probably, the timezone configuration (i.e. the contents of TZ 
timezone environment variable) somehow doesn't reach the final stages of 
e-mail delivery.
> I think I found out that the function sieve_file_storage_update_mtime()
> is the cause of this problem.
No. That is for the storage of the Sieve scripts and not the delivered 
e-mail. That part is handled by Dovecot lib-storage.
> But perhaps there has to be some kind of
> setup, that tells pigeonhole to use the 2 hour offset of CEST.
> I think to reset the mtime by utime(s) is a bit strange. It already gets
> the correct modtime just by storing it in the filesystem.
>
> Last version we used (0.2.5) did not have this poblem. So it must be
> there for some reason?
That is very old. Many things have changed in the mean time, so this is 
not very helpful in pinpointing what could cause this.

I haven't tried this at my end yet, but - to make sure we have all the 
information we may need - could you enlighten us a bit about your 
configuration? So, what output is produced by `dovecot -n`? How is final 
delivery performed (using LDA or LMTP)?

Regards,

Stephan.

Thanks Stephan for your answer.
> 
> Hmm. Probably, the timezone configuration (i.e. the contents of TZ 
> timezone environment variable) somehow doesn't reach the final stages
of
> e-mail delivery.
Sorry, I just found out we had pigeonhole-0.4.3 running on the old server.
The sources of 0.2.5 were also lying around, but were not used anymore.

On the old and the new server there's no TZ or TIMEZONE variable.
Still the version 0.4.3 together with System V on Mandriva 2010.2 worked and
the systemd version on CentOS 7.1.x sets up the past (2h back) as the modtime
> 
> > I think I found out that the function
sieve_file_storage_update_mtime()
> > is the cause of this problem.
> 
> No. That is for the storage of the Sieve scripts and not the delivered 
> e-mail. That part is handled by Dovecot lib-storage.
I see. Made some assumptions which were wrong.
> 
> I haven't tried this at my end yet, but - to make sure we have all the 
> information we may need - could you enlighten us a bit about your 
> configuration? So, what output is produced by `dovecot -n`? How is final 
> delivery performed (using LDA or LMTP)?
We are delivering mail via  Dovecot-LDA, which calls pigeonhole ...

This is the (relevant) part of 'doveconf -':

-------------------------------------
# 2.2.18: /srv/dovecot-2.2.18/etc/dovecot/dovecot.conf
# Pigeonhole version 0.4.8 (0c4ae064f307+)
# OS: Linux 3.10.0-229.7.2.el7.x86_64 x86_64 CentOS Linux release 7.1.1503
(Core)
auth_debug = yes
auth_debug_passwords = yes
auth_mechanisms = plain login cram-md5
auth_verbose = yes
auth_verbose_passwords = plain
base_dir = /var/run/dovecot-22/
debug_log_path = /var/log/dovecot/dovecot.debug
default_internal_user = someuser
default_login_user = someuser
disable_plaintext_auth = no
info_log_path = /var/log/dovecot/dovecot.log
log_path = /var/log/dovecot/dovecot.err
mail_location = maildir:~/Maildir:INBOX=~/Maildir
mail_plugins = acl
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character
vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy
include variables body enotify environment mailbox date index ihave duplicate
[...]
plugin {
  acl = vfile
  mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename
  mail_log_fields = uid box msgid size
  sieve = /srv/mail/sieve/%n.sieve
  sieve_before = /srv/mail/sieve/spam-filter/%n.sieve
  sieve_dir = ~/sieve
  sieve_global_dir = /srv/mail/sieve/global/
  sieve_global_path = /srv/mail/sieve/default.sieve
}
protocols = imap sieve
service auth {
  unix_listener auth-userdb {
    group = vmail
    mode = 0600
    user = someuser
  }
}
service imap-login {
  inet_listener imap {
    port = 143
  }
  inet_listener imaps {
    port = 993
    ssl = yes
  }
  process_limit = 400
  process_min_avail = 2
}
service imap {
  executable = imap postlogin
  process_limit = 350
}
service postlogin {
  executable = script-login rawlog
  user = someuser
}
[..]
userdb {
  args = uid=someuser gid=vmail home=/srv/mail/someuser/%u
  driver = static
}
userdb {
  args = username_format=%n /etc/dovecot/users
  driver = passwd-file
}
protocol imap {
  mail_max_userip_connections = 30
  mail_plugins = acl imap_acl mail_log notify
}
protocol lda {
  info_log_path = /var/log/dovecot/deliver.log
  log_path = /var/log/dovecot/deliver.err
  mail_plugins = sieve
}

-------------------------------


I had a look at lib-storage of dovecot, which also has calls for utime in it.

Well, I yet fail to understand why this could be useful or necessary.
After I write the file it already has the correct modtime. Absolutely no need to
fiddle around with utime - IMHO.

If I create a file by just touching it like 'touch SOMEFILE' it has the
correct current localtime as modtime.
Why should I change this to two hours in the past?
I still can't see the reason for this behaviour. Perhaps some IMAP
requirement I don't know of?

Hope you can elighten me and/or help me.

Thank you for your time.

-- 
Christoph Gr?ver

Hallo Stephan,
> 
> Hmm. Probably, the timezone configuration (i.e. the contents of TZ 
> timezone environment variable) somehow doesn't reach the final stages
of
> e-mail delivery.
I investigated further.

I just did a telnet into the server and discoverered that dovecot knows the
localtime. If I ask for the INTERNALDATE of a message the 2 hour offset of
CEST is actually in the response:

a fetch 166 INTERNALDATE        
* 166 FETCH (INTERNALDATE "02-Aug-2015 20:18:21 +0200")
a OK Fetch completed (0.000 secs).

See? The message above actually  arrived at the server at 22:18 localtime.
The Date-Header is set accordingly.

The file modtime is being set to 20:18 of that day (for whatever reason).
So the server responds with that time and adds the correct TZ offset (2
hours). So my assumption is that dovecot knows that we are at CEST (+0200).

It's a maildir storage and the mails are received by netqmail-1.06.
The last dovecot which we were using was version 2.2.14.

With this version and system init and Mandriva 2010.2 we didn't have this
kind of problem.
I'd really like to understand this because some apple clients are having
huge
problems with the hours old INTERNALDATE.


Thank you for your time.

Greetings

-- 
Christoph Gr?ver

Hello ML, Hello Stephan,
> Hmm. Probably, the timezone configuration (i.e. the contents of TZ 
> timezone environment variable) somehow doesn't reach the final stages
> of e-mail delivery.
Well. I tried several ways of telling the lda or whatever is setting up
the INTERNALDATE to use the CEST +0200. 
Although it is already setup on the server via a symlink
from /etc/localtime to /usr/share/zoneinfo/Europe/Berlin, I defined it
at several stages, for example globally and for the account of the
virtual user of the mails. But all of it to no avail.
It just keeps getting a mtime in the past.

So I actually had to patch the sources. I commented out the utime calls
of src/lib-storage/index/maildir/maildir-save.c .
This way the file gets the correct mtime.

Still the clients saw the wrong INTERNALDATE.
I also had to completely disable writing a index.cache by dovecot.

Both are not ideal in my opinion. I'd still prefer a real solution.
But for the moment I had to do it because my users became "desperate".

If you have any ideas left, please tell me. I'd still like to here them.

Thank you.

Greetings

-- 
Sitepark Gesellschaft f?r Informationsmanagement mbH
Rothenburg 14-16, 48143 M?nster

Telefon: +49 251 482655-0, Telefax: +49 251 482655-55
http://www.sitepark.com
http://www.facebook.com/sitepark

Gesch?ftsf?hrer: Thorsten Liebold
Amtsgericht M?nster, HRB 5017