Strange error accessing emails via activesync - crashes dovecot. Accessing the same mailbox via IMAp works as expected.

Sa Dez 31 23:11:43 CET 2016

Hi,

in my old PHP 5.6 Horde Setup, I have a client with activeSync errors: The
users iphone (several devices, so it is device independent) stopps syncing
emails premature and throws warnings in Horde and crashes the dovecot mail
server. When accessing the emails via pure imap (webmailer or imap client),
everything works as expected. 

The Horde logs a lot of this errors ("The email server reported an error"):

2016-12-31T22:30:48+01:00 ERR: Der E-Mail-Server hat einen IMAP-Fehler
gemeldet.

2016-12-31T22:30:48+01:00 ERR: [19643] Unknown backend error skipping
message: Der E-Mail-Server hat einen IMAP-Fehler gemeldet.

2016-12-31T22:30:48+01:00 ERR: [19643] Unable to fetch message: Der
E-Mail-Server hat einen IMAP-Fehler gemeldet.

2016-12-31T22:30:48+01:00 ERR: Der E-Mail-Server hat einen IMAP-Fehler
gemeldet.

, usually followed by

2016-12-31T22:32:22+01:00 ERR: [21693]
Horde_ActiveSync_Collections::getBackendIdForFolderUid failed because folder
was not found in cache.

I watched simultaneous the imap server's standard log and got lots of this
messages:

Dec 31 22:42:54 jeeves dovecot: imap-login: Login: user=<user at domain.tld>,
method=PLAIN, rip=IPv6-ADDRESS, lip=IPv6-ADDRESS, mpid=24524, TLS, TLSv1.2
with cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)

Dec 31 22:42:54 jeeves dovecot: imap(user at domain.tld): Disconnected: Logged
out in=6119 out=6906

Dec 31 22:42:55 jeeves dovecot: imap-login: Login: user=<user at domain.tld>,
method=PLAIN, rip=IPv6-ADDRESS, lip=IPv6-ADDRESS, mpid=24526, TLS, TLSv1.2
with cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)

Dec 31 22:42:55 jeeves dovecot: imap(user at domain.tld): Disconnected: Logged
out in=2757 out=78187

Dec 31 22:42:55 jeeves dovecot: imap-login: Login: user=<user at domain.tld>,
method=PLAIN, rip=IPv6-ADDRESS, lip=IPv6-ADDRESS, mpid=24528, TLS, TLSv1.2
with cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)

Dec 31 22:42:55 jeeves dovecot: imap(user at domain.tld): Disconnected: Logged
out in=6119 out=7995

Dec 31 22:42:56 jeeves dovecot: imap-login: Login: user=<user at domain.tld>,
method=PLAIN, rip=IPv6-ADDRESS, lip=IPv6-ADDRESS, mpid=24530, TLS, TLSv1.2
with cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)

Dec 31 22:42:56 jeeves dovecot: imap(user at domain.tld): Disconnected: Logged
out in=2585 out=89960

Dec 31 22:42:56 jeeves dovecot: imap-login: Login: user=<user at domain.tld>,
method=PLAIN, rip=IPv6-ADDRESS, lip=IPv6-ADDRESS, mpid=24532, TLS, TLSv1.2
with cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)

Dec 31 22:42:56 jeeves dovecot: imap(user at domain.tld): Disconnected: Logged
out in=6119 out=9188

Is it normal that EAS uasage triggers a high frequency of imap
logins/logouts?

Additionally I observerd in the mailservers error log the following crash
report (happens immediatly after the hi frequency logins stop):

Dec 31 22:46:58 jeeves dovecot: imap(user at domain.tld): Panic: file
istream-qp-decoder.c: line 102 (i_stream_qp_decoder_read): assertion failed:
(ret < 0)

Dec 31 22:46:58 jeeves dovecot: imap(user at domain.tld): Error: Raw backtrace:
/usr/lib/dovecot/libdovecot.so.0(+0x6b6fe) [0x7fc2481d66fe] ->
/usr/lib/dovecot/libdovecot.so.0(+0x6b7ec) [0x7fc2481d67ec] ->
/usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7fc24818d8fb] ->
/usr/lib/dovecot/libdovecot.so.0(+0x58c2f) [0x7fc2481c3c2f] ->
/usr/lib/dovecot/libdovecot.so.0(i_stream_read+0x53) [0x7fc2481df7b3] ->
/usr/lib/dovecot/libdovecot.so.0(+0x7a08a) [0x7fc2481e508a] ->
/usr/lib/dovecot/libdovecot.so.0(+0x7a1e5) [0x7fc2481e51e5] ->
/usr/lib/dovecot/libdovecot.so.0(+0x7a383) [0x7fc2481e5383] ->
/usr/lib/dovecot/libdovecot.so.0(i_stream_read+0x53) [0x7fc2481df7b3] ->
/usr/lib/dovecot/libdovecot.so.0(i_stream_read_data+0x3d) [0x7fc2481e007d]
-> /usr/lib/dovecot/libdovecot-storage.so.0(+0xa139e) [0x7fc2484e639e] ->
/usr/lib/dovecot/libdovecot-storage.so.0(index_mail_get_binary_stream+0x76)
[0x7 fc2484e6876] ->
/usr/lib/dovecot/libdovecot-storage.so.0(mail_get_binary_stream+0x5e)
[0x7fc2484bd42e] ->
/usr/lib/dovecot/libdovecot-storage.so.0(imap_msgpart_open+0x139)
[0x7fc24851e5e9] -> dovecot/imap [user at domain.tld IPv6-ADDRESS UID
FETCH](+0x1c0de) [0x7fc2489a50de] -> dovecot/imap [user at domain.tld
IPv6-ADDRESS UID FETCH](+0x1a85a) [0x7fc2489a385a] -> dovecot/imap
[user at domain.tld IPv6-ADDRESS UID FETCH](imap_fetch_more+0x37)
[0x7fc2489a4957] -> dovecot/imap [user at domain.tld IPv6-ADDRESS UID
FETCH](cmd_fetch+0x340) [0x7fc248998070] -> dovecot/imap [user at domain.tld
IPv6-ADDRESS UID FETCH](command_exec+0x3c) [0x7fc2489a209c] -> dovecot/imap
[user at domain.tld IPv6-ADDRESS UID FETCH](+0x17fb2) [0x7fc2489a0fb2] ->
dovecot/imap [user at domain.tld IPv6-ADDRESS UID FETCH](+0x18066)
[0x7fc2489a1066] -> dovecot/imap [user at domain.tld IPv6-ADDRESS UID
FETCH](client_handle_input+0x13d) [0x7fc2489a139d] -> dovecot/imap
[user at domain.tld IPv6-ADDRESS UID FETCH](client_input+0x85) [0x7fc2489a1745]
-> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x3f) [0x7fc2481e7d0f]
-> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0xf9)
[0x7fc2481e8d09] ->
/usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x9) [0x7fc2481e7d79]
-> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7fc2481e7df8] ->
/usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7fc248192dc3]

Dec 31 22:46:58 jeeves dovecot: imap(user at domain.tld): Fatal: master:
service(imap): child 24952 killed with signal 6 (core dumps disabled)

What makes dovecot crash when using exchange activesync, but it works as
expected when using imap directly? What does horde EAS while accing the imap
backend?

My setup is: 

Debian Jessie

Dovecot 2.2.13-12

Apache 2.4.10

PHP 5.6.29

Horde current stable releases

Has anyone a idea where to go on searching? It seems a bit strange and I'm
currently out of ideas..

Ill sent this in copy to dovecot list.  

Thanks and happy new year!

Torben

-------------- nächster Teil --------------
Ein Dateianhang mit HTML-Daten wurde abgetrennt...
URL: <https://listen.jpberlin.de/pipermail/dovecot/attachments/20161231/8e3710ac/attachment.html>