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

Tue Jan 3 16:44:31 UTC 2017

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

> Debug should be sufficient.

Hmm

Debugging does not work, did I miss something?

My backends.local.php:

<snip>
$servers['imap'] = array(
     'disabled' => false,
     'name' => 'IMAP Server',
     'hostspec' => 'DOMAIN',
     'hordeauth' => 'full',
     'protocol' => 'imap',
     'port' => 143,
     'secure' => 'tls',
     'maildomain' => 'DOMAIN',
     'cache' => 'cache',
     'acl' => true,
     'preferred' => 'DOMAIN',
     'quota' => array(
         'driver' => 'imap',
     ),
     'smtp' => array(
         'auth' => true,
         'debug' => '/tmp/imap.log',
         'localhost' => 'DOMAIN',
         'host' => 'DOMAIN',
         'password' => null,
         'port' => 25,
         'username' => null
     ),
<snap>

>
> --
> mike
> Sent from mobile
> ________________________________
> From: Torben Dannhauer <torben at dannhauer.info>
> Sent: Jan 2, 2017 6:18 AM
> To: horde at lists.horde.org
> Subject: Re: [horde] Strange error accessing emails via activesync -  
> crashes dovecot. Accessing the same mailbox via IMAp works as  
> expected.
>
>>
>> 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
>>>>
>>
>>
>>
>> -- 
>> Horde mailing list
>> Frequently Asked Questions: http://horde.org/faq/
>> To unsubscribe, mail: horde-unsubscribe at lists.horde.org
>>
>
>
> -- 
> Horde mailing list
> Frequently Asked Questions: http://horde.org/faq/
> To unsubscribe, mail: horde-unsubscribe at lists.horde.org