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

Sun Jan 1 01:07:45 UTC 2017

Enable the  IMAP debug log in imp's backends.php file so we can see  
the IMAP conversation.

--
mike
Sent from mobile
________________________________
From: Torben Dannhauer <torben at dannhauer.info>
Sent: Dec 31, 2016 5:11 PM
To: dovecot at listen.jpberlin.de; horde at lists.horde.org
Subject: [horde] Strange error accessing emails via activesync -  
crashes dovecot. Accessing the same mailbox via IMAp works as expected.

> 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
>
>
>
>
>
>
>
>
>
>
>
> --
> Horde mailing list
> Frequently Asked Questions: http://horde.org/faq/
> To unsubscribe, mail: horde-unsubscribe at lists.horde.org
>