Menu

#536 pcmanfm using high cpu when ran twice

1.0.1
closed-fixed
nobody
pcmanfm (136)
7
2015-01-27
2012-05-18
No

This is on NetBSD. pcmanfm version 0.9.10

When ran using --desktop (via the default lxde-common) the desktop icons appear; but when I click the pcmanfm icon on the lxpanel
(using default configuration), the process goes to high cpu near 100%. (System is sluggish and menus and other items get stuck unti I kill it.)

I killed with -6 to get core dump. here is backtrace of that:

(gdb) bt
#0 0x00007f7ff2133dda in read () from /usr/lib/libc.so.12
#1 0x00007f7ff24066f5 in read () from /usr/lib/libpthread.so.0
#2 0x00007f7ff4909c30 in _xcb_in_read () from /usr/pkg/lib/libxcb.so.1
#3 0x00007f7ff490a312 in xcb_poll_for_event () from /usr/pkg/lib/libxcb.so.1
#4 0x00007f7ff4b49a45 in poll_for_event () from /usr/pkg/lib/libX11.so.6
#5 0x00007f7ff4b4a4cf in poll_for_response () from /usr/pkg/lib/libX11.so.6
#6 0x00007f7ff4b4a7f9 in _XEventsQueued () from /usr/pkg/lib/libX11.so.6
#7 0x00007f7ff4b340bd in XPending () from /usr/pkg/lib/libX11.so.6
#8 0x00007f7ff735df6b in gdk_event_send_client_message_for_display ()
from /usr/pkg/lib/libgdk-x11-2.0.so.0
#9 0x00007f7ff2a4cbfc in g_main_context_prepare ()
from /usr/pkg/lib/libglib-2.0.so.0
#10 0x00007f7ff2a4cd6a in g_main_context_prepare ()
from /usr/pkg/lib/libglib-2.0.so.0
#11 0x00007f7ff2a4cfdc in g_main_loop_run () from /usr/pkg/lib/libglib-2.0.so.0
#12 0x00007f7ff783f952 in gtk_main () from /usr/pkg/lib/libgtk-x11-2.0.so.0
#13 0x000000000040f59e in main ()

It happened to start back up. When I kill with normal -TERM it does not start back up.

Then I ran with ktrace:

...
2801 1 pcmanfm CALL read(3,0x7f7ff1a6a074,0x1000)
2801 1 pcmanfm RET read -1 errno 35 Resource temporarily unavailable
2801 1 pcmanfm CALL clock_gettime(3,0x7f7fffffda30)
2801 1 pcmanfm RET clock_gettime 0
2801 1 pcmanfm CALL poll(0x7f7ff0c470d0,5,0x86)
2801 1 pcmanfm RET poll 2
2801 1 pcmanfm CALL read(4,0x7f7fffffda80,0x10)
2801 1 pcmanfm GIO fd 4 read 2 bytes
"\^A\^A"
2801 1 pcmanfm RET read 2
2801 1 pcmanfm CALL clock_gettime(3,0x7f7fffffda60)
2801 1 pcmanfm RET clock_gettime 0
2801 1 pcmanfm CALL write(5,0x7f7fffffda30,1)
2801 1 pcmanfm GIO fd 5 wrote 1 bytes
"\^A"
2801 1 pcmanfm RET write 1
2801 1 pcmanfm CALL read(9,0x7f7ff0c1f800,0x400)
2801 1 pcmanfm GIO fd 9 read 0 bytes
""
... this was repeated thousands of times ... and so was just the following ....

2801 1 pcmanfm RET read -1 errno 35 Resource temporarily unavailable
2801 1 pcmanfm CALL read(3,0x7f7ff1a6a074,0x1000)

...

I think fd 3 is:

2801 1 pcmanfm NAMI "/etc/pwd.db"
2801 1 pcmanfm RET open 3

I think fd 5 is some pipe.

I think fd 9 is some socket but not sure. It read data:
/home/reed\n0\n--show-pref\n0\n

I can repeat problem by starting pcmanfm twice. Start it via menu or via panel launcher and then do it again. Or whrn ran with --desktop and run again.

It does not happen if I open the file manager by clicking on folder on the desktop (since it is the same process I assume).

Discussion

  • Lonely Stranger

    Lonely Stranger - 2012-05-19

    I cannot reproduce it. Opened 3 entities of pcmanfm via lxpanel menu and no mentioned symptoms. Could you, please, remake pcmanfm with debug symbols and reproduce your bug getting info? Unfortunately your backtrace above is useless and gives some false assumptions until you have debug symbols in pcmanfm and libfm which are obviously stripped by default install. Thank you in advance.

     
  • Jeremy C. Reed

    Jeremy C. Reed - 2012-05-20

    I built with -g and removed the -s from install, and then kill -6 the broken process.

    #0 0x00007f7ff1f33dda in read () from /usr/lib/libc.so.12
    #1 0x00007f7ff22066f5 in read () from /usr/lib/libpthread.so.0
    #2 0x00007f7ff288552f in g_wakeup_acknowledge ()
    from /usr/pkg/lib/libglib-2.0.so.0
    #3 0x00007f7ff284c961 in g_main_context_check ()
    from /usr/pkg/lib/libglib-2.0.so.0
    #4 0x00007f7ff284cde1 in g_main_context_prepare ()
    from /usr/pkg/lib/libglib-2.0.so.0
    #5 0x00007f7ff284cfdc in g_main_loop_run () from /usr/pkg/lib/libglib-2.0.so.0
    #6 0x00007f7ff783f952 in gtk_main () from /usr/pkg/lib/libgtk-x11-2.0.so.0
    #7 0x000000000040f5ae in main (argc=1, argv=0x7f7fffffd9f0) at pcmanfm.c:201

    I guess I will have to check the debug symbols and make sure every dependency is not stripped. I am not sure if aborting it gives any clue of where it is at.

    I ran it again with ktrace. Attempt to start it again from the panel. It never displayed any filemanager. The CPU usage went up. I sorted the kdump output and counted each line; here are the busiest lines; see the huge jump from
    1427 to 1750938 to where the loop begins:

    996 4314 1 pcmanfm CALL poll(0x7f7ff0c40050,5,0x3f)
    999 4314 1 pcmanfm CALL poll(0x7f7ff0c40050,5,0x34)
    1010 4314 1 pcmanfm CALL poll(0x7f7ff0c40050,5,0x29)
    1427 4314 1 pcmanfm RET __stat30 -1 errno 2 No such file or directory
    1750938 "\^A\^A"
    1750938 4314 1 pcmanfm GIO fd 4 read 2 bytes
    1750938 4314 1 pcmanfm RET read 2
    1750950 4314 1 pcmanfm RET poll 2
    1750954 4314 1 pcmanfm CALL read(9,0x7f7ff0c1b800,0x400)
    1750981 4314 1 pcmanfm CALL clock_gettime(3,0x7f7fffffd850)
    1751080 4314 1 pcmanfm GIO fd 9 read 0 bytes
    1751084 4314 1 pcmanfm CALL clock_gettime(3,0x7f7fffffd820)
    1751110 4314 1 pcmanfm CALL read(4,0x7f7fffffd870,0x10)
    1751194 4314 1 pcmanfm RET read 0
    1751305 ""
    1751561 4314 1 pcmanfm CALL read(3,0x7f7ff1a6a074,0x1000)
    1751571 4314 1 pcmanfm RET read -1 errno 35 Resource temporarily unava
    ilable
    3501910 4314 1 pcmanfm CALL write(5,0x7f7fffffd820,1)
    3501920 4314 1 pcmanfm GIO fd 5 wrote 1 bytes
    3501920 4314 1 pcmanfm RET write 1
    3501938 "\^A"
    3502139 4314 1 pcmanfm RET clock_gettime 0

    For running for less than a minute the loop caused 2.6 GB of ktrace data. I bzipped a small portion of the kdump output; here it is: http://tx.reedmedia.net:17777/kdump.out.bz2 -- maybe this can give some clue.

     
  • Lonely Stranger

    Lonely Stranger - 2012-05-21

    The program almost certain has some other threads running ATM. Would be nice to explore corefile what other threads doing too as your data does not give clues what happens unfortunately.

     
  • Jeremy C. Reed

    Jeremy C. Reed - 2012-05-22

    How to build with better debug symbols? I configured with --enable-debug and then manually copied the unstripped src/pcmanfm to my bin directory.

    I run with gdb (and not desktop mode). In another console I type pcmanfm and press enter. I only have one process running still. The CPU goes up and pcmanfm is unsuable. I Ctrl-C, bt, and then cont a few times in gdb:

    (gdb) bt
    #0 0x00007f7ff1f33dda in read () from /usr/lib/libc.so.12
    #1 0x00007f7ff22066f5 in read () from /usr/lib/libpthread.so.0
    #2 0x00007f7ff4709c30 in _xcb_in_read () from /usr/pkg/lib/libxcb.so.1
    #3 0x00007f7ff470a312 in xcb_poll_for_event () from /usr/pkg/lib/libxcb.so.1
    #4 0x00007f7ff4949a45 in poll_for_event () from /usr/pkg/lib/libX11.so.6
    #5 0x00007f7ff494a4cf in poll_for_response () from /usr/pkg/lib/libX11.so.6
    #6 0x00007f7ff494a7f9 in _XEventsQueued () from /usr/pkg/lib/libX11.so.6
    #7 0x00007f7ff49340bd in XPending () from /usr/pkg/lib/libX11.so.6
    #8 0x00007f7ff735df6b in gdk_event_send_client_message_for_display ()
    from /usr/pkg/lib/libgdk-x11-2.0.so.0
    #9 0x00007f7ff284cbfc in g_main_context_prepare ()
    from /usr/pkg/lib/libglib-2.0.so.0
    #10 0x00007f7ff284cd6a in g_main_context_prepare ()
    from /usr/pkg/lib/libglib-2.0.so.0
    #11 0x00007f7ff284cfdc in g_main_loop_run () from /usr/pkg/lib/libglib-2.0.so.0
    #12 0x00007f7ff783f952 in gtk_main () from /usr/pkg/lib/libgtk-x11-2.0.so.0
    #13 0x000000000040f60e in main (argc=1, argv=0x7f7fffffdc20) at pcmanfm.c:201

    #0 0x00007f7ff1f33e3a in poll () from /usr/lib/libc.so.12
    #1 0x00007f7ff22069e1 in poll () from /usr/lib/libpthread.so.0
    #2 0x00007f7ff284ce6a in g_main_context_prepare ()
    from /usr/pkg/lib/libglib-2.0.so.0
    #3 0x00007f7ff284cfdc in g_main_loop_run () from /usr/pkg/lib/libglib-2.0.so.0
    #4 0x00007f7ff783f952 in gtk_main () from /usr/pkg/lib/libgtk-x11-2.0.so.0
    #5 0x000000000040f60e in main (argc=1, argv=0x7f7fffffdc20) at pcmanfm.c:201

    #0 0x00007f7ff1f33dda in read () from /usr/lib/libc.so.12
    #1 0x00007f7ff22066f5 in read () from /usr/lib/libpthread.so.0
    #2 0x00007f7ff4709c30 in _xcb_in_read () from /usr/pkg/lib/libxcb.so.1
    #3 0x00007f7ff470a312 in xcb_poll_for_event () from /usr/pkg/lib/libxcb.so.1
    #4 0x00007f7ff4949a45 in poll_for_event () from /usr/pkg/lib/libX11.so.6
    #5 0x00007f7ff494a4cf in poll_for_response () from /usr/pkg/lib/libX11.so.6
    #6 0x00007f7ff494a7f9 in _XEventsQueued () from /usr/pkg/lib/libX11.so.6
    #7 0x00007f7ff49340bd in XPending () from /usr/pkg/lib/libX11.so.6
    #8 0x00007f7ff735df6b in gdk_event_send_client_message_for_display ()
    from /usr/pkg/lib/libgdk-x11-2.0.so.0
    #9 0x00007f7ff284cbfc in g_main_context_prepare ()
    from /usr/pkg/lib/libglib-2.0.so.0
    #10 0x00007f7ff284cd6a in g_main_context_prepare ()
    from /usr/pkg/lib/libglib-2.0.so.0
    #11 0x00007f7ff284cfdc in g_main_loop_run () from /usr/pkg/lib/libglib-2.0.so.0
    #12 0x00007f7ff783f952 in gtk_main () from /usr/pkg/lib/libgtk-x11-2.0.so.0
    #13 0x000000000040f60e in main (argc=1, argv=0x7f7fffffdc20) at pcmanfm.c:201

    If you have any specific steps on how to build or install or run gdb, etc, I will be glad to try them.

    Or if you'd like access to the system to test it, please let me know.

     
  • Lonely Stranger

    Lonely Stranger - 2012-05-23

    To view all current threads you can enter command 'info threads' and then switch between threads with 'thread 1', 'thread 2' and so on. I meant exactly this.

    About your ktrace - it would be very nice if you could find in your dump OPENs which returned file descriptors which were in loop, probably it could help somehow.

     
  • Jeremy C. Reed

    Jeremy C. Reed - 2012-05-23

    Here is some gdb thread info:

    (gdb) info threads
    3 process 68579 0x00007f7ff1f33c3a in write () from /usr/lib/libc.so.12
    2 process 1182691 0x00007f7ff1f6cfea in _lwp_exit ()
    from /usr/lib/libc.so.12
    * 1 process 134115 0x00007f7ff1f34b3a in kevent () from /usr/lib/libc.so.12

    (gdb) thread 1
    [Switching to thread 1 (process 134115)]#0 0x00007f7ff1f34b3a in kevent ()
    from /usr/lib/libc.so.12
    (gdb) bt
    #0 0x00007f7ff1f34b3a in kevent () from /usr/lib/libc.so.12
    #1 0x00007f7ff32ede60 in g_local_file_monitor_get_type ()
    from /usr/pkg/lib/libgio-2.0.so.0
    #2 0x00007f7ff220b572 in pthread_create () from /usr/lib/libpthread.so.0
    #3 0x00007f7ff1f54370 in swapcontext () from /usr/lib/libc.so.12
    #4 0x00007f7ff7fc5740 in ?? ()
    #5 0x0000000000000000 in ?? ()

    You can see from above that I use a different glib2 and no longer using the gio-fam.
    I also don't know why I don't have debugging info.
    I built with --enable-debug and have an unstripped binary.

    (gdb) thread 2
    [Switching to thread 2 (process 1182691)]#0 0x00007f7ff1f6cfea in _lwp_exit ()
    from /usr/lib/libc.so.12
    (gdb) bt
    #0 0x00007f7ff1f6cfea in _lwp_exit () from /usr/lib/libc.so.12
    #1 0x00007f7ff220ad3d in pthread_exit () from /usr/lib/libpthread.so.0
    #2 0x00007f7ff220b57a in pthread_create () from /usr/lib/libpthread.so.0
    #3 0x00007f7ff1f54370 in swapcontext () from /usr/lib/libc.so.12
    #4 0x00007f7ff0400000 in ?? ()
    #5 0x0000000611110001 in ?? ()
    #6 0x0000000033330003 in ?? ()
    #7 0x0000000000000000 in ?? ()

    (Sorry I do not know why I don't have debugging info.)

    (gdb) thread 3
    [Switching to thread 3 (process 68579)]#0 0x00007f7ff1f33c3a in write ()
    from /usr/lib/libc.so.12
    (gdb) bt
    #0 0x00007f7ff1f33c3a in write () from /usr/lib/libc.so.12
    #1 0x00007f7ff22064c3 in write () from /usr/lib/libpthread.so.0
    #2 0x00007f7ff28854e7 in g_wakeup_signal () from /usr/pkg/lib/libglib-2.0.so.0
    #3 0x00007f7ff2849bec in g_main_loop_is_running ()
    from /usr/pkg/lib/libglib-2.0.so.0
    #4 0x00007f7ff284aa55 in g_main_context_dispatch ()
    from /usr/pkg/lib/libglib-2.0.so.0
    #5 0x00007f7ff284ce46 in g_main_context_prepare ()
    from /usr/pkg/lib/libglib-2.0.so.0
    #6 0x00007f7ff284cfdc in g_main_loop_run () from /usr/pkg/lib/libglib-2.0.so.0
    #7 0x00007f7ff783f952 in gtk_main () from /usr/pkg/lib/libgtk-x11-2.0.so.0
    #8 0x000000000040f60e in main (argc=1, argv=0x7f7fffffdc58) at pcmanfm.c:201

    But this one does have debugging symbols.

    As for the looping entries in the ktrace output:

    23343 1 pcmanfm CALL open(0x7f7ff1fe1234,0,0)
    23343 1 pcmanfm NAMI "/etc/pwd.db"
    23343 1 pcmanfm RET open 3

    (which is getpwnam or getpwuid or similar)

    23343 7 pcmanfm CALL open(0x7f7ff07fdf00,0,0xf1fe0201)
    23343 7 pcmanfm NAMI "/usr/share/nls/C/libc.cat"
    23343 7 pcmanfm RET open 16/0x10

    The 4 and 5 file descriptors were:

    23343 1 pcmanfm CALL pipe
    23343 1 pcmanfm RET pipe 4, 5

    (I guess that is the signal_pipe code.)

     
  • Lonely Stranger

    Lonely Stranger - 2012-05-26
    • priority: 5 --> 7
     
  • Jeremy C. Reed

    Jeremy C. Reed - 2012-06-02

    This problem still exists in libfm and pcmanfm from git master today.

     
  • Jeremy C. Reed

    Jeremy C. Reed - 2012-06-02

    http://tx.reedmedia.net:54545/~reed/netbsd-i386-qemu-disk-4GB.bz2 is a qemu image with NetBSD on it. It is a 444MB. bunzip it and then boot with qemu -hda netbsd-i386-qemu-disk-4GB. No root password. Run startx to start X11. Maybe it can help someone identify problem with pcmanfm. The system has ktrace and gdb installed. Lots of other software available; see "pkgin".

     
  • Lonely Stranger

    Lonely Stranger - 2012-06-03
    • milestone: --> 557433
     
  • Lonely Stranger

    Lonely Stranger - 2012-06-03
    • milestone: 557433 --> 2334066
     
  • Lonely Stranger

    Lonely Stranger - 2012-06-03

    I cannot get that image from host tx.reedmedia.net, wget sends a request and gets no answer. Sorry.

     
  • wolfpython

    wolfpython - 2012-06-06

    I can reproduce it. If 2 or 3 times has no effect, we can click more times. The OS is NetBSD 6.0 Beta2.
    below is the step I take to reproduce it:
    1. Open an terminal , here is xterm. and run top
    2. Click the pcmanfm in the task bar. It's fine until now. The cpu load is low.
    3. Click the pcmanfm in the task bar more times quickly, you can find cpu load is higher with every click.
    Then move the cursor to pcmanfm, we can find it's unusable now, frozen, no response anymore

     
  • Lonely Stranger

    Lonely Stranger - 2012-07-06

    I've tried to get your image working. Unfortunately I could not find any clues what is wrong with your setup but from your ktrace log it seems for me as bug of GIO (gnome i/o library) - it continues to poll descriptors that are already closed (fd 9, fd 4, and fd 3) and also fd 5 which is some Glib internal pipe (since the pipe created by pcmanfm got fd 7 and fd 8). So I think it's problem in you system, sorry.
    Also I should say that very big number of problems were fixed in pcmanfm recently so you would try to get latest sources from Git and check all again, it can be your bugs are fixed. Thank you!

     
  • Lonely Stranger

    Lonely Stranger - 2012-07-18
    • labels: --> 2616493
     
  • Lonely Stranger

    Lonely Stranger - 2012-08-09
    • milestone: 2334066 --> 1.0.1
    • status: open --> open-works-for-me
     
  • Lonely Stranger

    Lonely Stranger - 2012-08-13

    I would like you to check 1.0 release if you still experience this behavior. Thank you very much.

     
  • Lonely Stranger

    Lonely Stranger - 2012-08-17

    I've tried Git version in netbsd 5.1.2 and it eats cpu randomly, not only on second window opening.
    I'm afraid the problem is in NetBSD threads implementation which is not fully supported by GLib as gdb doesn't show any thread in the application and problem starts as soon new thread should be created. I don't know if that can be fixed anyhow, sorry.

     
  • Lonely Stranger

    Lonely Stranger - 2012-08-17
    • labels: 2616493 --> 3376468
    • status: open-works-for-me --> closed-works-for-me
     
  • Lonely Stranger

    Lonely Stranger - 2012-08-18
    • labels: 3376468 --> pcmanfm
    • status: closed-works-for-me --> closed-fixed
     
  • Lonely Stranger

    Lonely Stranger - 2012-08-18

    We hope this issue is completely fixed in the Git repository recently.
    Check it out when it's possible for you and if the bug still exists then reopen the report, please.
    Thank you very much.

     

Anonymous
Anonymous

Add attachments
Cancel