Dovecot 2.3.0 imap-login using 100% CPU
When in the process of testing out the 2.3.0 version of Dovecot, we noticed that on a busy server, imap-login can sometimes take 100% CPU and remain there indefinitely. We grabbed a gdb trace while it was happening:
dovenull 36053 31.2 0.0 60460 17316 ? R 04:38 11:55 dovecot/imap-login root@server [~]# strace -p 36053 Process 36053 attached ^CProcess 36053 detached root@server [~]# gdb atGNU gdb (GDB) Red Hat Enterprise Linux (7.2-92.el6) Copyright (C) 2010 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/. (gdb) attach 36053 Attaching to process 36053 Reading symbols from /usr/libexec/dovecot/imap-login...done. Reading symbols from /usr/lib64/dovecot/libdovecot-login.so.0...done. Loaded symbols for /usr/lib64/dovecot/libdovecot-login.so.0 Reading symbols from /usr/lib64/dovecot/libdovecot.so.0...done. Loaded symbols for /usr/lib64/dovecot/libdovecot.so.0 Reading symbols from /lib64/libc.so.6...(no debugging symbols found)...done. Loaded symbols for /lib64/libc.so.6 Reading symbols from /usr/lib64/libssl.so.10...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libssl.so.10 Reading symbols from /usr/lib64/libcrypto.so.10...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libcrypto.so.10 Reading symbols from /lib64/librt.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/librt.so.1 Reading symbols from /lib64/libdl.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libdl.so.2 Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/ld-linux-x86-64.so.2 Reading symbols from /lib64/libgssapi_krb5.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libgssapi_krb5.so.2 Reading symbols from /lib64/libkrb5.so.3...(no debugging symbols found)...done. Loaded symbols for /lib64/libkrb5.so.3 Reading symbols from /lib64/libcom_err.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libcom_err.so.2 Reading symbols from /lib64/libk5crypto.so.3...(no debugging symbols found)...done. Loaded symbols for /lib64/libk5crypto.so.3 Reading symbols from /lib64/libz.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libz.so.1 Reading symbols from /lib64/libpthread.so.0...(no debugging symbols found)...done. [Thread debugging using libthread_db enabled] Loaded symbols for /lib64/libpthread.so.0 Reading symbols from /lib64/libkrb5support.so.0...(no debugging symbols found)...done. Loaded symbols for /lib64/libkrb5support.so.0 Reading symbols from /lib64/libkeyutils.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libkeyutils.so.1 Reading symbols from /lib64/libresolv.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libresolv.so.2 Reading symbols from /lib64/libselinux.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libselinux.so.1 Reading symbols from /usr/lib64/dovecot/libssl_iostream_openssl.so...done. Loaded symbols for /usr/lib64/dovecot/libssl_iostream_openssl.so 0x00007f758fb8dd18 in client_notify_auth_ready@plt () from /usr/lib64/dovecot/libdovecot-login.so.0 Missing separate debuginfos, use: debuginfo-install dovecot-2.3.0-4.cp1162.x86_64 (gdb) back #0 0x00007f758fb8dd18 in client_notify_auth_ready@plt () from /usr/lib64/dovecot/libdovecot-login.so.0 #1 0x00007f758fb90af0 in clients_notify_auth_connected () at client-common-auth.c:837 #2 0x00007f758f8cfc04 in auth_server_input_done (conn=0x7f7591911838) at auth-server-connection.c:127 #3 auth_server_connection_input_line (conn=0x7f7591911838) at auth-server-connection.c:229 #4 auth_server_connection_input (conn=0x7f7591911838) at auth-server-connection.c:281 #5 0x00007f758f8f5e35 in io_loop_call_io (io=0x7f759277e2a0) at ioloop.c:614 #6 0x00007f758f8f7d3f in io_loop_handler_run_internal (ioloop=<value optimized out>) at ioloop-epoll.c:222 #7 0x00007f758f8f5f25 in io_loop_handler_run (ioloop=0x7f75918e4d00) at ioloop.c:666 #8 0x00007f758f8f6148 in io_loop_run (ioloop=0x7f75918e4d00) at ioloop.c:639 #9 0x00007f758f875ab3 in master_service_run (service=0x7f75918e4b90, callback=<value optimized out>) at master-service.c:767 #10 0x00007f758fb96156 in login_binary_run (binary=<value optimized out>, argc=1, argv=0x7f75918e4890) at main.c:549 #11 0x00007f758f4a2d1d in __libc_start_main () from /lib64/libc.so.6 #12 0x00007f758ffc4469 in _start () (gdb) run The program being debugged has been started already. Start it from the beginning? (y or n) n Program not restarted. (gdb) continue Continuing. ^C Program received signal SIGINT, Interrupt. client_notify_auth_ready (client=0x7f7592775140) at client-common.c:1031 1031 client-common.c: No such file or directory. in client-common.c (gdb) back #0 client_notify_auth_ready (client=0x7f7592775140) at client-common.c:1031 #1 0x00007f758fb90af0 in clients_notify_auth_connected () at client-common-auth.c:837 #2 0x00007f758f8cfc04 in auth_server_input_done (conn=0x7f7591911838) at auth-server-connection.c:127 #3 auth_server_connection_input_line (conn=0x7f7591911838) at auth-server-connection.c:229 #4 auth_server_connection_input (conn=0x7f7591911838) at auth-server-connection.c:281 #5 0x00007f758f8f5e35 in io_loop_call_io (io=0x7f759277e2a0) at ioloop.c:614 #6 0x00007f758f8f7d3f in io_loop_handler_run_internal (ioloop=<value optimized out>) at ioloop-epoll.c:222 #7 0x00007f758f8f5f25 in io_loop_handler_run (ioloop=0x7f75918e4d00) at ioloop.c:666 #8 0x00007f758f8f6148 in io_loop_run (ioloop=0x7f75918e4d00) at ioloop.c:639 #9 0x00007f758f875ab3 in master_service_run (service=0x7f75918e4b90, callback=<value optimized out>) at master-service.c:767 #10 0x00007f758fb96156 in login_binary_run (binary=<value optimized out>, argc=1, argv=0x7f75918e4890) at main.c:549 #11 0x00007f758f4a2d1d in __libc_start_main () from /lib64/libc.so.6 #12 0x00007f758ffc4469 in _start () (gdb)
Anyone have any thoughts?
Regards,
Jason Kiniry
We were able to obtain a better backtrace:
0x00007f4b303b5af5 in clients_notify_auth_connected () at client-common-auth.c:839 839 if (!client_does_custom_io(client) && client->input_blocked) { (gdb) run
Thank you!
Regards,
Jason Kiniry
On Jan 10, 2018, at 4:28 PM, Jason Kiniry jason@cpanel.net wrote:
When in the process of testing out the 2.3.0 version of Dovecot, we noticed that on a busy server, imap-login can sometimes take 100% CPU and remain there indefinitely. We grabbed a gdb trace while it was happening:
dovenull 36053 31.2 0.0 60460 17316 ? R 04:38 11:55 dovecot/imap-login root@server [~]# strace -p 36053 Process 36053 attached ^CProcess 36053 detached root@server [~]# gdb atGNU gdb (GDB) Red Hat Enterprise Linux (7.2-92.el6) Copyright (C) 2010 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/. (gdb) attach 36053 Attaching to process 36053 Reading symbols from /usr/libexec/dovecot/imap-login...done. Reading symbols from /usr/lib64/dovecot/libdovecot-login.so.0...done. Loaded symbols for /usr/lib64/dovecot/libdovecot-login.so.0 Reading symbols from /usr/lib64/dovecot/libdovecot.so.0...done. Loaded symbols for /usr/lib64/dovecot/libdovecot.so.0 Reading symbols from /lib64/libc.so.6...(no debugging symbols found)...done. Loaded symbols for /lib64/libc.so.6 Reading symbols from /usr/lib64/libssl.so.10...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libssl.so.10 Reading symbols from /usr/lib64/libcrypto.so.10...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libcrypto.so.10 Reading symbols from /lib64/librt.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/librt.so.1 Reading symbols from /lib64/libdl.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libdl.so.2 Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/ld-linux-x86-64.so.2 Reading symbols from /lib64/libgssapi_krb5.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libgssapi_krb5.so.2 Reading symbols from /lib64/libkrb5.so.3...(no debugging symbols found)...done. Loaded symbols for /lib64/libkrb5.so.3 Reading symbols from /lib64/libcom_err.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libcom_err.so.2 Reading symbols from /lib64/libk5crypto.so.3...(no debugging symbols found)...done. Loaded symbols for /lib64/libk5crypto.so.3 Reading symbols from /lib64/libz.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libz.so.1 Reading symbols from /lib64/libpthread.so.0...(no debugging symbols found)...done. [Thread debugging using libthread_db enabled] Loaded symbols for /lib64/libpthread.so.0 Reading symbols from /lib64/libkrb5support.so.0...(no debugging symbols found)...done. Loaded symbols for /lib64/libkrb5support.so.0 Reading symbols from /lib64/libkeyutils.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libkeyutils.so.1 Reading symbols from /lib64/libresolv.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libresolv.so.2 Reading symbols from /lib64/libselinux.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libselinux.so.1 Reading symbols from /usr/lib64/dovecot/libssl_iostream_openssl.so...done. Loaded symbols for /usr/lib64/dovecot/libssl_iostream_openssl.so 0x00007f758fb8dd18 in client_notify_auth_ready@plt () from /usr/lib64/dovecot/libdovecot-login.so.0 Missing separate debuginfos, use: debuginfo-install dovecot-2.3.0-4.cp1162.x86_64 (gdb) back #0 0x00007f758fb8dd18 in client_notify_auth_ready@plt () from /usr/lib64/dovecot/libdovecot-login.so.0 #1 0x00007f758fb90af0 in clients_notify_auth_connected () at client-common-auth.c:837 #2 0x00007f758f8cfc04 in auth_server_input_done (conn=0x7f7591911838) at auth-server-connection.c:127 #3 auth_server_connection_input_line (conn=0x7f7591911838) at auth-server-connection.c:229 #4 auth_server_connection_input (conn=0x7f7591911838) at auth-server-connection.c:281 #5 0x00007f758f8f5e35 in io_loop_call_io (io=0x7f759277e2a0) at ioloop.c:614 #6 0x00007f758f8f7d3f in io_loop_handler_run_internal (ioloop=<value optimized out>) at ioloop-epoll.c:222 #7 0x00007f758f8f5f25 in io_loop_handler_run (ioloop=0x7f75918e4d00) at ioloop.c:666 #8 0x00007f758f8f6148 in io_loop_run (ioloop=0x7f75918e4d00) at ioloop.c:639 #9 0x00007f758f875ab3 in master_service_run (service=0x7f75918e4b90, callback=<value optimized out>) at master-service.c:767 #10 0x00007f758fb96156 in login_binary_run (binary=<value optimized out>, argc=1, argv=0x7f75918e4890) at main.c:549 #11 0x00007f758f4a2d1d in __libc_start_main () from /lib64/libc.so.6 #12 0x00007f758ffc4469 in _start () (gdb) run The program being debugged has been started already. Start it from the beginning? (y or n) n Program not restarted. (gdb) continue Continuing. ^C Program received signal SIGINT, Interrupt. client_notify_auth_ready (client=0x7f7592775140) at client-common.c:1031 1031 client-common.c: No such file or directory. in client-common.c (gdb) back #0 client_notify_auth_ready (client=0x7f7592775140) at client-common.c:1031 #1 0x00007f758fb90af0 in clients_notify_auth_connected () at client-common-auth.c:837 #2 0x00007f758f8cfc04 in auth_server_input_done (conn=0x7f7591911838) at auth-server-connection.c:127 #3 auth_server_connection_input_line (conn=0x7f7591911838) at auth-server-connection.c:229 #4 auth_server_connection_input (conn=0x7f7591911838) at auth-server-connection.c:281 #5 0x00007f758f8f5e35 in io_loop_call_io (io=0x7f759277e2a0) at ioloop.c:614 #6 0x00007f758f8f7d3f in io_loop_handler_run_internal (ioloop=<value optimized out>) at ioloop-epoll.c:222 #7 0x00007f758f8f5f25 in io_loop_handler_run (ioloop=0x7f75918e4d00) at ioloop.c:666 #8 0x00007f758f8f6148 in io_loop_run (ioloop=0x7f75918e4d00) at ioloop.c:639 #9 0x00007f758f875ab3 in master_service_run (service=0x7f75918e4b90, callback=<value optimized out>) at master-service.c:767 #10 0x00007f758fb96156 in login_binary_run (binary=<value optimized out>, argc=1, argv=0x7f75918e4890) at main.c:549 #11 0x00007f758f4a2d1d in __libc_start_main () from /lib64/libc.so.6 #12 0x00007f758ffc4469 in _start () (gdb)
Anyone have any thoughts?
Regards,
Jason Kiniry
Thank you for this, we'll look into it.
Aki
On 11.01.2018 01:29, Jason Kiniry wrote:
We were able to obtain a better backtrace:
0x00007f4b303b5af5 in clients_notify_auth_connected () at client-common-auth.c:839 839 if (!client_does_custom_io(client) && client->input_blocked) { (gdb) run
Thank you!
Regards,
Jason Kiniry
On Jan 10, 2018, at 4:28 PM, Jason Kiniry jason@cpanel.net wrote:
When in the process of testing out the 2.3.0 version of Dovecot, we noticed that on a busy server, imap-login can sometimes take 100% CPU and remain there indefinitely. We grabbed a gdb trace while it was happening:
dovenull 36053 31.2 0.0 60460 17316 ? R 04:38 11:55 dovecot/imap-login root@server [~]# strace -p 36053 Process 36053 attached ^CProcess 36053 detached root@server [~]# gdb atGNU gdb (GDB) Red Hat Enterprise Linux (7.2-92.el6) Copyright (C) 2010 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/. (gdb) attach 36053 Attaching to process 36053 Reading symbols from /usr/libexec/dovecot/imap-login...done. Reading symbols from /usr/lib64/dovecot/libdovecot-login.so.0...done. Loaded symbols for /usr/lib64/dovecot/libdovecot-login.so.0 Reading symbols from /usr/lib64/dovecot/libdovecot.so.0...done. Loaded symbols for /usr/lib64/dovecot/libdovecot.so.0 Reading symbols from /lib64/libc.so.6...(no debugging symbols found)...done. Loaded symbols for /lib64/libc.so.6 Reading symbols from /usr/lib64/libssl.so.10...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libssl.so.10 Reading symbols from /usr/lib64/libcrypto.so.10...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libcrypto.so.10 Reading symbols from /lib64/librt.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/librt.so.1 Reading symbols from /lib64/libdl.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libdl.so.2 Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/ld-linux-x86-64.so.2 Reading symbols from /lib64/libgssapi_krb5.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libgssapi_krb5.so.2 Reading symbols from /lib64/libkrb5.so.3...(no debugging symbols found)...done. Loaded symbols for /lib64/libkrb5.so.3 Reading symbols from /lib64/libcom_err.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libcom_err.so.2 Reading symbols from /lib64/libk5crypto.so.3...(no debugging symbols found)...done. Loaded symbols for /lib64/libk5crypto.so.3 Reading symbols from /lib64/libz.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libz.so.1 Reading symbols from /lib64/libpthread.so.0...(no debugging symbols found)...done. [Thread debugging using libthread_db enabled] Loaded symbols for /lib64/libpthread.so.0 Reading symbols from /lib64/libkrb5support.so.0...(no debugging symbols found)...done. Loaded symbols for /lib64/libkrb5support.so.0 Reading symbols from /lib64/libkeyutils.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libkeyutils.so.1 Reading symbols from /lib64/libresolv.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libresolv.so.2 Reading symbols from /lib64/libselinux.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libselinux.so.1 Reading symbols from /usr/lib64/dovecot/libssl_iostream_openssl.so...done. Loaded symbols for /usr/lib64/dovecot/libssl_iostream_openssl.so 0x00007f758fb8dd18 in client_notify_auth_ready@plt () from /usr/lib64/dovecot/libdovecot-login.so.0 Missing separate debuginfos, use: debuginfo-install dovecot-2.3.0-4.cp1162.x86_64 (gdb) back #0 0x00007f758fb8dd18 in client_notify_auth_ready@plt () from /usr/lib64/dovecot/libdovecot-login.so.0 #1 0x00007f758fb90af0 in clients_notify_auth_connected () at client-common-auth.c:837 #2 0x00007f758f8cfc04 in auth_server_input_done (conn=0x7f7591911838) at auth-server-connection.c:127 #3 auth_server_connection_input_line (conn=0x7f7591911838) at auth-server-connection.c:229 #4 auth_server_connection_input (conn=0x7f7591911838) at auth-server-connection.c:281 #5 0x00007f758f8f5e35 in io_loop_call_io (io=0x7f759277e2a0) at ioloop.c:614 #6 0x00007f758f8f7d3f in io_loop_handler_run_internal (ioloop=<value optimized out>) at ioloop-epoll.c:222 #7 0x00007f758f8f5f25 in io_loop_handler_run (ioloop=0x7f75918e4d00) at ioloop.c:666 #8 0x00007f758f8f6148 in io_loop_run (ioloop=0x7f75918e4d00) at ioloop.c:639 #9 0x00007f758f875ab3 in master_service_run (service=0x7f75918e4b90, callback=<value optimized out>) at master-service.c:767 #10 0x00007f758fb96156 in login_binary_run (binary=<value optimized out>, argc=1, argv=0x7f75918e4890) at main.c:549 #11 0x00007f758f4a2d1d in __libc_start_main () from /lib64/libc.so.6 #12 0x00007f758ffc4469 in _start () (gdb) run The program being debugged has been started already. Start it from the beginning? (y or n) n Program not restarted. (gdb) continue Continuing. ^C Program received signal SIGINT, Interrupt. client_notify_auth_ready (client=0x7f7592775140) at client-common.c:1031 1031 client-common.c: No such file or directory. in client-common.c (gdb) back #0 client_notify_auth_ready (client=0x7f7592775140) at client-common.c:1031 #1 0x00007f758fb90af0 in clients_notify_auth_connected () at client-common-auth.c:837 #2 0x00007f758f8cfc04 in auth_server_input_done (conn=0x7f7591911838) at auth-server-connection.c:127 #3 auth_server_connection_input_line (conn=0x7f7591911838) at auth-server-connection.c:229 #4 auth_server_connection_input (conn=0x7f7591911838) at auth-server-connection.c:281 #5 0x00007f758f8f5e35 in io_loop_call_io (io=0x7f759277e2a0) at ioloop.c:614 #6 0x00007f758f8f7d3f in io_loop_handler_run_internal (ioloop=<value optimized out>) at ioloop-epoll.c:222 #7 0x00007f758f8f5f25 in io_loop_handler_run (ioloop=0x7f75918e4d00) at ioloop.c:666 #8 0x00007f758f8f6148 in io_loop_run (ioloop=0x7f75918e4d00) at ioloop.c:639 #9 0x00007f758f875ab3 in master_service_run (service=0x7f75918e4b90, callback=<value optimized out>) at master-service.c:767 #10 0x00007f758fb96156 in login_binary_run (binary=<value optimized out>, argc=1, argv=0x7f75918e4890) at main.c:549 #11 0x00007f758f4a2d1d in __libc_start_main () from /lib64/libc.so.6 #12 0x00007f758ffc4469 in _start () (gdb)
Anyone have any thoughts?
Regards,
Jason Kiniry
Is it possible for you to provide output of
p *client p *client->next p *client->next->next
until it hits NULL?
Aki
On 11.01.2018 01:29, Jason Kiniry wrote:
We were able to obtain a better backtrace:
0x00007f4b303b5af5 in clients_notify_auth_connected () at client-common-auth.c:839 839 if (!client_does_custom_io(client) && client->input_blocked) { (gdb) run
Thank you!
Regards,
Jason Kiniry
On Jan 10, 2018, at 4:28 PM, Jason Kiniry jason@cpanel.net wrote:
When in the process of testing out the 2.3.0 version of Dovecot, we noticed that on a busy server, imap-login can sometimes take 100% CPU and remain there indefinitely. We grabbed a gdb trace while it was happening:
dovenull 36053 31.2 0.0 60460 17316 ? R 04:38 11:55 dovecot/imap-login root@server [~]# strace -p 36053 Process 36053 attached ^CProcess 36053 detached root@server [~]# gdb atGNU gdb (GDB) Red Hat Enterprise Linux (7.2-92.el6) Copyright (C) 2010 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/. (gdb) attach 36053 Attaching to process 36053 Reading symbols from /usr/libexec/dovecot/imap-login...done. Reading symbols from /usr/lib64/dovecot/libdovecot-login.so.0...done. Loaded symbols for /usr/lib64/dovecot/libdovecot-login.so.0 Reading symbols from /usr/lib64/dovecot/libdovecot.so.0...done. Loaded symbols for /usr/lib64/dovecot/libdovecot.so.0 Reading symbols from /lib64/libc.so.6...(no debugging symbols found)...done. Loaded symbols for /lib64/libc.so.6 Reading symbols from /usr/lib64/libssl.so.10...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libssl.so.10 Reading symbols from /usr/lib64/libcrypto.so.10...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libcrypto.so.10 Reading symbols from /lib64/librt.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/librt.so.1 Reading symbols from /lib64/libdl.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libdl.so.2 Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/ld-linux-x86-64.so.2 Reading symbols from /lib64/libgssapi_krb5.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libgssapi_krb5.so.2 Reading symbols from /lib64/libkrb5.so.3...(no debugging symbols found)...done. Loaded symbols for /lib64/libkrb5.so.3 Reading symbols from /lib64/libcom_err.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libcom_err.so.2 Reading symbols from /lib64/libk5crypto.so.3...(no debugging symbols found)...done. Loaded symbols for /lib64/libk5crypto.so.3 Reading symbols from /lib64/libz.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libz.so.1 Reading symbols from /lib64/libpthread.so.0...(no debugging symbols found)...done. [Thread debugging using libthread_db enabled] Loaded symbols for /lib64/libpthread.so.0 Reading symbols from /lib64/libkrb5support.so.0...(no debugging symbols found)...done. Loaded symbols for /lib64/libkrb5support.so.0 Reading symbols from /lib64/libkeyutils.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libkeyutils.so.1 Reading symbols from /lib64/libresolv.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libresolv.so.2 Reading symbols from /lib64/libselinux.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libselinux.so.1 Reading symbols from /usr/lib64/dovecot/libssl_iostream_openssl.so...done. Loaded symbols for /usr/lib64/dovecot/libssl_iostream_openssl.so 0x00007f758fb8dd18 in client_notify_auth_ready@plt () from /usr/lib64/dovecot/libdovecot-login.so.0 Missing separate debuginfos, use: debuginfo-install dovecot-2.3.0-4.cp1162.x86_64 (gdb) back #0 0x00007f758fb8dd18 in client_notify_auth_ready@plt () from /usr/lib64/dovecot/libdovecot-login.so.0 #1 0x00007f758fb90af0 in clients_notify_auth_connected () at client-common-auth.c:837 #2 0x00007f758f8cfc04 in auth_server_input_done (conn=0x7f7591911838) at auth-server-connection.c:127 #3 auth_server_connection_input_line (conn=0x7f7591911838) at auth-server-connection.c:229 #4 auth_server_connection_input (conn=0x7f7591911838) at auth-server-connection.c:281 #5 0x00007f758f8f5e35 in io_loop_call_io (io=0x7f759277e2a0) at ioloop.c:614 #6 0x00007f758f8f7d3f in io_loop_handler_run_internal (ioloop=<value optimized out>) at ioloop-epoll.c:222 #7 0x00007f758f8f5f25 in io_loop_handler_run (ioloop=0x7f75918e4d00) at ioloop.c:666 #8 0x00007f758f8f6148 in io_loop_run (ioloop=0x7f75918e4d00) at ioloop.c:639 #9 0x00007f758f875ab3 in master_service_run (service=0x7f75918e4b90, callback=<value optimized out>) at master-service.c:767 #10 0x00007f758fb96156 in login_binary_run (binary=<value optimized out>, argc=1, argv=0x7f75918e4890) at main.c:549 #11 0x00007f758f4a2d1d in __libc_start_main () from /lib64/libc.so.6 #12 0x00007f758ffc4469 in _start () (gdb) run The program being debugged has been started already. Start it from the beginning? (y or n) n Program not restarted. (gdb) continue Continuing. ^C Program received signal SIGINT, Interrupt. client_notify_auth_ready (client=0x7f7592775140) at client-common.c:1031 1031 client-common.c: No such file or directory. in client-common.c (gdb) back #0 client_notify_auth_ready (client=0x7f7592775140) at client-common.c:1031 #1 0x00007f758fb90af0 in clients_notify_auth_connected () at client-common-auth.c:837 #2 0x00007f758f8cfc04 in auth_server_input_done (conn=0x7f7591911838) at auth-server-connection.c:127 #3 auth_server_connection_input_line (conn=0x7f7591911838) at auth-server-connection.c:229 #4 auth_server_connection_input (conn=0x7f7591911838) at auth-server-connection.c:281 #5 0x00007f758f8f5e35 in io_loop_call_io (io=0x7f759277e2a0) at ioloop.c:614 #6 0x00007f758f8f7d3f in io_loop_handler_run_internal (ioloop=<value optimized out>) at ioloop-epoll.c:222 #7 0x00007f758f8f5f25 in io_loop_handler_run (ioloop=0x7f75918e4d00) at ioloop.c:666 #8 0x00007f758f8f6148 in io_loop_run (ioloop=0x7f75918e4d00) at ioloop.c:639 #9 0x00007f758f875ab3 in master_service_run (service=0x7f75918e4b90, callback=<value optimized out>) at master-service.c:767 #10 0x00007f758fb96156 in login_binary_run (binary=<value optimized out>, argc=1, argv=0x7f75918e4890) at main.c:549 #11 0x00007f758f4a2d1d in __libc_start_main () from /lib64/libc.so.6 #12 0x00007f758ffc4469 in _start () (gdb)
Anyone have any thoughts?
Regards,
Jason Kiniry
On 10 Jan 2018, at 17.28, Jason Kiniry jason@cpanel.net wrote:
When in the process of testing out the 2.3.0 version of Dovecot, we noticed that on a busy server, imap-login can sometimes take 100% CPU and remain there indefinitely. We grabbed a gdb trace while it was happening:
dovenull 36053 31.2 0.0 60460 17316 ? R 04:38 11:55 dovecot/imap-login root@server [~]# strace -p 36053 Process 36053 attached ^CProcess 36053 detached
So it's not doing any syscalls. What about ltrace -tt -e '*' -p <pid>?
Also what's your doveconf -n? Mainly wondering about service imap-login { .. } settings. Probably service_count=1 (default)? This somehow hangs here when there's a client with pending input, but auth process wasn't yet connected to. It's not very obvious though how it could have gotten stuck in there.
participants (3)
-
Aki Tuomi
-
Jason Kiniry
-
Timo Sirainen