Bug 187970
| Summary: | gamin is crazy busy when idle. | ||||||||
|---|---|---|---|---|---|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | Dave Jones <davej> | ||||||
| Component: | gamin | Assignee: | Tomáš Bžatek <tbzatek> | ||||||
| Status: | CLOSED WONTFIX | QA Contact: | |||||||
| Severity: | medium | Docs Contact: | |||||||
| Priority: | medium | ||||||||
| Version: | 5 | CC: | ariel, chkr, firewalkergr, hugh, lmacken, namonai, nphilipp, pfrields, triage, tsmetana | ||||||
| Target Milestone: | --- | ||||||||
| Target Release: | --- | ||||||||
| Hardware: | All | ||||||||
| OS: | Linux | ||||||||
| Whiteboard: | bzcl34nup | ||||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||||
| Doc Text: | Story Points: | --- | |||||||
| Clone Of: | Environment: | ||||||||
| Last Closed: | 2008-05-06 15:45:07 UTC | Type: | --- | ||||||
| Regression: | --- | Mount Type: | --- | ||||||
| Documentation: | --- | CRM: | |||||||
| Verified Versions: | Category: | --- | |||||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||||
| Embargoed: | |||||||||
| Attachments: |
|
||||||||
(that should have read 'a billion times a second' instead of 'every few seconds'). anyways, you can see for yourself with strace -p `pidof gam_server` I'm not sure of the details, but gamin sometimes falls back to polling. I think you can set this up to happen for folders or filesystem types (NFS is on by default i think). Anyway, that should be more like "every few seconds", not "a billion times a second", so its probably not this. This might be a dup of bug 132354. I have gam_server problems. I have not analyzed them, but I want to record them before I reboot. I am running FC5, x86_64 (dual core), with updates up to 2006 April 23. This means gamin is version 1.1.7. There are two RPMs installed (by default): one for x86_64 and one for i386. I wish all reports included gamin's version number. According to the gamin site, there were leaks fixed by 1.1.7. Symptom: gam_server eats a lot of memory and a fair bit of CPU. This is after several weeks of uptime. Here's what ps laxgwf said: F UID PID PPID PRI NI VSZ RSS WCHAN STAT TTY TIME COMMAND 0 104 2767 1 15 0 5231900 1942528 - S ? 1753:04 /usr/libexec/gam_server Notice that the RSS is 1.9 gigabytes (my machine has 3G of RAM). VSZ was 5.2g and CPU time was over a day. An strace (enclosed) showed a lot of redundant stuff. For example, a handful of lstats on /etc/mtab with no intervening system calls. There were 6486 references to /etc/mtab in the 31646-line strace, all of which took only a couple of seconds of real time. I "fixed" the problem by sending a SIGHUP to gam_server. I have no idea if this is safe or correct. Here's what ps says about 8 hours later: 0 104 13408 1 15 0 11112 6620 - S ? 1:46 /usr/libexec/gam_server (While this gam_server process was running, I applied all the recent updates to the FC5 system, but have not yet rebooted or even shut down my X session. This may muddy the water. There was no update for gamin.) Created attachment 129206 [details]
strace output for misbehavinb gam_server
I see this about once a week; sometimes it gets so bad that I have to switch to a VT and kill X11 to take my system back. This is with an SMP kernel on a hyperthreaded processor. This is with gamin-0.1.7-1.2.1; I typically run GNOME and amaroK, both of which use fam. This never happened to me with FC4 or FC3 on the same box. same here on my destop with SMP kernel. millions of:
stat64("/etc/mtab", {st_mode=S_IFREG|0644, st_size=406, ...}) = 0
with strace -p <pid_of_gam_server>
I'm using gnome and for 2 days i did nothing with the machine (no apps running),
but still, gam_server uses CPU and memory all the time. The memory consumption
is like follows (in KB):
Wed Jun 14 17:00:35 CEST 2006: 2792
Wed Jun 14 17:01:35 CEST 2006: 2916
Wed Jun 14 17:02:17 CEST 2006: 3004
Wed Jun 14 17:03:17 CEST 2006: 3124
Wed Jun 14 17:04:17 CEST 2006: 3252
Wed Jun 14 17:05:17 CEST 2006: 3376
.........
Wed Jun 14 22:31:32 CEST 2006: 44712
Wed Jun 14 22:32:32 CEST 2006: 44836
Wed Jun 14 22:33:32 CEST 2006: 44964
.........
Thu Jun 15 09:12:56 CEST 2006: 126768
Thu Jun 15 09:13:56 CEST 2006: 126896
Thu Jun 15 09:14:56 CEST 2006: 127028
i did an update this morning, but gam_server still uses ~10% cpu time and memory
consumtion is still rising.
rpm -q gamin
gamin-0.1.7-1.2.1
rpm -q glib2
glib2-2.10.3-1
Created attachment 130959 [details]
strace -p <gam_server_pid)
strace of gam_server. X11 is running, but no applications (except a xterm).
I did an kernel update this morning. After rebooting the machine and some hours gam_server only uses 1344kb of memory. rpm -q kernel-smp kernel-smp-2.6.17-1.2145_FC5 uname -a Linux localhost 2.6.17-1.2145_FC5smp #1 SMP Sat Jul 1 13:19:14 EDT works for me. Could the next person with this issue strace the gnome-panel side of the connection for 5 seconds or so and post the attachment? I'm interested if it's the same bug I've seen, and am working on fixes for, described at Bug #196444. You should see "invalid length" in the strace. Oh and please use "-s 128" strace option. I guess that it might be the same issue because read/write to gnome-panel is on 2, and I see a lot of read(2, 0x588c2c, 4106) = -1 ECONNRESET (Connection reset by peer) in the strace (server) attachments posted here already, which matches the other bug's m.o. Thanks. Hi I think this is related. uname -a Linux anarchos64 2.6.17-1.2174_FC5 #1 SMP Tue Aug 8 15:30:44 EDT 2006 x86_64 x86_64 x86_64 GNU/Linux rpmquery gamin.x86_64 gnome-panel gamin-0.1.7-1.2.1 gnome-panel-2.14.3-1.fc5 Last few weeks/days gam_server takes uses steadly 8% of CPU and it's resident memory usage grows every second. Sending a STOP to gnome-panel, drops gam_server CPU usage to 0% and it's memory usage stops growing. Find below some of the output from the debug file you get when you send a USR2 to gam_server. This repeats over and over again and the file grows to tenths megabytes pretty quick : MONFILE request: from gnome-panel, seq 21, type 1 options 10 gnome-panel listening for /etc/xdg/menus/preferences.menu g_a_s: /etc/xdg/menus/preferences.menu using kernel monitoring inotify: success adding watch for /etc/xdg/menus/preferences.menu (wd = 77192) Adding sub /etc/xdg/menus/preferences.menu to listener gnome-panel inotify: Sending initial events for /etc/xdg/menus/preferences.menu MONDIR request: from gnome-panel, seq 22, type 2 options 10 gnome-panel listening for /etc/xdg/menus/preferences-merged g_a_s: /etc/xdg/menus/preferences-merged using kernel monitoring inotify: success adding watch for /etc/xdg/menus/preferences-merged (wd = 77193) Adding sub /etc/xdg/menus/preferences-merged to listener gnome-panel inotify: Sending initial events for /etc/xdg/menus/preferences-merged MONDIR request: from gnome-panel, seq 23, type 2 options 10 gnome-panel listening for /home/tasos/.config/menus/preferences-merged g_a_s: /home/tasos/.config/menus/preferences-merged using kernel monitoring inotify: failed to add watch for /home/tasos/.config/menus/preferences-merged inotify: reason 2 = No such file or directory inotify: could not add watch for /home/tasos/.config/menus/preferences-merged inotify: adding /home/tasos/.config/menus/preferences-merged to missing list MISSING inotify-missing: add - /home/tasos/.config/menus/preferences-merged Adding sub /home/tasos/.config/menus/preferences-merged to listener gnome-panel inotify: Sending initial events for /home/tasos/.config/menus/preferences-merged -- WAS_MISSING MONDIR request: from gnome-panel, seq 24, type 2 options 10 gnome-panel listening for /etc/xdg/menus/preferences-post-merged g_a_s: /etc/xdg/menus/preferences-post-merged using kernel monitoring inotify: success adding watch for /etc/xdg/menus/preferences-post-merged (wd = 77194) Adding sub /etc/xdg/menus/preferences-post-merged to listener gnome-panel inotify: Sending initial events for /etc/xdg/menus/preferences-post-merged .... Removing all KDE packages except kdelibs has solved the issue. Maybe something is in the kde menu entries. As a followup, I haven't seen this behavior recently. It may have been solved by a gam or kernel update. (In reply to comment #12) > As a followup, I haven't seen this behavior recently. It may have been solved > by a gam or kernel update. I still can see the issue described in comment #10: When gnome-panel is running, gam_server uses ca. 10% of the CPU: ~# uname -a Linux hostname 2.6.17-1.2187_FC5 #1 Mon Sep 11 01:17:06 EDT 2006 i686 athlon i386 GNU/Linux ~# rpmquery gamin gnome-panel gamin-0.1.7-1.2.1 gnome-panel-2.14.3-1.fc5 When I stop gnome-panel: killall -SIGSTOP gnome-panel gam_server doesn't appear in to top 20 of top any more after a killall -SIGCONT gnome-panel it uses again ca. 10% CPU 10887 chkr 15 0 83504 80m 904 S 8.3 7.9 50:48.97 gam_server Additionally there is memory leak, but I think this is covered in #196444. Is there already a solution for this problem? How I could help to find the reason of the problem? Fedora apologizes that these issues have not been resolved yet. We're sorry it's taken so long for your bug to be properly triaged and acted on. We appreciate the time you took to report this issue and want to make sure no important bugs slip through the cracks. If you're currently running a version of Fedora Core between 1 and 6, please note that Fedora no longer maintains these releases. We strongly encourage you to upgrade to a current Fedora release. In order to refocus our efforts as a project we are flagging all of the open bugs for releases which are no longer maintained and closing them. http://fedoraproject.org/wiki/LifeCycle/EOL If this bug is still open against Fedora Core 1 through 6, thirty days from now, it will be closed 'WONTFIX'. If you can reporduce this bug in the latest Fedora version, please change to the respective version. If you are unable to do this, please add a comment to this bug requesting the change. Thanks for your help, and we apologize again that we haven't handled these issues to this point. The process we are following is outlined here: http://fedoraproject.org/wiki/BugZappers/F9CleanUp We will be following the process here: http://fedoraproject.org/wiki/BugZappers/HouseKeeping to ensure this doesn't happen again. And if you'd like to join the bug triage team to help make things better, check out http://fedoraproject.org/wiki/BugZappers This bug is open for a Fedora version that is no longer maintained and will not be fixed by Fedora. Therefore we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen thus bug against that version. Thank you for reporting this bug and we are sorry it could not be fixed. |
strace... poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 32) = 0 poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 32) = 0 poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 1) = 0 poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 11) = 0 poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 21) = 0 poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 32) = 0 poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 2) = 0 poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 3) = 0 lstat("/home/davej/.config/menus/gnome-screensavers.menu", 0x7ffffffae7a0) = -1 ENOENT (No such file or directory) lstat("/home/davej/.config/menus/server-settings-merged", 0x7ffffffae7a0) = -1 ENOENT (No such file or directory) lstat("/etc/xdg/menus/server-settings-merged", 0x7ffffffae7a0) = -1 ENOENT (No such file or directory) lstat("/home/davej/.config/menus/system-settings-merged", 0x7ffffffae7a0) = -1 ENOENT (No such file or directory) lstat("/etc/xdg/menus/system-settings-merged", 0x7ffffffae7a0) = -1 ENOENT (No such file or directory) lstat("/home/davej/.config/menus/preferences-merged", 0x7ffffffae7a0) = -1 ENOENT (No such file or directory) lstat("/home/davej/.config/menus/settings-merged", 0x7ffffffae7a0) = -1 ENOENT (No such file or directory) lstat("/etc/xdg/menus/settings-merged", 0x7ffffffae7a0) = -1 ENOENT (No such file or directory) lstat("/home/davej/.config/menus/settings.menu", 0x7ffffffae7a0) = -1 ENOENT (No such file or directory) lstat("/etc/xdg/menus/applications-kmenuedit.menu", 0x7ffffffae7a0) = -1 ENOENT (No such file or directory) lstat("/home/davej/.config/menus/applications-merged", 0x7ffffffae7a0) = -1 ENOENT (No such file or directory) lstat("/home/davej/.config/menus/applications.menu", 0x7ffffffae7a0) = -1 ENOENT (No such file or directory) poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 26) = 0 poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 0) = 0 poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 7) = 0 poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 0) = 0 poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 24) = 0 poll([{fd=1, events=0}, {fd=2, events=POLLIN}, {fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=0, events=POLLIN}, {fd=1, events=POLLIN}], 6, 1) = 0 poll( <unfinished ...> Process 2760 detached over and over and over every couple seconds. ltrace is also interesting. g_queue_foreach(0x51b520, 0x40c073, 0, 0x7ffffffae8d0, 7) = 0 g_queue_is_empty(0x51b520, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 7) = 1 g_queue_is_empty(0x51b500, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 7) = 1 g_queue_foreach(0x51b520, 0x40c073, 0, 0x7ffffffae8d0, 925704) = 0 g_queue_is_empty(0x51b520, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 925704) = 1 g_queue_is_empty(0x51b500, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 925704) = 1 g_queue_foreach(0x51b520, 0x40c073, 0, 0x7ffffffae8d0, 961703) = 0 g_queue_is_empty(0x51b520, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 961703) = 1 g_queue_is_empty(0x51b500, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 961703) = 1 g_queue_is_empty(0x51b900, 0x51fba0, 0x51fba0, 0x7ffffffae8d0, 961703) = 1 g_queue_is_empty(0x5217a0, 0x522b40, 0x522b40, 0x7ffffffae8d0, 961703) = 1 g_queue_is_empty(0x527540, 0x526270, 0x526270, 0x7ffffffae8d0, 961703) = 1 g_queue_foreach(0x51b520, 0x40c073, 0, 0x7ffffffae8d0, 997703) = 0 g_queue_is_empty(0x51b520, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 997703) = 1 g_queue_is_empty(0x51b500, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 997703) = 1 g_queue_foreach(0x51b520, 0x40c073, 0, 0x7ffffffae8d0, 33702) = 0 g_queue_is_empty(0x51b520, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 33702) = 1 g_queue_is_empty(0x51b500, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 33702) = 1 g_queue_is_empty(0x51b900, 0x51fba0, 0x51fba0, 0x7ffffffae8d0, 7) = 1 g_queue_is_empty(0x5217a0, 0x522b40, 0x522b40, 0x7ffffffae8d0, 7) = 1 g_queue_is_empty(0x527540, 0x526270, 0x526270, 0x7ffffffae8d0, 7) = 1 g_queue_foreach(0x51b520, 0x40c073, 0, 0x7ffffffae8d0, 69701) = 0 g_queue_is_empty(0x51b520, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 69701) = 1 g_queue_is_empty(0x51b500, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 69701) = 1 g_queue_foreach(0x51b520, 0x40c073, 0, 0x7ffffffae8d0, 7) = 0 g_queue_is_empty(0x51b520, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 7) = 1 g_queue_is_empty(0x51b500, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 7) = 1 g_queue_foreach(0x51b520, 0x40c073, 0, 0x7ffffffae8d0, 137700) = 0 g_queue_is_empty(0x51b520, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 137700) = 1 g_queue_is_empty(0x51b500, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 137700) = 1 g_queue_is_empty(0x51b900, 0x51fba0, 0x51fba0, 0x7ffffffae8d0, 161699) = 1 g_queue_is_empty(0x5217a0, 0x522b40, 0x522b40, 0x7ffffffae8d0, 161699) = 1 g_queue_is_empty(0x527540, 0x526270, 0x526270, 0x7ffffffae8d0, 161699) = 1 g_queue_foreach(0x51b520, 0x40c073, 0, 0x7ffffffae8d0, 173699) = 0 g_queue_is_empty(0x51b520, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 173699) = 1 g_queue_is_empty(0x51b500, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 173699) = 1 g_queue_foreach(0x51b520, 0x40c073, 0, 0x7ffffffae8d0, 209699) = 0 g_queue_is_empty(0x51b520, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 209699) = 1 g_queue_is_empty(0x51b500, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 209699) = 1 g_queue_foreach(0x51b520, 0x40c073, 0, 0x7ffffffae8d0, 7) = 0 g_queue_is_empty(0x51b520, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 7) = 1 g_queue_is_empty(0x51b500, 0x40c073, 0x2aaaaac16307, 0x7ffffffae8d0, 7) = 1 yada yada yada.. Why isn't it using inotify ?