Bug#454764: Nautilus at 100% cpu after running as root
Regis Fernandes Gontijo
regisfg at yahoo.com.br
Mon Sep 15 23:40:41 UTC 2008
Hi all
I have a similar problem even when not running nautilus explicitly under GNOME provided by Debian Lenny as an unprivileged user. Although I can't determine the conditions that raise this problem in my environment, I can reproduce it as Jay Sears suggested.
I've also followed the instructions provided by Josselin Mouette to trace it and I'll post it below:
gdb /usr/bin/nautilus <pid>
(gdb) “thread apply all bt full”
Thread 1 (Thread 0x7f99ff62a780 (LWP 9546)):
#0 0x00007f99fa31cb74 in fputs () from /lib/libc.so.6
No symbol table info available.
#1 0x000000000049ba41 in write_string (
filename=0x1212400 "/root/nautilus-debug-log.txt", file=0x1, str=0x0,
error=0x313120) at nautilus-debug-log.c:446
No locals.
#2 0x000000000049bb57 in nautilus_debug_log_dump (
filename=0x1212400 "/root/nautilus-debug-log.txt", error=0x0)
at nautilus-debug-log.c:508
file = <value optimized out>
success = <value optimized out>
__PRETTY_FUNCTION__ = "nautilus_debug_log_dump"
#3 0x0000000000440104 in dump_debug_log () at nautilus-main.c:213
filename = 0x1535e90 "0xd49d70 2008/09/15 16:36:07.4790 (USER): debug log dumped due to signal 11"
#4 0x0000000000440130 in sigfatal_handler (sig=11) at nautilus-main.c:258
func = <value optimized out>
#5 <signal handler called>
No symbol table info available.
#6 0x00007f99fb615d2d in ?? () from /usr/lib/libglib-2.0.so.0
No symbol table info available.
---Type <return> to continue, or q <return> to quit---
#7 0x00007f99fb616cb9 in g_slice_free1 () from /usr/lib/libglib-2.0.so.0
No symbol table info available.
#8 0x00007f99fb5ebb9f in ?? () from /usr/lib/libglib-2.0.so.0
No symbol table info available.
#9 0x00007f99fb5ebc0d in ?? () from /usr/lib/libglib-2.0.so.0
No symbol table info available.
#10 0x00007f99fb5ec80a in g_hash_table_remove_all ()
from /usr/lib/libglib-2.0.so.0
No symbol table info available.
#11 0x00007f99fb5ec915 in g_hash_table_destroy ()
from /usr/lib/libglib-2.0.so.0
No symbol table info available.
#12 0x00007f99feee148a in ?? () from /usr/lib/libeel-2-2.20.so
No symbol table info available.
#13 0x00007f99feed9ad8 in eel_debug_shut_down () from /usr/lib/libeel-2-2.20.so
No symbol table info available.
#14 0x0000000000440bb3 in main (argc=<value optimized out>,
argv=0x7fff07767168) at nautilus-main.c:563
kill_shell = 0
restart_shell = 0
no_default_window = 0
browser_window = 0
no_desktop = 0
startup_id = <value optimized out>
startup_id_copy = 0xd42560 ""
session_to_load = 0x0
geometry = (gchar *) 0x0
remaining = (const gchar **) 0x0
perform_self_check = 0
context = <value optimized out>
application = (NautilusApplication *) 0xd58430
program = (GnomeProgram *) 0xd5a050
options = {{long_name = 0x4f7e5e "check", short_name = 99 'c',
flags = 0, arg = G_OPTION_ARG_NONE, arg_data = 0x7fff07767058,
description = 0x4f7f10 "Perform a quick set of self-check tests.",
arg_description = 0x0}, {long_name = 0x4fb407 "geometry",
short_name = 103 'g', flags = 0, arg = G_OPTION_ARG_STRING,
arg_data = 0x7fff07767048,
description = 0x4f7f40 "Create the initial window with the given geometry.", arg_description = 0x4f7d01 "GEOMETRY"}, {
long_name = 0x4f7d0a "no-default-window", short_name = 110 'n', flags = 0,
arg = G_OPTION_ARG_NONE, arg_data = 0x7fff07767064,
description = 0x4f7f78 "Only create windows for explicitly specified URIs.", arg_description = 0x0}, {long_name = 0x4f7d1c "no-desktop",
short_name = 0 '\0', flags = 0, arg = G_OPTION_ARG_NONE,
arg_data = 0x7fff0776705c,
description = 0x4f7fb0 "Do not manage the desktop (ignore the preference set in the preferences dialog).", arg_description = 0x0}, {
long_name = 0x4fa3b7 "browser", short_name = 0 '\0', flags = 0,
arg = G_OPTION_ARG_NONE, arg_data = 0x7fff07767060,
description = 0x4f7d27 "open a browser window.", arg_description = 0x0}, {
long_name = 0x4f7e66 "quit", short_name = 113 'q', flags = 0,
arg = G_OPTION_ARG_NONE, arg_data = 0x7fff0776706c,
description = 0x4f7d3e "Quit Nautilus.", arg_description = 0x0}, {
long_name = 0x4f7e6d "restart", short_name = 0 '\0', flags = 1,
arg = G_OPTION_ARG_NONE, arg_data = 0x7fff07767068,
description = 0x4f7d4d "Restart Nautilus.", arg_description = 0x0}, {
long_name = 0x4fc984 "", short_name = 0 '\0', flags = 0,
arg = G_OPTION_ARG_STRING_ARRAY, arg_data = 0x7fff07767040,
description = 0x0, arg_description = 0x4f7d5f "[URI...]"}, {
long_name = 0x4f4013 "load-session", short_name = 108 'l', flags = 0,
arg = G_OPTION_ARG_STRING, arg_data = 0x7fff07767050,
description = 0x4f8008 "Load a saved session from the specified file. Implies \"--no-default-window\".", arg_description = 0x4f7d68 "FILENAME"}, {
long_name = 0x0, short_name = 0 '\0', flags = 0, arg = G_OPTION_ARG_NONE,
arg_data = 0x0, description = 0x0, arg_description = 0x0}}
#0 0x00007f99fa31cb74 in fputs () from /lib/libc.so.6
I've found the file /root/nautilus-debug-log.txt (cited in the above log) and it's contents is something like this :
===== BEGIN MILESTONES =====
0xa171c28 2008/09/06 15:13:47.5281 (USER): debug log dumped due to signal 11
0xa171c28 2008/09/06 15:13:47.5714 (USER): debug log dumped due to signal 11
0xa171c28 2008/09/06 15:13:47.5844 (USER): debug log dumped due to signal 11
0xa171c28 2008/09/06 15:13:47.6156 (USER): debug log dumped due to signal 11
(repeated thousands of times...)
0xa171c28 2008/09/08 09:56:18.5323 (USER): debug log dumped due to signal 11
0xa171c28 2008/09/08 09:56:20.1843 (USER): debug log dumped due to signal 11
0xa171c28 2008/09/08 09:56:21.8203 (USER): debug log dumped due to signal 11
0xa171c28 2008/09/08 09:56:23.4981 (USER): debug log dumped due to signal 11
===== END MILESTONES =====
===== BEGIN RING BUFFER =====
0xa171c28 2008/09/08 09:28:22.4405 (USER): debug log dumped due to signal 11
0xa171c28 2008/09/08 09:28:23.9408 (USER): debug log dumped due to signal 11
0xa171c28 2008/09/08 09:28:25.5356 (USER): debug log dumped due to signal 11
0xa171c28 2008/09/08 09:28:27.1137 (USER): debug log dumped due to signal 11
(repeated thousands of times...)
0xa171c28 2008/09/08 09:56:18.5323 (USER): debug log dumped due to signal 11
0xa171c28 2008/09/08 09:56:20.1843 (USER): debug log dumped due to signal 11
0xa171c28 2008/09/08 09:56:21.8203 (USER): debug log dumped due to signal 11
0xa171c28 2008/09/08 09:56:23.4981 (USER): debug log dumped due to signal 11
===== END RING BUFFER =====
This configuration for the debug log can be re-created
by putting the following in ~/nautilus-debug-log.conf
(use ';' to separate domain names):
[debug log]
max lines=1000
Of course that now I know that I can avoid the growing of ~/nautilus-debug-log.conf after reading the log but watching this file I've confirmed some information obtained by strace, as I'll post below.
Just as a comment, I've noted this bug because at my job we are trying Debian Lenny in five stations, which are nfs clients. Last days the sysadmin reported to us that several times the nfs server was overloaded when Nautilus is running under our Debian Lenny stations. Using strace I can suppose that it's due to write syscalls from nautilus, because I've found huge nautilus-debug-log.txt files at the home directories of some users, and these users were warned by the sysadmin about nfs server cpu overloading when running nautilus, as I will describe bellow:
1: At some time nautilus crashed and it started to fill the file ~/nautilus-debug-log.txt, using write syscalls of 4KB buffers (see the write syscalls from nautilus bellow):
fstat(22, {st_dev=makedev(8, 7), st_ino=101848, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=0,st_size=0, st_atime=2008/09/15-18:06:33, st_mtime=2008/09/15-18:27:00, st_ctime=2008/09/15-18:27:00}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f99ec91e000
write(22, "===== BEGIN MILESTONES =====\n0xd49d70 2008/09/15 16:35:18.9812 (USER): debug log dumped due to signal 11\n0xd49d70 2008/09/15 16:35:18.9814 (USER): debug log dumped due to signal 11\n0xd49d70 2008/09/15 16:35:18.9815 (USER): debug log dumped due to signal 11"..., 4096) = 4096
(repeated thousands of times...)
write(22, "g log dumped due to signal 11\n0xd49d70 2008/09/15 18:27:00.5071 (USER): debug log dumped due to signal 11\n0xd49d70 2008/09/15 18:27:00.5742 (USER): debug log dumped due to signal 11\n0xd49d70 2008/09/15 18:27:00.6411 (USER): debug log dumped due to signal 11\n0xd49d70 2008/09/15 18:27:00.7078 (USER): debug log dumped due to signal 11\n0xd49d70 2008/09/15 18:27:00.7746 (USER): debug log dumped due to signal 11\n0xd49d70 2008/09/15 18:27:00.8428 (USER): debug log dumped due to signal 11\n===== END RING BUFFER =====\n\n\nThis configuration for the debug log can be re-created\nby putting the following in ~/nautilus-debug-log.conf\n(use ';' to separate domain names):\n\n\n[debug log]\nmax lines=1000\n"..., 690) = 690
close(22) = 0
2: Last syscall nautilus finnished to write the log into nautilus-debug-log.txt. Then it tried to close the file and after this we can see a segfault:
munmap(0x7f99ec91e000, 4096) = 0
rt_sigreturn(0x7f99fa6069e0) = 51
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
3: but now nautilus opened the same file again and repeated everything...
stat("/etc/localtime", {st_dev=makedev(8, 7), st_ino=1207, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=8, st_size=1983, st_atime=2008/09/15-18:27:00, st_mtime=2008/09/15-11:47:05, st_ctime=2008/09/15-11:47:05}) = 0
open("/root/nautilus-debug-log.txt", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 22
fstat(22, {st_dev=makedev(8, 7), st_ino=101848, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=0, st_size=0, st_atime=2008/09/15-18:06:33, st_mtime=2008/09/15-18:27:04, st_ctime=2008/09/15-18:27:04}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f99ec91e000
write(22, "===== BEGIN MILESTONES =====\n0xd49d70 2008/ (...)
And if I don't now that my nautilus process crashed and, for example, lock my nfs client system at the end of the day (which runs Debian Lenny + GNOME, and then , which uses Nautilus) and return next morning, I think that a lot of write syscalls per minute after some hours would overload the nfs server and sometimes it could gerenate huge nautilus-debug-log.txt files. And in fact the server was known to be overloaded a lot of times under similar conditions.
I hope it could help you to solve this problem, but considering that this bug is also known by Ubuntu, I think it would be a problem of Nautilus and not of Debian. Should I send this report to GNOME project?
Best regards and thank you very much.
Regis Fernandes Gontijo
---
Diga adeus para a Microsoft. Agora.
http://goodbye-microsoft.com/
Seu Linux não roda os downloads .exe que você baixa na rede? Seus problemas acabaram! /bin/true setup.exe
http://regisfg.multiply.com
http://www.advogato.org/person/regisfg
Usuário GNU/Linux 341449 - http://counter.li.org
Ooops... Não basta ser GNU/Linux, tem que ser Debian! @
Email livre de vírus! Este computador é movido a Debian GNU/Linux e Gnome. Use Debian você também!
www.debian.org
www.gnome.org
www.gnu.org
Novos endereços, o Yahoo! que você conhece. Crie um email novo com a sua cara @ymail.com ou @rocketmail.com.
http://br.new.mail.yahoo.com/addresses
More information about the pkg-gnome-maintainers
mailing list