Re: Strange "IMAP connection broken (server response)" errors

2018-03-20 Thread Aki Tuomi


On 20.03.2018 10:16, Kadlecsik József wrote:
> On Fri, 20 Oct 2017, Kadlecsik József wrote:
>
>> On Fri, 6 Oct 2017, Jozsef Kadlecsik wrote:
>>
>>> We upgraded one of our dovecot servers to debian stretch with dovecot 
>>> 2.2.27 and since then one of our users has been experiencing random IMAP 
>>> failures.
>>>
>>> On the client side the user runs alpine and the corresponding debug lines:
>>>
>>> IMAP DEBUG 14:22:02.216167: 0011 FETCH 6 (BODYSTRUCTURE FLAGS)
>>>
>>> 14:22:02.217396
>>> IMAP 14:22:02 10/6 mm_notify bye: 
>>> {[127.0.0.1]:1555/imap/user="ha4aa"}INBOX: [CLOSED] IMAP connection broken 
>>> (server response)
>> The date of the last rawlog line corresponds to an ssl debug log of 
>> dovecot (from the last run):
>>
>> Oct 20 18:50:05 mail2 dovecot: imap-login: Debug: SSL error: SSL_read() 
>> failed: error:140E0197:SSL routines:SSL_shutdown:shutdown while in init
> It is an openssl compatibility issue introduced in OpenSSL 1.0.2f. The 
> IMAP failures could be solved with the following patches, which are 
> similar to what nginx uses (http://hg.nginx.org/nginx/rev/062c189fee20):
>
> For Dovecot 2.2.35:
>
> diff --git a/src/lib-ssl-iostream/iostream-openssl.c 
> b/src/lib-ssl-iostream/iostream-openssl.c
> index 68ec221..31d1017 100644
> --- a/src/lib-ssl-iostream/iostream-openssl.c
> +++ b/src/lib-ssl-iostream/iostream-openssl.c
> @@ -324,7 +324,7 @@ static void openssl_iostream_unref(struct ssl_iostream 
> *ssl_io)
>  
>  static void openssl_iostream_destroy(struct ssl_iostream *ssl_io)
>  {
> - if (SSL_shutdown(ssl_io->ssl) != 1) {
> + if (!SSL_in_init(ssl_io->ssl) && SSL_shutdown(ssl_io->ssl) != 1) {
>   /* if bidirectional shutdown fails we need to clear
>  the error queue */
>   openssl_iostream_clear_errors();
> diff --git a/src/login-common/ssl-proxy-openssl.c 
> b/src/login-common/ssl-proxy-openssl.c
> index 947c8ef..3ac6823 100644
> --- a/src/login-common/ssl-proxy-openssl.c
> +++ b/src/login-common/ssl-proxy-openssl.c
> @@ -833,7 +833,7 @@ void ssl_proxy_destroy(struct ssl_proxy *proxy)
>   if (proxy->io_plain_write != NULL)
>   io_remove(&proxy->io_plain_write);
>  
> - if (SSL_shutdown(proxy->ssl) != 1) {
> + if (!SSL_in_init(proxy->ssl) && SSL_shutdown(proxy->ssl) != 1) {
>   /* if bidirectional shutdown fails we need to clear
>  the error queue. */
>   openssl_iostream_clear_errors();
>
> For Dovecot master branch:
>
> diff --git a/src/lib-ssl-iostream/iostream-openssl.c 
> b/src/lib-ssl-iostream/iostream-openssl.c
> index 45de412..ed1f0a4 100644
> --- a/src/lib-ssl-iostream/iostream-openssl.c
> +++ b/src/lib-ssl-iostream/iostream-openssl.c
> @@ -345,7 +345,7 @@ static void openssl_iostream_unref(struct ssl_iostream 
> *ssl_io)
>  
>  static void openssl_iostream_destroy(struct ssl_iostream *ssl_io)
>  {
> - if (SSL_shutdown(ssl_io->ssl) != 1) {
> + if (!SSL_in_init(ssl_io->ssl) && SSL_shutdown(ssl_io->ssl) != 1) {
>   /* if bidirectional shutdown fails we need to clear
>  the error queue */
>   openssl_iostream_clear_errors();
>
> Best regards,
> Jozsef
> --
> E-mail : kadlecsik.joz...@wigner.mta.hu
> PGP key: http://www.kfki.hu/~kadlec/pgp_public_key.txt
> Address: Wigner Research Centre for Physics, Hungarian Academy of Sciences
>  H-1525 Budapest 114, POB. 49, Hungary
Hi!

Thank you for your patch, we'll look into it.

Aki


Re: Strange "IMAP connection broken (server response)" errors

2018-03-20 Thread Kadlecsik József
On Fri, 20 Oct 2017, Kadlecsik József wrote:

> On Fri, 6 Oct 2017, Jozsef Kadlecsik wrote:
> 
> > We upgraded one of our dovecot servers to debian stretch with dovecot 
> > 2.2.27 and since then one of our users has been experiencing random IMAP 
> > failures.
> > 
> > On the client side the user runs alpine and the corresponding debug lines:
> > 
> > IMAP DEBUG 14:22:02.216167: 0011 FETCH 6 (BODYSTRUCTURE FLAGS)
> > 
> > 14:22:02.217396
> > IMAP 14:22:02 10/6 mm_notify bye: 
> > {[127.0.0.1]:1555/imap/user="ha4aa"}INBOX: [CLOSED] IMAP connection broken 
> > (server response)
> 
> The date of the last rawlog line corresponds to an ssl debug log of 
> dovecot (from the last run):
> 
> Oct 20 18:50:05 mail2 dovecot: imap-login: Debug: SSL error: SSL_read() 
> failed: error:140E0197:SSL routines:SSL_shutdown:shutdown while in init

It is an openssl compatibility issue introduced in OpenSSL 1.0.2f. The 
IMAP failures could be solved with the following patches, which are 
similar to what nginx uses (http://hg.nginx.org/nginx/rev/062c189fee20):

For Dovecot 2.2.35:

diff --git a/src/lib-ssl-iostream/iostream-openssl.c 
b/src/lib-ssl-iostream/iostream-openssl.c
index 68ec221..31d1017 100644
--- a/src/lib-ssl-iostream/iostream-openssl.c
+++ b/src/lib-ssl-iostream/iostream-openssl.c
@@ -324,7 +324,7 @@ static void openssl_iostream_unref(struct ssl_iostream 
*ssl_io)
 
 static void openssl_iostream_destroy(struct ssl_iostream *ssl_io)
 {
-   if (SSL_shutdown(ssl_io->ssl) != 1) {
+   if (!SSL_in_init(ssl_io->ssl) && SSL_shutdown(ssl_io->ssl) != 1) {
/* if bidirectional shutdown fails we need to clear
   the error queue */
openssl_iostream_clear_errors();
diff --git a/src/login-common/ssl-proxy-openssl.c 
b/src/login-common/ssl-proxy-openssl.c
index 947c8ef..3ac6823 100644
--- a/src/login-common/ssl-proxy-openssl.c
+++ b/src/login-common/ssl-proxy-openssl.c
@@ -833,7 +833,7 @@ void ssl_proxy_destroy(struct ssl_proxy *proxy)
if (proxy->io_plain_write != NULL)
io_remove(&proxy->io_plain_write);
 
-   if (SSL_shutdown(proxy->ssl) != 1) {
+   if (!SSL_in_init(proxy->ssl) && SSL_shutdown(proxy->ssl) != 1) {
/* if bidirectional shutdown fails we need to clear
   the error queue. */
openssl_iostream_clear_errors();

For Dovecot master branch:

diff --git a/src/lib-ssl-iostream/iostream-openssl.c 
b/src/lib-ssl-iostream/iostream-openssl.c
index 45de412..ed1f0a4 100644
--- a/src/lib-ssl-iostream/iostream-openssl.c
+++ b/src/lib-ssl-iostream/iostream-openssl.c
@@ -345,7 +345,7 @@ static void openssl_iostream_unref(struct ssl_iostream 
*ssl_io)
 
 static void openssl_iostream_destroy(struct ssl_iostream *ssl_io)
 {
-   if (SSL_shutdown(ssl_io->ssl) != 1) {
+   if (!SSL_in_init(ssl_io->ssl) && SSL_shutdown(ssl_io->ssl) != 1) {
/* if bidirectional shutdown fails we need to clear
   the error queue */
openssl_iostream_clear_errors();

Best regards,
Jozsef
--
E-mail : kadlecsik.joz...@wigner.mta.hu
PGP key: http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address: Wigner Research Centre for Physics, Hungarian Academy of Sciences
 H-1525 Budapest 114, POB. 49, Hungary

Re: Strange "IMAP connection broken (server response)" errors

2017-10-20 Thread Kadlecsik József
Hello,

On Fri, 6 Oct 2017, Jozsef Kadlecsik wrote:

> We upgraded one of our dovecot servers to debian stretch with dovecot 
> 2.2.27 and since then one of our users has been experiencing random IMAP 
> failures.
> 
> We enabled raw logging at the server side and it shows normal IMAP 
> commands/responses:
> 
> 1507292522.222427 * 6 FETCH (FLAGS () BODYSTRUCTURE ("text" "plain" 
> ("charset" "us-ascii")
>  NIL NIL "7bit" 4645 112 NIL NIL NIL NIL))
> 1507292522.222653 0011 OK Fetch completed (0.006 + 0.000 secs).
> 
> On the client side the user runs alpine and the corresponding debug lines:
> 
> IMAP DEBUG 14:22:02.216167: 0011 FETCH 6 (BODYSTRUCTURE FLAGS)
> 
> 14:22:02.217396
> IMAP 14:22:02 10/6 mm_notify bye: 
> {[127.0.0.1]:1555/imap/user="ha4aa"}INBOX: [CLOSED] IMAP connection broken 
> (server response)
> 
> 14:22:02.217471
> IMAP 14:22:02 10/6 mm_log error: [CLOSED] IMAP connection broken (server 
> response)
> 
> The "[127.0.0.1]:1555/imap/user="ha4aa" part in the log comes from an 
> socat inserted between the client and the server to check independently 
> the imap session. According to socat, the server response didn't reach 
> the client!:
> 
> 0010 OK Fetch completed (0.005 + 0.000 secs).\r
> > 2017/10/06 14:22:02.216299  length=40 from=845 to=884
> 0011 FETCH 6 (BODYSTRUCTURE FLAGS)\r
> 
> and here ends the socat log.

The date of the last rawlog line corresponds to an ssl debug log of 
dovecot (from the last run):

Oct 20 18:50:05 mail2 dovecot: imap-login: Debug: SSL error: SSL_read() 
failed: error:140E0197:SSL routines:SSL_shutdown:shutdown while in init

I added the patch "openssl: Clear error queue after an incomplete 
SSL_shutdown", recompiled the package but it did not help.

Any help is highly welcomed!

Best regards,
Jozsef
--
E-mail : kadlecsik.joz...@wigner.mta.hu
PGP key: http://www.kfki.hu/~kadlec/pgp_public_key.txt
Address: Wigner Research Centre for Physics, Hungarian Academy of Sciences
 H-1525 Budapest 114, POB. 49, Hungary