[Dovecot] imap-login: memory corruption
From my logs (dovecot-1.1.8)
Jan 14 08:42:52 postamt dovecot: imap-login: *** glibc detected *** imap-login: malloc(): memory corruption: 0x0844e778 *** Jan 14 08:42:52 postamt dovecot: child 15380 (login) killed with signal 6
Jan 14 10:06:42 postamt dovecot: Panic: imap-login: file ioloop.c: line 71 (io_remove_full): assertion failed: (io->callback != NULL) Jan 14 10:06:42 postamt dovecot: child 15389 (login) killed with signal 6
Jan 14 10:53:15 postamt dovecot: Panic: imap-login: file ioloop.c: line 71 (io_remove_full): assertion failed: (io->callback != NULL) Jan 14 10:53:15 postamt dovecot: child 15367 (login) killed with signal 6
Jan 14 12:05:20 postamt dovecot: imap-login: *** glibc detected *** imap-login: malloc(): memory corruption: 0x0882fe40 *** Jan 14 12:05:20 postamt dovecot: child 2263 (login) killed with signal 6
Jan 14 12:35:13 postamt dovecot: imap-login: *** glibc detected *** imap-login: free(): invalid pointer: 0x08a46620 *** Jan 14 12:35:13 postamt dovecot: child 4169 (login) killed with signal 6
Jan 14 13:08:27 postamt dovecot: imap-login: *** glibc detected *** imap-login: free(): invalid pointer: 0x08f5b5b0 *** Jan 14 13:08:27 postamt dovecot: child 6316 (login) killed with signal 6
Jan 14 13:18:00 postamt dovecot: imap-login: *** glibc detected *** imap-login: malloc(): memory corruption: 0x085f3d48 *** Jan 14 13:18:00 postamt dovecot: child 15378 (login) killed with signal 6
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de IMPORTANT - ANTI-DISCLAIMER - This email is not and cannot, by its nature, be confidential. En route from me to you, it will pass across the public Internet, easily readable by any number of system administrators along the way. If you have received this message by mistake, it would be ridiculous for me to tell you not to read it or copy to anyone else, because, let's face it, if it's a message revealing confidential information or that could embarrass me intensely, that's precisely what you'll do. Who wouldn't? Likewise, it is superfluous for me to claim copyright in the contents, because I own that anyway, even if you print out a hard copy or disseminate this message all over the known universe. I don't know why so many corporate mail servers feel impelled to attach a disclaimer to the bottom of every email message saying otherwise. If you don't know either, why not email your corporate lawyers and system administrators and ask them why they insist on contributing so much to the waste of bandwidth? To say nothing of making the presence of your mail on public discussions or mailinglists of explicitly contratictory nature. May as well just delete it, eh? Oh, and this message is probably plagued with viruses as well.
On Wed, 2009-01-14 at 14:50 +0100, Ralf Hildebrandt wrote:
From my logs (dovecot-1.1.8)
Jan 14 08:42:52 postamt dovecot: imap-login: *** glibc detected *** imap-login: malloc(): memory corruption: 0x0844e778 *** Jan 14 08:42:52 postamt dovecot: child 15380 (login) killed with signal 6
The annoying thing is that these are pretty much impossible to fix without a way to reproduce or running imap-login via valgrind..
Do you use SSL? What authentication mechanisms do you use? login_process_per_connection=yes/no?
- Timo Sirainen <tss@iki.fi>:
Jan 14 08:42:52 postamt dovecot: imap-login: *** glibc detected *** imap-login: malloc(): memory corruption: 0x0844e778 *** Jan 14 08:42:52 postamt dovecot: child 15380 (login) killed with signal 6
The annoying thing is that these are pretty much impossible to fix without a way to reproduce or running imap-login via valgrind..
And valgrind would be impossibly slow (I think)
Do you use SSL?
Yes.
What authentication mechanisms do you use?
passdb passwd-file { args = /usr/local/etc/dovecot.masterusers master = yes pass = yes } passdb shadow { }
login_process_per_connection=yes/no? login_process_per_connection = no
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de Why is Linux so stable? Because Penguins can't fly.
On Wed, 2009-01-14 at 16:46 +0100, Ralf Hildebrandt wrote:
- Timo Sirainen <tss@iki.fi>:
Jan 14 08:42:52 postamt dovecot: imap-login: *** glibc detected *** imap-login: malloc(): memory corruption: 0x0844e778 *** Jan 14 08:42:52 postamt dovecot: child 15380 (login) killed with signal 6
The annoying thing is that these are pretty much impossible to fix without a way to reproduce or running imap-login via valgrind..
And valgrind would be impossibly slow (I think)
For non-SSL connections I think it would be usable (my machine handles 600 logins/sec fine with valgrind), but I suppose with many SSL connections it's too slow.
How soon after upgrading to 1.1.8 did this happen? There was one login process change done for 1.1.8, but it was supposed to fix a crash. And I don't really see how it could cause memory corruption. I guess you haven't seen these with older versions?
Do you use SSL? Yes.
Did you happen to upgrade OpenSSL also?
login_process_per_connection=yes/no? login_process_per_connection = no
That makes it more difficult to debug. I was thinking about ways to see if the crashes happens because one specific user is trying to log in or if they're completely different users. Adding %p to login_log_format_elements would log PIDs of users that successfully log in, but if the crash happens before logging in that doesn't really help (and with login_process_per_connection=no it's even more useless).
I was also thinking about adding some code that would attach IP address to the "killed with signal n" error (with login_process_per_connection=no it would be the last IP that started logging in).
- Timo Sirainen <tss@iki.fi>:
How soon after upgrading to 1.1.8 did this happen?
it always happened, even befor 1.1.8 :)
There was one login process change done for 1.1.8, but it was supposed to fix a crash. And I don't really see how it could cause memory corruption. I guess you haven't seen these with older versions?
Yes, I have seen those with older versions.
Do you use SSL? Yes.
Did you happen to upgrade OpenSSL also?
It's the Debian Package, no.
login_process_per_connection = no
That makes it more difficult to debug. I was thinking about ways to see if the crashes happens because one specific user is trying to log in or if they're completely different users. Adding %p to login_log_format_elements would log PIDs of users that successfully log in, but if the crash happens before logging in that doesn't really help (and with login_process_per_connection=no it's even more useless).
I tried "login_process_per_connection = yes" but that gives me problems:
Jan 14 16:59:05 postamt dovecot: Dovecot v1.1.8 starting up Jan 14 16:59:07 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Jan 14 16:59:07 postamt dovecot: Temporary failure in creating login processes, slowing down for now Jan 14 16:59:07 postamt dovecot: child 17937 (login) returned error 89 (Fatal failure) Jan 14 16:59:07 postamt dovecot: child 17938 (login) returned error 89 (Fatal failure) Jan 14 16:59:07 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Jan 14 17:00:07 postamt dovecot: Created login processes successfully, unstalling Jan 14 17:00:07 postamt dovecot: child 20033 (login) returned error 89 (Fatal failure) Jan 14 17:00:07 postamt dovecot: child 20037 (login) returned error 89 (Fatal failure) Jan 14 17:00:07 postamt dovecot: child 20038 (login) returned error 89 (Fatal failure) Jan 14 17:00:07 postamt dovecot: child 20040 (login) returned error 89 (Fatal failure) Jan 14 17:00:07 postamt dovecot: child 20041 (login) returned error 89 (Fatal failure) Jan 14 17:00:07 postamt dovecot: child 20042 (login) returned error 89 (Fatal failure) Jan 14 17:00:07 postamt dovecot: child 20043 (login) returned error 89 (Fatal failure) Jan 14 17:00:07 postamt dovecot: child 20044 (login) returned error 89 (Fatal failure) Jan 14 17:00:07 postamt dovecot: child 20045 (login) returned error 89 (Fatal failure) Jan 14 17:00:07 postamt dovecot: child 20046 (login) returned error 89 (Fatal failure) Jan 14 17:00:07 postamt dovecot: child 20047 (login) returned error 89 (Fatal failure) Jan 14 17:00:07 postamt dovecot: child 20048 (login) returned error 89 (Fatal failure) Jan 14 17:00:07 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Jan 14 17:00:07 postamt dovecot: Temporary failure in creating login processes, slowing down for now Jan 14 17:00:07 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Jan 14 17:01:07 postamt dovecot: Created login processes successfully, unstalling Jan 14 17:01:07 postamt dovecot: child 21758 (login) returned error 89 (Fatal failure) Jan 14 17:01:07 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Jan 14 17:01:07 postamt dovecot: Temporary failure in creating login processes, slowing down for now Jan 14 17:01:07 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files Jan 14 17:01:07 postamt dovecot: child 21757 (login) returned error 89 (Fatal failure) Jan 14 17:01:07 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files
I was also thinking about adding some code that would attach IP address to the "killed with signal n" error (with login_process_per_connection=no it would be the last IP that started logging in).
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de The trouble with being punctual is that people think you have nothing more important to do.
On Wed, 2009-01-14 at 17:04 +0100, Ralf Hildebrandt wrote:
Jan 14 16:59:05 postamt dovecot: Dovecot v1.1.8 starting up Jan 14 16:59:07 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files
Wonder if these patches fix this:
http://hg.dovecot.org/dovecot-1.1/rev/66687cb6951c http://hg.dovecot.org/dovecot-1.1/rev/60b4e34791c4
What distribution are you using?
- Timo Sirainen <tss@iki.fi>:
On Wed, 2009-01-14 at 17:04 +0100, Ralf Hildebrandt wrote:
Jan 14 16:59:05 postamt dovecot: Dovecot v1.1.8 starting up Jan 14 16:59:07 postamt dovecot: Fatal: imap-login: epoll_create(): Too many open files
Wonder if these patches fix this:
http://hg.dovecot.org/dovecot-1.1/rev/66687cb6951c http://hg.dovecot.org/dovecot-1.1/rev/60b4e34791c4
What distribution are you using?
Debian/testing
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de "The Internet is like a giant jellyfish. You can't step on it. You can't go around it. You've got to get through it."-John Evans
- Timo Sirainen <tss@iki.fi>:
For non-SSL connections I think it would be usable (my machine handles 600 logins/sec fine with valgrind), but I suppose with many SSL connections it's too slow.
How would I run imap-login from valgrind?
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de I think the natural reaction one has to their mail being blocked for what they think are inappropriate reasons is first to say, "WTF?" and then to issue the missle launch codes.
On Wed, 2009-01-14 at 18:25 +0100, Ralf Hildebrandt wrote:
- Timo Sirainen <tss@iki.fi>:
For non-SSL connections I think it would be usable (my machine handles 600 logins/sec fine with valgrind), but I suppose with many SSL connections it's too slow.
How would I run imap-login from valgrind?
login_executable = /usr/bin/valgrind /usr/local/libexec/dovecot/imap-login
It logs to Dovecot's error log (or use valgrind --log-file=/tmp/imap.%p).
- Timo Sirainen <tss@iki.fi>:
login_executable = /usr/bin/valgrind /usr/local/libexec/dovecot/imap-login
It logs to Dovecot's error log (or use valgrind --log-file=/tmp/imap.%p).
I remember last time:
Jan 14 20:44:05 postamt dovecot: imap-login: Valgrind's memory management: out of memory: Jan 14 20:44:05 postamt dovecot: imap-login: newSuperblock's request for 1048576 bytes failed. Jan 14 20:44:05 postamt dovecot: imap-login: 54521856 bytes have already been allocated. Jan 14 20:44:05 postamt dovecot: imap-login: Valgrind cannot continue. Sorry.
:(
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de No sig. Move along - nothing to see here.
On Wed, 2009-01-14 at 20:51 +0100, Ralf Hildebrandt wrote:
- Timo Sirainen <tss@iki.fi>:
login_executable = /usr/bin/valgrind /usr/local/libexec/dovecot/imap-login
It logs to Dovecot's error log (or use valgrind --log-file=/tmp/imap.%p).
I remember last time:
Jan 14 20:44:05 postamt dovecot: imap-login: Valgrind's memory management: out of memory:
Ah, this is easy. Set login_process_size=0
- Timo Sirainen <tss@iki.fi>:
Ah, this is easy. Set login_process_size=0 Ah, ok. Now it's very talkativ and clutters my log...
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de OpenVMS is today what Microsoft wants Windows NT v8.0 to be!
On Wed, 2009-01-14 at 21:06 +0100, Ralf Hildebrandt wrote:
- Timo Sirainen <tss@iki.fi>:
Ah, this is easy. Set login_process_size=0 Ah, ok. Now it's very talkativ and clutters my log...
valgrind --log-file=/tmp/imap.%p could be helpful there then. But does it keep logging something? With me it logs one error when the process starts:
==6036== Syscall param socketcall.sendmsg(msg.msg_iov[i]) points to uninitialised byte(s) ==6036== at 0x40007D2: (within /lib/ld-2.8.90.so) ==6036== by 0x804F94E: master_request_login (master.c:87) ==6036== by 0x8054D86: auth_client_input_ok (auth-server-request.c:194)
After that there's nothing. Probably all output after that are bugs (maybe this one too, but I haven't managed to figure out how it could be fixed).
Oh, and valgrind -q also makes it more quiet if you want to keep logging to Dovecot logs.
- Timo Sirainen <tss@iki.fi>:
valgrind --log-file=/tmp/imap.%p could be helpful there then. Yes, done that now. Better But does it keep logging something? With me it logs one error when the process starts:
==6036== Syscall param socketcall.sendmsg(msg.msg_iov[i]) points to uninitialised byte(s) ==6036== at 0x40007D2: (within /lib/ld-2.8.90.so) ==6036== by 0x804F94E: master_request_login (master.c:87) ==6036== by 0x8054D86: auth_client_input_ok (auth-server-request.c:194)
After that there's nothing. Probably all output after that are bugs (maybe this one too, but I haven't managed to figure out how it could be fixed).
Oh, and valgrind -q also makes it more quiet if you want to keep logging to Dovecot logs.
I get:
==9769== Memcheck, a memory error detector. ==9769== Copyright (C) 2002-2007, and GNU GPL'd, by Julian Seward et al. ==9769== Using LibVEX rev 1854, a library for dynamic binary translation. ==9769== Copyright (C) 2004-2007, and GNU GPL'd, by OpenWorks LLP. ==9769== Using valgrind-3.3.1-Debian, a dynamic binary instrumentation framework. ==9769== Copyright (C) 2000-2007, and GNU GPL'd, by Julian Seward et al. ==9769== For more details, rerun with: -v ==9769== ==9769== My PID = 9769, parent PID = 9306. Prog and args are: ==9769== /usr/local/libexec/dovecot/imap-login ==9769== ==9769== Conditional jump or move depends on uninitialised value(s) ==9769== at 0x40F09F7: BN_mod_inverse (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F48E0: BN_MONT_CTX_set (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40E93C1: BN_mod_exp_mont (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40E9BBF: BN_mod_exp (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40EFA3F: BN_BLINDING_create_param (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410BD55: RSA_setup_blinding (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109A0C: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109F94: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410B91D: RSA_private_decrypt (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40447F3: ssl3_get_client_key_exchange (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4047244: ssl3_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== ==9769== Conditional jump or move depends on uninitialised value(s) ==9769== at 0x40E7451: BN_div (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40ED531: BN_nnmod (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F130A: BN_mod_inverse (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F48E0: BN_MONT_CTX_set (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40E93C1: BN_mod_exp_mont (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40E9BBF: BN_mod_exp (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40EFA3F: BN_BLINDING_create_param (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410BD55: RSA_setup_blinding (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109A0C: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109F94: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410B91D: RSA_private_decrypt (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40447F3: ssl3_get_client_key_exchange (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== ==9769== Conditional jump or move depends on uninitialised value(s) ==9769== at 0x40E7451: BN_div (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4942: BN_MONT_CTX_set (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40E93C1: BN_mod_exp_mont (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40E9BBF: BN_mod_exp (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40EFA3F: BN_BLINDING_create_param (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410BD55: RSA_setup_blinding (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109A0C: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109F94: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410B91D: RSA_private_decrypt (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40447F3: ssl3_get_client_key_exchange (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4047244: ssl3_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== ==9769== Conditional jump or move depends on uninitialised value(s) ==9769== at 0x40F09F7: BN_mod_inverse (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F48E0: BN_MONT_CTX_set (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4C27: BN_MONT_CTX_set_locked (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x41097DD: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109DD2: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410B91D: RSA_private_decrypt (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40447F3: ssl3_get_client_key_exchange (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4047244: ssl3_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x8050F4A: ssl_step (ssl-proxy-openssl.c:399) ==9769== by 0x80599CF: io_loop_handler_run (ioloop-epoll.c:203) ==9769== by 0x8058E3F: io_loop_run (ioloop.c:326) ==9769== ==9769== Conditional jump or move depends on uninitialised value(s) ==9769== at 0x40E7451: BN_div (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4942: BN_MONT_CTX_set (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4C27: BN_MONT_CTX_set_locked (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x41097DD: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109DD2: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410B91D: RSA_private_decrypt (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40447F3: ssl3_get_client_key_exchange (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4047244: ssl3_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x8050F4A: ssl_step (ssl-proxy-openssl.c:399) ==9769== by 0x80599CF: io_loop_handler_run (ioloop-epoll.c:203) ==9769== by 0x8058E3F: io_loop_run (ioloop.c:326) ==9769== ==9769== Conditional jump or move depends on uninitialised value(s) ==9769== at 0x40F09F7: BN_mod_inverse (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F48E0: BN_MONT_CTX_set (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4C27: BN_MONT_CTX_set_locked (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410980D: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109DD2: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410B91D: RSA_private_decrypt (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40447F3: ssl3_get_client_key_exchange (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4047244: ssl3_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x8050F4A: ssl_step (ssl-proxy-openssl.c:399) ==9769== by 0x80599CF: io_loop_handler_run (ioloop-epoll.c:203) ==9769== by 0x8058E3F: io_loop_run (ioloop.c:326) ==9769== ==9769== Conditional jump or move depends on uninitialised value(s) ==9769== at 0x40E7451: BN_div (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4942: BN_MONT_CTX_set (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4C27: BN_MONT_CTX_set_locked (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410980D: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109DD2: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410B91D: RSA_private_decrypt (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40447F3: ssl3_get_client_key_exchange (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4047244: ssl3_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x8050F4A: ssl_step (ssl-proxy-openssl.c:399) ==9769== by 0x80599CF: io_loop_handler_run (ioloop-epoll.c:203) ==9769== by 0x8058E3F: io_loop_run (ioloop.c:326) ==9769== ==9769== Conditional jump or move depends on uninitialised value(s) ==9769== at 0x40F09F7: BN_mod_inverse (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F48E0: BN_MONT_CTX_set (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4C27: BN_MONT_CTX_set_locked (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109840: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109DD2: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410B91D: RSA_private_decrypt (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40447F3: ssl3_get_client_key_exchange (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4047244: ssl3_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x8050F4A: ssl_step (ssl-proxy-openssl.c:399) ==9769== by 0x80599CF: io_loop_handler_run (ioloop-epoll.c:203) ==9769== by 0x8058E3F: io_loop_run (ioloop.c:326) ==9769== ==9769== Conditional jump or move depends on uninitialised value(s) ==9769== at 0x40E7451: BN_div (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4942: BN_MONT_CTX_set (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4C27: BN_MONT_CTX_set_locked (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109840: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109DD2: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410B91D: RSA_private_decrypt (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40447F3: ssl3_get_client_key_exchange (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4047244: ssl3_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x8050F4A: ssl_step (ssl-proxy-openssl.c:399) ==9769== by 0x80599CF: io_loop_handler_run (ioloop-epoll.c:203) ==9769== by 0x8058E3F: io_loop_run (ioloop.c:326) ==9769== ==9769== Syscall param socketcall.sendmsg(msg.msg_iov[i]) points to uninitialised byte(s) ==9769== at 0x4295D6C: sendmsg (in /usr/lib/debug/libc-2.7.so) ==9769== by 0x804F3A6: master_request_login (master.c:87) ==9769== by 0x8054406: auth_client_input_ok (auth-server-request.c:194) ==9769== by 0x8053589: auth_client_input (auth-server-connection.c:136) ==9769== by 0x80599CF: io_loop_handler_run (ioloop-epoll.c:203) ==9769== by 0x8058E3F: io_loop_run (ioloop.c:326) ==9769== by 0x804E839: main (main.c:482) ==9769== Address 0xbefe68be is on thread 1's stack ==9769== ==9769== Conditional jump or move depends on uninitialised value(s) ==9769== at 0x40F09F7: BN_mod_inverse (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F48E0: BN_MONT_CTX_set (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4C27: BN_MONT_CTX_set_locked (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4113D10: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4113821: DH_generate_key (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4045A4C: ssl3_send_server_key_exchange (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4047997: ssl3_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4051DDF: ssl23_get_client_hello (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x40526D7: ssl23_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x8050F4A: ssl_step (ssl-proxy-openssl.c:399) ==9769== ==9769== Conditional jump or move depends on uninitialised value(s) ==9769== at 0x40E7451: BN_div (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4942: BN_MONT_CTX_set (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F4C27: BN_MONT_CTX_set_locked (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4113D10: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4113821: DH_generate_key (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4045A4C: ssl3_send_server_key_exchange (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4047997: ssl3_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4051DDF: ssl23_get_client_hello (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x40526D7: ssl23_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x8050F4A: ssl_step (ssl-proxy-openssl.c:399)
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de This signature was added just to have one. ;-)
On Wed, 2009-01-14 at 21:26 +0100, Ralf Hildebrandt wrote:
I get: .. ==9769== Conditional jump or move depends on uninitialised value(s) ==9769== at 0x40F09F7: BN_mod_inverse (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40F48E0: BN_MONT_CTX_set (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40E93C1: BN_mod_exp_mont (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40E9BBF: BN_mod_exp (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40EFA3F: BN_BLINDING_create_param (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410BD55: RSA_setup_blinding (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109A0C: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x4109F94: (within /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x410B91D: RSA_private_decrypt (in /usr/lib/i686/cmov/libcrypto.so.0.9.8) ==9769== by 0x40447F3: ssl3_get_client_key_exchange (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x4047244: ssl3_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8) ==9769== by 0x405FCB9: SSL_accept (in /usr/lib/i686/cmov/libssl.so.0.9.8)
Oh, right, libcrypto stuff isn't very valgrind-friendly. I think it's possible to disable these with:
--suppressions=<filename> [default: $PREFIX/lib/valgrind/default.supp]
Specifies an extra file from which to read descriptions of
errors to suppress. You may use up to 100 extra suppression
files.But I don't know how to generate those suppressions.
On Wed, 2009-01-14 at 15:31 -0500, Timo Sirainen wrote:
Oh, right, libcrypto stuff isn't very valgrind-friendly. I think it's possible to disable these with:
--suppressions=<filename> [default: $PREFIX/lib/valgrind/default.supp] Specifies an extra file from which to read descriptions of errors to suppress. You may use up to 100 extra suppression files.But I don't know how to generate those suppressions.
Looks like at the bottom of http://www.kegel.com/wine/valgrind/valgrind-suppressions there are some libcrypto and libssl suppressions.
- Timo Sirainen <tss@iki.fi>:
valgrind --log-file=/tmp/imap.%p could be helpful there then. But does it keep logging something? With me it logs one error when the process starts:
A watched kettle never boils. No incidents so far.
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de In the rather clear UNIX language: the TCPA cartel will be always root on your system(s) and you will it never be again.
On Thu, 2009-01-15 at 16:42 +0100, Ralf Hildebrandt wrote:
- Timo Sirainen <tss@iki.fi>:
valgrind --log-file=/tmp/imap.%p could be helpful there then. But does it keep logging something? With me it logs one error when the process starts:
A watched kettle never boils. No incidents so far.
Are you also looking at what errors are in the valgrind log? It might prevent the crashes. Does grep find any of:
Invalid free() / delete / delete[] Invalid read of size Invalid write of size bytes inside a block of size
- Timo Sirainen <tss@iki.fi>:
On Thu, 2009-01-15 at 16:42 +0100, Ralf Hildebrandt wrote:
- Timo Sirainen <tss@iki.fi>:
valgrind --log-file=/tmp/imap.%p could be helpful there then. But does it keep logging something? With me it logs one error when the process starts:
A watched kettle never boils. No incidents so far.
Are you also looking at what errors are in the valgrind log? It might prevent the crashes. Does grep find any of:
Invalid free() / delete / delete[] Invalid read of size Invalid write of size bytes inside a block of size
root@postamt:/tmp# egrep -i "(invalid|inside)" imap-login.* root@postamt:/tmp#
:(
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de echo Mhbqnrnes Stbjr | tr "[a-y]" "[b-z]"
On Jan 15, 2009, at 7:28 PM, Ralf Hildebrandt wrote: Well..
==10780== Invalid write of size 1 ==10780== at 0x402499E: memcpy (mc_replace_strmem.c:402) ==10780== by 0x805B000: pool_system_clean_realloc (mempool-system- clean.c:149) ==10780== by 0x804FC09: ssl_clean_realloc (ssl-proxy-openssl.c:729)
I did find that pool_system_clean_realloc() didn't handle shrinking the memory area, fixed: http://hg.dovecot.org/dovecot-1.1/rev/17c73b14ed9d But I'm not sure if that really caused the problem, because it only says invalid size of 1. More likely valgrind just doesn't like that I use glibc-specific malloc_usable_size(). I think I noticed the same problem before too. So to avoid these you should disable using the clean pool (perhaps I should disable it entirely by default - it's not useful after all for what I originally thought it would have been): diff -r 17c73b14ed9d src/login-common/main.c --- a/src/login-common/main.c Thu Jan 15 21:36:26 2009 -0500 +++ b/src/login-common/main.c Thu Jan 15 21:40:12 2009 -0500 @@ -413,8 +413,8 @@ int main(int argc ATTR_UNUSED, char *arg processes pretty safe to reuse for new connections since the attacker won't be able to find anything interesting from the memory. */ - default_pool = system_clean_pool; - data_stack_set_clean_after_pop(TRUE); + /*default_pool = system_clean_pool; + data_stack_set_clean_after_pop(TRUE);*/ /* NOTE: we start rooted, so keep the code minimal until restrict_access_by_env() is called */ Then again perhaps using the clean pool really is the problem. You could just see if after applying the above patch it runs without crashes even without valgrind.
- Timo Sirainen <tss@iki.fi>:
I did find that pool_system_clean_realloc() didn't handle shrinking the memory area, fixed: http://hg.dovecot.org/dovecot-1.1/rev/17c73b14ed9d
I checked that out
default_pool = system_clean_pool;data_stack_set_clean_after_pop(TRUE);
/*default_pool = system_clean_pool;data_stack_set_clean_after_pop(TRUE);*/
Did that and recompiled, deactivated valgrind, let's see what happens.
Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de I have never seen anything fill up a vacuum so fast and still suck. -- Rob Pike, commenting on the X Window System.
- Ralf Hildebrandt <Ralf.Hildebrandt@charite.de>:
Did that and recompiled, deactivated valgrind, let's see what happens.
Right now I don't see any more libc related crashes.
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de What's the most effective Windows NT remote management tool? A car.
- Ralf Hildebrandt <Ralf.Hildebrandt@charite.de>:
- Ralf Hildebrandt <Ralf.Hildebrandt@charite.de>:
Did that and recompiled, deactivated valgrind, let's see what happens.
Right now I don't see any more libc related crashes.
Still no crashes. Your fix seems to be working
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de My advice is simple: Boycott IE. It's a cancer on the Web that must be stopped. IE isn't secure and isn't standards-compliant, which makes it unworkable both for end users and Web content creators.
On Wed, 2009-01-14 at 11:01 -0500, Timo Sirainen wrote:
I was also thinking about adding some code that would attach IP address to the "killed with signal n" error (with login_process_per_connection=no it would be the last IP that started logging in).
Implemented: http://hg.dovecot.org/dovecot-1.1/rev/2146e1963b79
- Timo Sirainen <tss@iki.fi>:
Implemented: http://hg.dovecot.org/dovecot-1.1/rev/2146e1963b79
I rebuild dovecot just now with that
-- Ralf Hildebrandt (Ralf.Hildebrandt@charite.de) snickebo@charite.de Postfix - Einrichtung, Betrieb und Wartung Tel. +49 (0)30-450 570-155 http://www.arschkrebs.de Windows is the answer, but only if the question was 'what is the intellectual equivalent of being a galley slave?'
participants (2)
-
Ralf Hildebrandt
-
Timo Sirainen