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

Mon Jan 2 11:18:26 UTC 2017

Zitat von Michael J Rubinsky <mrubinsk at horde.org>:

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

is debug sufficient, or do is debug_raw better?

thanks,
Torben

>
> --
> 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
>>