460933 - Firefox hangs after downloading PDF it should open in Document Viewer (evince)

Status: VERIFIED FIXED

(Core :: Memory Allocator, defect)

Description

[Myk Melez [:myk] [@mykmelez]]

I have configured Firefox trunk nightly builds to open PDFs using the default application (Document Viewer, i.e. evince) on my Linux system.  Generally this works, but occasionally Firefox will hang at the point at which the statusbar claims there are only a few seconds remaining for the download.

During the hang, ps shows an extra firefox-bin process owned by the init process:

0 S myk        448 19413  0  80   0 -   945 -      13:32 pts/0    00:00:00 /bin/sh /home/myk/Applications/firefox/firefox
0 S myk        451   448  0  80   0 -   960 -      13:32 pts/0    00:00:00 /bin/sh /home/myk/Applications/firefox/run-mozilla.sh /home/myk/Applications/firefox/firefox-bin
0 S myk        457   451  7  80   0 - 68415 -      13:32 pts/0    00:00:24 /home/myk/Applications/firefox/firefox-bin
1 S myk        592     1  0  80   0 - 68415 -      13:37 pts/0    00:00:00 /home/myk/Applications/firefox/firefox-bin

stracing both firefox-bin processes shows the original is stuck on a read call while the other is stuck on futex:

myk@myk:~$ strace -p 457
Process 457 attached - interrupt to quit
read(55, 

myk@myk:~$ strace -p 592
Process 592 attached - interrupt to quit
futex(0xb613f040, 0x80 /* FUTEX_??? */, 2

I'm not lsof savvy, but I've captured its output during one of these hangs and can grep it for useful info if needed.

When I subsequently force kill the Firefox process and then restart it, it displays a dialog complaining that it couldn't save the PDF file.  If I then redownload it, it invariably downloads and then opens in evince without incident (as do subsequent PDF downloads until the problem recurs).

Comment 1

[Reed Loden [:reed]]

I can definitely confirm this... drives me insane, and it's the number one reason that Minefield hangs for me.

Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9.1b2pre) Gecko/20081020 Minefield/3.1b2pre

Let me know if I can.

Comment 2

[Reed Loden [:reed]]

(In reply to comment #1)
> Let me know if I can.

... if I can help.

Comment 3

[Mike Hommey [:glandium]]

It would be interesting to have the output for "strace -f -eexecve firefox", to begin with.

Comment 4

[Myk Melez [:myk] [@mykmelez]]

(In reply to comment #3)
> It would be interesting to have the output for "strace -f -eexecve firefox", to
> begin with.

Ok, I'll run it that way from now on and attach the output once I see a hang.

Also, I thought there was a way to trigger the crash reporter when killing a hung process, although I can't find that info now.

Comment 5

[Mike Hommey [:glandium]]

You could attach gdb to the hung process, too.

Comment 6

[Myk Melez [:myk] [@mykmelez]]

Attachment: output of |strace -f -eexecve firefox|

I made Firefox hang by downloading the same PDF <http://www.irs.gov/pub/irs-pdf/fw4.pdf> several times.  Here's the output of |strace -f -eexecve firefox| with these Firefox processes running:

myk@myk:~$ ps -leaf | grep firefox
0 S myk      11770  7262  2  80   0 -   477 -      11:41 pts/0    00:06:55 strace -f -eexecve -o/home/myk/strace-firefox.txt firefox
0 T myk      11771 11770  0  80   0 -   945 -      11:41 pts/0    00:00:00 /bin/sh /home/myk/bin/firefox
0 T myk      11783 11771  0  80   0 -   960 -      11:41 pts/0    00:00:00 /bin/sh /home/myk/Applications/firefox/run-mozilla.sh /home/myk/Applications/firefox/firefox-bin
0 S myk      11789 11783  3  80   0 - 112809 -     11:41 pts/0    00:12:53 /home/myk/Applications/firefox/firefox-bin
1 S myk      17162     1  0  80   0 - 112809 -     17:25 pts/0    00:00:00 /home/myk/Applications/firefox/firefox-bin

Comment 7

[Myk Melez [:myk] [@mykmelez]]

(In reply to comment #5)
> You could attach gdb to the hung process, too.

Good idea, I'll compile my out-of-date debug build and see if I can reproduce this problem with it.

Comment 8

[Myk Melez [:myk] [@mykmelez]]

Note: the alert dialog I get once I restart Firefox (after force quitting it) is titled "Download Error" and contains the following message:

  /tmp/fw4.pdf could not be saved, because you cannot change the contents of that folder.

  Change the folder properties and try again, or try saving in a different location.

Comment 9

[Mike Hommey [:glandium]]

Do the various files /tmp/fw4*.pdf exist ? Does evince actually show up, and what happens when you quit it ?

Comment 10

[Reed Loden [:reed]]

Minefield hung while trying to open a .zip file just now... I only have a nightly build (no debugging symbols), but maybe this will help:

#0  0xb7f0c410 in __kernel_vsyscall ()
#1  0xb7ee799b in read () from /lib/tls/i686/cmov/libpthread.so.0
#2  0xb6b4f35d in ?? () from /usr/lib/libglib-2.0.so.0
#3  0xb6b4f7af in ?? () from /usr/lib/libglib-2.0.so.0
#4  0xb6b4fdd6 in g_spawn_async_with_pipes () from /usr/lib/libglib-2.0.so.0
#5  0xb6b4fe7a in g_spawn_async () from /usr/lib/libglib-2.0.so.0
#6  0xb59ecfc2 in gnome_vfs_mime_application_launch_with_env ()
   from /usr/lib/libgnomevfs-2.so.0
#7  0xb59fb05a in gnome_vfs_url_show_with_env () from /usr/lib/libgnomevfs-2.so.0
#8  0xb5bc9204 in gnome_url_show_with_env () from /usr/lib/libgnome-2.so.0
#9  0xb5bc955c in gnome_url_show () from /usr/lib/libgnome-2.so.0
#10 0xb611ef84 in ?? () from /home/reed/firefox/components/libmozgnome.so
#11 0xb7b5cb25 in ?? () from /home/reed/firefox/libxul.so

Comment 11

[Myk Melez [:myk] [@mykmelez]]

(In reply to comment #9)
> Do the various files /tmp/fw4*.pdf exist ? Does evince actually show up, and
> what happens when you quit it ?

The files /tmp/fw4*.pdf do all exist, including /tmp/fw4.pdf, which presumably got created the first time I loaded the PDF file.  And evince does start and open the file each time I load it, except for the last time when Firefox hangs.

Comment 12

[Mike Hommey [:glandium]]

Reading Reed's stacktrace and your original report, could you try to find out what file descriptor is being read from? For that, you can try to attach strace to the hung process again, which will display "read(n," where n is the file descriptor number. You can then look at what file it is with "ls -l /proc/$pid/fd/$n" $pid being the pid of the hung process and $n the number in the strace output.

Comment 13

[Myk Melez [:myk] [@mykmelez]]

Here's the output of the command described in comment 12 for a hung process:

myk@myk:~$ ls -l /proc/15621/fd/62 
lr-x------ 1 myk myk 64 2008-10-22 16:32 /proc/15621/fd/62 -> pipe:[233543]

Comment 14

[Mike Hommey [:glandium]]

It would be interesting to find out the other end of this pipe. You can try with find /proc -lname pipe:[233543] while the process is hung (obviously, you'll need to replace 233543 with the new number you'll get when trying again).

Comment 15

[Mike Hommey [:glandium]]

(In reply to comment #14)
> It would be interesting to find out the other end of this pipe.

and what process has this other end opened.

Comment 16

[Myk Melez [:myk] [@mykmelez]]

That command didn't find anything...

myk@myk:~$ strace -p 22753
Process 22753 attached - interrupt to quit
read(54,  <unfinished ...>
Process 22753 detached
myk@myk:~$ ls -l /proc/22753/fd/54
lr-x------ 1 myk myk 64 2008-10-22 22:54 /proc/22753/fd/54 -> pipe:[266318]
myk@myk:~$ find /proc -lname pipe:[266318]
  [no results]

Comment 17

[Myk Melez [:myk] [@mykmelez]]

Note: I've tried several times to reproduce this in my debug build, and I haven't been able to.  But I can reproduce it easily in the latest Firefox nightly.

Comment 18

[Myk Melez [:myk] [@mykmelez]]

It looks like that strange extra firefox-bin process links to the same pipe:

myk@myk:~$ ps -leaf | grep firefox-bin
0 S myk      28488 28476  0  80   0 -   957 -      15:35 ?        00:00:00 /bin/sh /home/myk/Applications/firefox/run-mozilla.sh /home/myk/Applications/firefox/firefox-bin
0 S myk      28494 28488  4  80   0 - 79729 -      15:35 ?        00:00:54 /home/myk/Applications/firefox-3.1-nightly/firefox-bin
1 S myk      28773     1  0  80   0 - 79729 -      15:48 ?        00:00:00 /home/myk/Applications/firefox-3.1-nightly/firefox-bin
myk@myk:~$ strace -p 28494
Process 28494 attached - interrupt to quit
read(48,  <unfinished ...>
Process 28494 detached
myk@myk:~$ ls -l /proc/28494/fd/48
lr-x------ 1 myk myk 64 2008-10-23 15:50 /proc/28494/fd/48 -> pipe:[334679]
myk@myk:~$ sudo find /proc -lname '*334679*' -exec ls -l {} \;
lr-x------ 1 myk myk 64 2008-10-23 15:50 /proc/28494/task/28494/fd/48 -> pipe:[334679]
lr-x------ 1 myk myk 64 2008-10-23 15:50 /proc/28494/task/28501/fd/48 -> pipe:[334679]
lr-x------ 1 myk myk 64 2008-10-23 15:50 /proc/28494/task/28502/fd/48 -> pipe:[334679]
lr-x------ 1 myk myk 64 2008-10-23 15:50 /proc/28494/task/28506/fd/48 -> pipe:[334679]
lr-x------ 1 myk myk 64 2008-10-23 15:50 /proc/28494/task/28507/fd/48 -> pipe:[334679]
lr-x------ 1 myk myk 64 2008-10-23 15:50 /proc/28494/task/28524/fd/48 -> pipe:[334679]
lr-x------ 1 myk myk 64 2008-10-23 15:50 /proc/28494/task/28767/fd/48 -> pipe:[334679]
lr-x------ 1 myk myk 64 2008-10-23 15:50 /proc/28494/fd/48 -> pipe:[334679]
l-wx------ 1 myk myk 64 2008-10-23 15:50 /proc/28773/task/28773/fd/49 -> pipe:[334679]
l-wx------ 1 myk myk 64 2008-10-23 15:50 /proc/28773/fd/49 -> pipe:[334679]

Comment 19

[Mike Hommey [:glandium]]

That is getting interesting...

So it looks like firefox is creating a pipe to communicate with the forked process it creates to exec() the external handler, but while the forked process read()s, the other one doesn't write to the pipe.

Now, coming back to comment #4, I see g_spawn_async_with_pipes is called, which, from its name, might be the one just doing that.

Overall this might just be a glib or gnomevfs issue.

Can you try upgrading or downgrading one or both ?

Comment 20

[Mike Hommey [:glandium]]

and at first glance to glib source, I don't see why it would read. Can you try to get another stacktrace with glib's debug symbols present?

Comment 21

[Myk Melez [:myk] [@mykmelez]]

(In reply to comment #19)
> Overall this might just be a glib or gnomevfs issue.
> 
> Can you try upgrading or downgrading one or both ?

I'll try, although I'm not sure how to do this within the restrictions of Ubuntu's package management system, given how many other packages depend on those two (at least glib).  Perhaps I can build and install older versions manually.


(In reply to comment #20)
> and at first glance to glib source, I don't see why it would read. Can you try
> to get another stacktrace with glib's debug symbols present?

Yup, here's such a stacktrace:

#0  0xb7ee6410 in __kernel_vsyscall ()
#1  0xb7ec699b in read () from /lib/tls/i686/cmov/libpthread.so.0
#2  0xb6b2e25d in read_ints (fd=48, buf=0xbfed7784, n_ints_in_buf=<value optimized out>, n_ints_read=0xbfed77b4, error=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:1106
#3  0xb6b2e6af in fork_exec_with_pipes (intermediate_child=1, working_directory=0x0, argv=0xa5012c50, envp=0x0, close_descriptors=1, search_path=1, stdout_to_null=0, stderr_to_null=0, child_inherits_stdin=0, file_and_argv_zero=0, 
    child_setup=0, user_data=0x0, child_pid=0x0, standard_input=0x0, standard_output=0x0, standard_error=0x0, error=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:1309
#4  0xb6b2ecd6 in IA__g_spawn_async_with_pipes (working_directory=0x0, argv=0xa5012c50, envp=0x0, flags=<value optimized out>, child_setup=0, user_data=0x0, child_pid=0x0, standard_input=0x0, standard_output=0x0, standard_error=0x0, 
    error=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:613
#5  0xb6b2ed7a in IA__g_spawn_async (working_directory=0x0, argv=0xa5012c50, envp=0x0, flags=G_SPAWN_SEARCH_PATH, child_setup=0, user_data=0x0, child_pid=0x0, error=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:114
#6  0xb59dcfc2 in gnome_vfs_mime_application_launch_with_env () from /usr/lib/libgnomevfs-2.so.0
#7  0xb59dd2cc in gnome_vfs_mime_application_launch () from /usr/lib/libgnomevfs-2.so.0
#8  0xb5636abb in ?? () from /home/myk/Applications/firefox-3.1-nightly/components/libmozgnome.so
#9  0xb791303c in ?? () from /home/myk/Applications/firefox/libxul.so
#10 0xb790dfbc in ?? () from /home/myk/Applications/firefox/libxul.so
#11 0xb79094ee in ?? () from /home/myk/Applications/firefox/libxul.so
#12 0xb7909c4b in ?? () from /home/myk/Applications/firefox/libxul.so
#13 0xb7909d61 in ?? () from /home/myk/Applications/firefox/libxul.so
#14 0xb7903976 in ?? () from /home/myk/Applications/firefox/libxul.so
#15 0xb73f57b7 in ?? () from /home/myk/Applications/firefox/libxul.so
#16 0xb738e97d in ?? () from /home/myk/Applications/firefox/libxul.so
#17 0xb738ec63 in ?? () from /home/myk/Applications/firefox/libxul.so
#18 0xb7b32402 in ?? () from /home/myk/Applications/firefox/libxul.so
#19 0xb7b46518 in ?? () from /home/myk/Applications/firefox/libxul.so
#20 0xb7b168f3 in ?? () from /home/myk/Applications/firefox/libxul.so
#21 0xb7a82786 in ?? () from /home/myk/Applications/firefox/libxul.so
#22 0xb79596fe in ?? () from /home/myk/Applications/firefox/libxul.so
#23 0xb732483b in XRE_main () from /home/myk/Applications/firefox/libxul.so
#24 0x0804945a in ?? ()
#25 0xb66ba450 in __libc_start_main () from /lib/tls/i686/cmov/libc.so.6
#26 0x080492c1 in ?? ()

Comment 22

[Myk Melez [:myk] [@mykmelez]]

And here's the stacktrace for the forked process:

#0  0xb7ee6410 in __kernel_vsyscall ()
#1  0xb7ec6589 in __lll_lock_wait () from /lib/tls/i686/cmov/libpthread.so.0
#2  0xb7ec1be5 in _L_lock_923 () from /lib/tls/i686/cmov/libpthread.so.0
#3  0xb7ec1a66 in pthread_mutex_lock () from /lib/tls/i686/cmov/libpthread.so.0
#4  0x08050bf1 in malloc ()
#5  0xb673551a in ?? () from /lib/tls/i686/cmov/libc.so.6
#6  0xb6735653 in opendir () from /lib/tls/i686/cmov/libc.so.6
#7  0xb6b2dc1d in do_exec (child_err_report_fd=49, stdin_fd=-1, stdout_fd=-1, stderr_fd=-1, working_directory=0x0, argv=0xa5012c50, envp=0x0, close_descriptors=1, search_path=1, stdout_to_null=0, stderr_to_null=0, 
    child_inherits_stdin=0, file_and_argv_zero=0, child_setup=0, user_data=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:906
#8  0xb6b2e5fb in fork_exec_with_pipes (intermediate_child=<value optimized out>, working_directory=0x0, argv=0xa5012c50, envp=0x0, close_descriptors=1, search_path=1, stdout_to_null=0, stderr_to_null=0, child_inherits_stdin=0, 
    file_and_argv_zero=0, child_setup=0, user_data=0x0, child_pid=0x0, standard_input=0x0, standard_output=0x0, standard_error=0x0, error=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:1261
#9  0xb6b2ecd6 in IA__g_spawn_async_with_pipes (working_directory=0x0, argv=0xa5012c50, envp=0x0, flags=<value optimized out>, child_setup=0, user_data=0x0, child_pid=0x0, standard_input=0x0, standard_output=0x0, standard_error=0x0, 
    error=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:613
#10 0xb6b2ed7a in IA__g_spawn_async (working_directory=0x0, argv=0xa5012c50, envp=0x0, flags=G_SPAWN_SEARCH_PATH, child_setup=0, user_data=0x0, child_pid=0x0, error=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:114
#11 0xb59dcfc2 in gnome_vfs_mime_application_launch_with_env () from /usr/lib/libgnomevfs-2.so.0
#12 0xb59dd2cc in gnome_vfs_mime_application_launch () from /usr/lib/libgnomevfs-2.so.0
#13 0xb5636abb in ?? () from /home/myk/Applications/firefox-3.1-nightly/components/libmozgnome.so
#14 0xb791303c in ?? () from /home/myk/Applications/firefox/libxul.so
#15 0xb790dfbc in ?? () from /home/myk/Applications/firefox/libxul.so
#16 0xb79094ee in ?? () from /home/myk/Applications/firefox/libxul.so
#17 0xb7909c4b in ?? () from /home/myk/Applications/firefox/libxul.so
#18 0xb7909d61 in ?? () from /home/myk/Applications/firefox/libxul.so
#19 0xb7903976 in ?? () from /home/myk/Applications/firefox/libxul.so
#20 0xb73f57b7 in ?? () from /home/myk/Applications/firefox/libxul.so
#21 0xb738e97d in ?? () from /home/myk/Applications/firefox/libxul.so
#22 0xb738ec63 in ?? () from /home/myk/Applications/firefox/libxul.so
#23 0xb7b32402 in ?? () from /home/myk/Applications/firefox/libxul.so
#24 0xb7b46518 in ?? () from /home/myk/Applications/firefox/libxul.so
#25 0xb7b168f3 in ?? () from /home/myk/Applications/firefox/libxul.so
#26 0xb7a82786 in ?? () from /home/myk/Applications/firefox/libxul.so
#27 0xb79596fe in ?? () from /home/myk/Applications/firefox/libxul.so
#28 0xb732483b in XRE_main () from /home/myk/Applications/firefox/libxul.so
#29 0x0804945a in ?? ()
#30 0xb66ba450 in __libc_start_main () from /lib/tls/i686/cmov/libc.so.6
#31 0x080492c1 in ?? ()

Comment 23

[Mike Hommey [:glandium]]

Could you also send the stacktrace for the other non hanging firefox-bin process ?

Comment 24

[Myk Melez [:myk] [@mykmelez]]

(In reply to comment #23)
> Could you also send the stacktrace for the other non hanging firefox-bin
> process ?

Erm, the stacktrace in comment 22 is for other firefox-bin process, which also seems hung (in its case on a call to futex).  Those are the only two firefox-bin processes running.

Comment 25

[Myk Melez [:myk] [@mykmelez]]

I tried a few tests, and I can't reproduce with the version of Firefox that ships with my distribution (3.0.3), nor can I reproduce with a fresh profile on a nightly build, but I can reproduce with my regular profile in safe mode (i.e. all extensions disabled, etc.) on a nightly build.

Comment 26

[Mike Hommey [:glandium]]

Stuck in malloc(), it looks like a regression candidate for libjemalloc... Can you try to run your nightly build with "LD_PRELOAD=/lib/libc.so.6 firefox" ? It will use libc symbols instead of jemalloc ones. Or to be even more sure, you can try to build without libjemalloc.

Comment 27

[Myk Melez [:myk] [@mykmelez]]

(In reply to comment #26)
> Stuck in malloc(), it looks like a regression candidate for libjemalloc... Can
> you try to run your nightly build with "LD_PRELOAD=/lib/libc.so.6 firefox" ?

I just tried that, but I was still able to reproduce the hang:

myk@myk:~$ LD_PRELOAD=/lib/libc.so.6 firefox
...


myk@myk:~$ ps -leaf | grep firefox
0 S myk      12026  7262  0  80   0 -   923 -      00:56 pts/0    00:00:00 /bin/sh /home/myk/bin/firefox
0 S myk      12038 12026  0  80   0 -   938 -      00:56 pts/0    00:00:00 /bin/sh /home/myk/Applications/firefox/run-mozilla.sh /home/myk/Applications/firefox/firefox-bin
0 S myk      12044 12038 14  80   0 - 79488 -      00:56 pts/0    00:00:30 /home/myk/Applications/firefox/firefox-bin
1 S myk      12147     1  0  80   0 - 81537 -      00:58 pts/0    00:00:00 /home/myk/Applications/firefox/firefox-bin
0 R myk      12180 11839  0  80   0 -   751 -      00:59 pts/14   00:00:00 grep firefox


myk@myk:~$ gdb prog 12044
...
(gdb) bt
#0  0xb7efca71 in read () from /lib/libc.so.6
#1  0xb6a8e25d in read_ints (fd=52, buf=0xbfbd98f4, n_ints_in_buf=<value optimized out>, n_ints_read=0xbfbd9924, error=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:1106
#2  0xb6a8e6af in fork_exec_with_pipes (intermediate_child=1, working_directory=0x0, argv=0xa78b0480, envp=0x0, close_descriptors=1, search_path=1, stdout_to_null=0, 
    stderr_to_null=0, child_inherits_stdin=0, file_and_argv_zero=0, child_setup=0, user_data=0x0, child_pid=0x0, standard_input=0x0, standard_output=0x0, standard_error=0x0, 
    error=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:1309
#3  0xb6a8ecd6 in IA__g_spawn_async_with_pipes (working_directory=0x0, argv=0xa78b0480, envp=0x0, flags=<value optimized out>, child_setup=0, user_data=0x0, child_pid=0x0, 
    standard_input=0x0, standard_output=0x0, standard_error=0x0, error=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:613
#4  0xb6a8ed7a in IA__g_spawn_async (working_directory=0x0, argv=0xa78b0480, envp=0x0, flags=G_SPAWN_SEARCH_PATH, child_setup=0, user_data=0x0, child_pid=0x0, error=0x0)
    at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:114
#5  0xb5a79fc2 in gnome_vfs_mime_application_launch_with_env () from /usr/lib/libgnomevfs-2.so.0
#6  0xb5a7a2cc in gnome_vfs_mime_application_launch () from /usr/lib/libgnomevfs-2.so.0
#7  0xb2ff8abb in ?? () from /home/myk/Applications/firefox-3.1-nightly/components/libmozgnome.so
#8  0xb7873594 in ?? () from /home/myk/Applications/firefox/libxul.so
#9  0xb786e514 in ?? () from /home/myk/Applications/firefox/libxul.so
#10 0xb7869a46 in ?? () from /home/myk/Applications/firefox/libxul.so
#11 0xb786a1a3 in ?? () from /home/myk/Applications/firefox/libxul.so
#12 0xb786a2b9 in ?? () from /home/myk/Applications/firefox/libxul.so
#13 0xb7863ece in ?? () from /home/myk/Applications/firefox/libxul.so
#14 0xb7355a03 in ?? () from /home/myk/Applications/firefox/libxul.so
#15 0xb72ee97d in ?? () from /home/myk/Applications/firefox/libxul.so
#16 0xb72eec63 in ?? () from /home/myk/Applications/firefox/libxul.so
#17 0xb7a9295a in ?? () from /home/myk/Applications/firefox/libxul.so
#18 0xb7aa6a70 in ?? () from /home/myk/Applications/firefox/libxul.so
#19 0xb7a76e4b in ?? () from /home/myk/Applications/firefox/libxul.so
#20 0xb79e2cde in ?? () from /home/myk/Applications/firefox/libxul.so
#21 0xb78b9c56 in ?? () from /home/myk/Applications/firefox/libxul.so
#22 0xb728483b in XRE_main () from /home/myk/Applications/firefox/libxul.so
#23 0x0804945a in ?? ()
#24 0xb7e5c450 in __libc_start_main () from /lib/libc.so.6
#25 0x080492c1 in ?? ()


myk@myk:~$ gdb prog 12147
...
(gdb) bt
0xb7e23be5 in _L_lock_923 () from /lib/tls/i686/cmov/libpthread.so.0
#3  0xb7e23a66 in pthread_mutex_lock () from /lib/tls/i686/cmov/libpthread.so.0
#4  0xb7f17646 in pthread_mutex_lock () from /lib/libc.so.6
#5  0x08050bf1 in malloc ()
#6  0xb7ed255a in ?? () from /lib/libc.so.6
#7  0xb7ed26a3 in opendir () from /lib/libc.so.6
#8  0xb6a8dc1d in do_exec (child_err_report_fd=53, stdin_fd=-1, stdout_fd=-1, stderr_fd=-1, working_directory=0x0, argv=0xa78b0480, envp=0x0, close_descriptors=1, 
    search_path=1, stdout_to_null=0, stderr_to_null=0, child_inherits_stdin=0, file_and_argv_zero=0, child_setup=0, user_data=0x0)
    at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:906
#9  0xb6a8e5fb in fork_exec_with_pipes (intermediate_child=<value optimized out>, working_directory=0x0, argv=0xa78b0480, envp=0x0, close_descriptors=1, search_path=1, 
    stdout_to_null=0, stderr_to_null=0, child_inherits_stdin=0, file_and_argv_zero=0, child_setup=0, user_data=0x0, child_pid=0x0, standard_input=0x0, standard_output=0x0, 
    standard_error=0x0, error=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:1261
#10 0xb6a8ecd6 in IA__g_spawn_async_with_pipes (working_directory=0x0, argv=0xa78b0480, envp=0x0, flags=<value optimized out>, child_setup=0, user_data=0x0, child_pid=0x0, 
    standard_input=0x0, standard_output=0x0, standard_error=0x0, error=0x0) at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:613
#11 0xb6a8ed7a in IA__g_spawn_async (working_directory=0x0, argv=0xa78b0480, envp=0x0, flags=G_SPAWN_SEARCH_PATH, child_setup=0, user_data=0x0, child_pid=0x0, error=0x0)
    at /build/buildd/glib2.0-2.16.6/glib/gspawn.c:114
#12 0xb5a79fc2 in gnome_vfs_mime_application_launch_with_env () from /usr/lib/libgnomevfs-2.so.0
#13 0xb5a7a2cc in gnome_vfs_mime_application_launch () from /usr/lib/libgnomevfs-2.so.0
#14 0xb2ff8abb in ?? () from /home/myk/Applications/firefox-3.1-nightly/components/libmozgnome.so
#15 0xb7873594 in ?? () from /home/myk/Applications/firefox/libxul.so
#16 0xb786e514 in ?? () from /home/myk/Applications/firefox/libxul.so
#17 0xb7869a46 in ?? () from /home/myk/Applications/firefox/libxul.so
#18 0xb786a1a3 in ?? () from /home/myk/Applications/firefox/libxul.so
#19 0xb786a2b9 in ?? () from /home/myk/Applications/firefox/libxul.so
#20 0xb7863ece in ?? () from /home/myk/Applications/firefox/libxul.so
#21 0xb7355a03 in ?? () from /home/myk/Applications/firefox/libxul.so
#22 0xb72ee97d in ?? () from /home/myk/Applications/firefox/libxul.so
#23 0xb72eec63 in ?? () from /home/myk/Applications/firefox/libxul.so
#24 0xb7a9295a in ?? () from /home/myk/Applications/firefox/libxul.so
#25 0xb7aa6a70 in ?? () from /home/myk/Applications/firefox/libxul.so
#26 0xb7a76e4b in ?? () from /home/myk/Applications/firefox/libxul.so
#27 0xb79e2cde in ?? () from /home/myk/Applications/firefox/libxul.so
#28 0xb78b9c56 in ?? () from /home/myk/Applications/firefox/libxul.so
#29 0xb728483b in XRE_main () from /home/myk/Applications/firefox/libxul.so
#30 0x0804945a in ?? ()
#31 0xb7e5c450 in __libc_start_main () from /lib/libc.so.6
#32 0x080492c1 in ?? ()


> It will use libc symbols instead of jemalloc ones. Or to be even more sure,
> you can try to build without libjemalloc.

I'll try that and report back.

Comment 28

[Mike Hommey [:glandium]]

> #5  0x08050bf1 in malloc ()

It looks like the LD_PRELOAD trick didn't work...

Comment 29

[Reed Loden [:reed]]

Jason / Stuart: Any help here?

Comment 30

[Jason Evans]

Attachment: Call pthread_atfork() to prevent potential deadlock after forking [Checkin: Comment 36]

The bug could be due to an internal malloc lock being held across the fork that creates the child process.  This patch adds a call to pthread_atfork(3).  I had this in my own development versions of Mozilla many months ago; I don't remember why it never got committed.

Comment 31

[Myk Melez [:myk] [@mykmelez]]

(In reply to comment #27)
> (In reply to comment #26)
> > It will use libc symbols instead of jemalloc ones. Or to be even more sure,
> > you can try to build without libjemalloc.
> 
> I'll try that and report back.

I couldn't reproduce on a build without libjemalloc.


(In reply to comment #30)
> Created an attachment (id=345107) [details]
> Call pthread_atfork() to prevent potential deadlock after forking.

I'll try building with jemalloc and this patch.

Comment 32

[Myk Melez [:myk] [@mykmelez]]

(In reply to comment #31)
> (In reply to comment #30)
> > Created an attachment (id=345107) [details] [details]
> > Call pthread_atfork() to prevent potential deadlock after forking.
> 
> I'll try building with jemalloc and this patch.

With the patch, I can't reproduce the hang, so the patch seems to fix the problem.

Comment 33

[Mike Hommey [:glandium]]

(In reply to comment #30)
> Created an attachment (id=345107) [details]
> Call pthread_atfork() to prevent potential deadlock after forking.
> 
> The bug could be due to an internal malloc lock being held across the fork that
> creates the child process.  This patch adds a call to pthread_atfork(3).  I had
> this in my own development versions of Mozilla many months ago; I don't
> remember why it never got committed.

Should this be applied on 1.9.0 too ?

Comment 34

[Mike Hommey [:glandium]]

Reed, doesn't this apply to trunk, too?

Comment 35

[Reed Loden [:reed]]

(In reply to comment #34)
> Reed, doesn't this apply to trunk, too?

It does. I just usually set the version field to the lowest Firefox version that the bug affects... Jason has commit access, so I'll let him commit the patch. If he'd rather somebody else do it, he can add the checkin-needed keyword.

Comment 36

[Reed Loden [:reed]]

Went ahead and landed it.

http://hg.mozilla.org/mozilla-central/rev/fbadbd5149d5

Comment 37

[Daniel Veditz [:dveditz]]

if this is jemalloc-related do we need this on the 1.9.0 branch? I thought jemalloc wasn't used in FF3 for linux builds.

Comment 38

[Reed Loden [:reed]]

(In reply to comment #37)
> if this is jemalloc-related do we need this on the 1.9.0 branch? I thought
> jemalloc wasn't used in FF3 for linux builds.

You're thinking of PGO... jemalloc is definitely used on Firefox 3.

Comment 39

[Daniel Veditz [:dveditz]]

No, I was thinking of jemalloc, but it's _mac_ that doesn't have it in 3.0.

Comment 40

[Daniel Veditz [:dveditz]]

Comment on attachment 345107 [details] [diff] [review]
Call pthread_atfork() to prevent potential deadlock after forking
[Checkin: Comment 36]

Approved for 1.9.0.5, a=dveditz for release-drivers

Comment 41

[Daniel Veditz [:dveditz]]

Checked into the 1.9.0 branch

Comment 42

[Al Billings [:abillings - ex-MoCo]]

Reed, can you verify that this is fixed for you with the 1.9.0.5 Linux candidate build?

Comment 43

[Reed Loden [:reed]]

I'm currently very busy with school stuff. Maybe Myk can help verify?

Comment 44

[Myk Melez [:myk] [@mykmelez]]

I have tested and cannot reproduce on the 1.9.0.5 candidate build nor on my trunk nightly.

Comment 45

[Al Billings [:abillings - ex-MoCo]]

Thanks, Myk.

Comment 46

[Benjamin Smedberg]

Fixed before 1.9.1 branched