pop3-login core dump when using TLSSTART on version dovecot-2.2.32 (INTERNAL)

[Aki Tuomi]

Can you outline the exact steps you perform to get this?

Aki

On 11.09.2017 13:42, Arvid.Eikas at telenor.com wrote:
> Hi,
>
> I switched back to 2.2.27 with the same config that I am using for 2.2.32 and it work fine.  
>
> Sep 11 11:49:37 imap-login: Info: Login: user=<viboge>, method=PLAIN, rip=88.89.118.45, lip=148.123.160.116, mpid=18709, TLS, session=<v7o22OZYrsdYWXYt>
> Sep 11 11:49:40 imap(mailuser) Session-ID v7o22OZYrsdYWXYt RemoteIP 88.89.118.45  Maildir /var/nextmail/nfs2.flex14/49/79/841 Info: Logged out in=4518 out=273720 deleted 0 expunged 0 trashed 0
> Sep 11 11:49:40 imap-login: Debug: SSL alert: close notify [88.89.118.45]
>
> How could I proceed?  Any clue?  It is quite annoying to see this entry in the log for each session.
>
> Arvid
>
>
>
>
> -----Original Message-----
> From: Aki Tuomi [mailto:aki.tuomi at dovecot.fi] 
> Sent: 11. september 2017 09:18
> To: Eikås Arvid; dovecot at dovecot.org
> Subject: Re: pop3-login core dump when using TLSSTART on version dovecot-2.2.32 (INTERNAL)
>
> Hi!
>
> I tried to reproduce this problem with dovecot-2.2.32 and OpenSSL 1.0.1k and was not able to. I enabled -DREF_CHECK on OpenSSL, but to no avail, the process did not crash. Is there something else you've done?
>
> Aki
>
>
> On 11.09.2017 08:07, Arvid.Eikas at telenor.com wrote:
>> Hi,
>>
>> Here is the gdb output.
>>
>> Arvid
>>
>> GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-94.el7 Copyright (C) 2013 
>> Free Software Foundation, Inc.
>> License GPLv3+: GNU GPL version 3 or later 
>> <http://gnu.org/licenses/gpl.html>
>> This is free software: you are free to change and redistribute it.
>> There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
>> and "show warranty" for details.
>> This GDB was configured as "x86_64-redhat-linux-gnu".
>> For bug reporting instructions, please see:
>> <http://www.gnu.org/software/gdb/bugs/>...
>> Reading symbols from /local/misc/mail/dovecot-32/libexec/dovecot/pop3-login...done.
>> [New LWP 15894]
>> Core was generated by `dovecot-test/pop3-login'.
>> Program terminated with signal 6, Aborted.
>> #0  0x00007ff0bd9cf1d7 in raise () from /lib64/libc.so.6 Missing 
>> separate debuginfos, use: debuginfo-install 
>> glibc-2.17-157.el7_3.1.x86_64
>> (gdb) bt full
>> #0  0x00007ff0bd9cf1d7 in raise () from /lib64/libc.so.6 No symbol 
>> table info available.
>> #1  0x00007ff0bd9d08c8 in abort () from /lib64/libc.so.6 No symbol 
>> table info available.
>> #2  0x00007ff0bd3c0f2f in engine_unlocked_finish (e=0x1c51c60, unlock_for_handlers=1) at eng_init.c:115
>>         to_return = 1
>> #3  0x00007ff0bd3c1064 in ENGINE_finish (e=0x1c51c60) at eng_init.c:150
>>         to_return = 1
>> #4  0x00007ff0be0f9300 in ssl_proxy_deinit () from 
>> /local/nextmail/dovecot/lib64/dovecot/libdovecot-login.so.0
>> No symbol table info available.
>> #5  0x00007ff0be0f4472 in main_deinit () from 
>> /local/nextmail/dovecot/lib64/dovecot/libdovecot-login.so.0
>> No symbol table info available.
>> #6  0x00007ff0be0f479f in login_binary_run () from 
>> /local/nextmail/dovecot/lib64/dovecot/libdovecot-login.so.0
>> No symbol table info available.
>> #7  0x00000000004032da in main (argc=1, argv=0x7ffe3059f3f8) at 
>> client.c:356 No locals.
>>
>>
>>
>> -----Original Message-----
>> From: Aki Tuomi [mailto:aki.tuomi at dovecot.fi]
>> Sent: 8. september 2017 14:08
>> To: Eikås Arvid; dovecot at dovecot.org
>> Subject: Re: pop3-login core dump when using TLSSTART on version 
>> dovecot-2.2.32 (OPEN)
>>
>> I assume you mean STARTTLS. Can you provide gdb /path/to/bin /path/to/core and provide output of bt full?
>>
>> Aki
>>
>>
>> On 08.09.2017 15:01, Arvid.Eikas at telenor.com wrote:
>>> Hi,
>>>
>>> Pop3-login are CORE-dumping when I log on with TLSSTART, I believe the same will happen with imap-logon to, but I have not tested it yet.
>>> The TLS session is coming up and it works fine until I log off, then it's core dump.  Open sslvesrion is   openssl-1.0.2k.
>>> We ran dovecot-2.2.27 before we upgraded to dovecote-2.2.32, and that 
>>> seems to work fine. (not core dumping)
>>>
>>>
>>> Arvid
>>>
>>>
>>> LOG
>>> Sep 05 14:27:34 pop3-login: Debug: SSL: elliptic curve secp384r1 will 
>>> be used for ECDH and ECDHE key exchanges Sep 05 14:30:30 pop3-login:
>>> Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE 
>>> key exchanges Sep 05 14:30:30 pop3-login: Debug: SSL: elliptic curve
>>> secp384r1 will be used for ECDH and ECDHE key exchanges Sep 05
>>> 14:30:42 pop3-login: Debug: SSL: elliptic curve secp384r1 will be 
>>> used for ECDH and ECDHE key exchanges Sep 05 14:30:42 pop3-login: Debug:
>>> SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key 
>>> exchanges Sep 05 14:30:50 pop3-login: Info: Login: user=<tstrand>, 
>>> method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=18361, secured, 
>>> session=<65m8ZXBYtpN/AAAB> Sep 05 14:30:50 pop3-login: Error:
>>> ENGINE_finish, bad functional reference count Sep 05 14:30:50
>>> pop3-login: Fatal: master: service(pop3-login): child 18359 killed 
>>> with signal 6 (core dumped)
>>>
>>>
>>>
>>>
>>>
>>>
>>> From  ./crypto/engine/eng_init.c
>>>
>>> .........
>>> int engine_unlocked_finish(ENGINE *e, int unlock_for_handlers) {
>>>     int to_return = 1;
>>>
>>>     /*
>>>      * Reduce the functional reference count here so if it's the terminating
>>>      * case, we can release the lock safely and call the finish() handler
>>>      * without risk of a race. We get a race if we leave the count until
>>>      * after and something else is calling "finish" at the same time -
>>>      * there's a chance that both threads will together take the count from 2
>>>      * to 0 without either calling finish().
>>>      */
>>>     e->funct_ref--;
>>>     engine_ref_debug(e, 1, -1);
>>>     if ((e->funct_ref == 0) && e->finish) {
>>>         if (unlock_for_handlers)
>>>             CRYPTO_w_unlock(CRYPTO_LOCK_ENGINE);
>>>         to_return = e->finish(e);
>>>         if (unlock_for_handlers)
>>>             CRYPTO_w_lock(CRYPTO_LOCK_ENGINE);
>>>         if (!to_return)
>>>             return 0;
>>>     }
>>> #ifdef REF_CHECK
>>>     if (e->funct_ref < 0) {
>>>         fprintf(stderr, "ENGINE_finish, bad functional reference count\n");
>>>         abort();
>>>
>>> .........
>>>
>>> /* The API (locked) version of "finish" */ int ENGINE_finish(ENGINE
>>> *e) {
>>>     int to_return = 1;
>>>
>>>     if (e == NULL) {
>>>         ENGINEerr(ENGINE_F_ENGINE_FINISH, ERR_R_PASSED_NULL_PARAMETER);
>>>         return 0;
>>>     }
>>>     CRYPTO_w_lock(CRYPTO_LOCK_ENGINE);
>>>     to_return = engine_unlocked_finish(e, 1);
>>>     CRYPTO_w_unlock(CRYPTO_LOCK_ENGINE);
>>>     if (!to_return) {
>>>         ENGINEerr(ENGINE_F_ENGINE_FINISH, ENGINE_R_FINISH_FAILED);
>>>         return 0;
>>>     }
>>>     return to_return;
>>> }
>