278009 - Abusive over-use of stat64(), open(), and read() syscalls when opening download manager.

Status: RESOLVED WORKSFORME

(Toolkit :: Downloads API, defect)

Description

[Valdis Kletnieks]

When opening the download manager 'save' dialog, Firefox goes nuts and tries to
stat64() everything in sight - multiple times.  My $HOME directory has 931 files
in it, so I use $HOME/Downloads as the target.  However, *before* putting up the
selector for directory (that has HOME, Filesystem, and then 2 entries for my
Downloads and another directory I've saved to), it stats every file in $HOME.
Multiple Times.

I ran an strace of firefox, and here's some sample numbers:

% grep stat64 /tmp/firefox.trace | sort | uniq -c | sort -nr | head
     27 fstat64(32, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
     17 stat64("/home/valdis", {st_mode=S_IFDIR|0700, st_size=22528, ...}) = 0
     14 stat64("/home/valdis/Downloads", {st_mode=S_IFDIR|0755, st_size=5120,
...}) = 0
     13 stat64("/usr/share//mime/magic", {st_mode=S_IFREG|0644, st_size=9767,
...}) = 0
     13 stat64("/usr/share//mime/globs", {st_mode=S_IFREG|0644, st_size=10546,
...}) = 0
     10 stat64("/home/valdis/za", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
     10 stat64("/home/valdis/z9", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
     10 stat64("/home/valdis/yellow.oldfiles", {st_mode=S_IFREG|0644,
st_size=780, ...}) = 0
     10 stat64("/home/valdis/yahoo.snort", {st_mode=S_IFREG|0644, st_size=2927,
...}) = 0
     10 stat64("/home/valdis/xprobe2-0.1.tar.gz", {st_mode=S_IFREG|0644,
st_size=419411, ...}) = 0

<long list of files elided>

      4 stat64("/home/valdis/Downloads/gnupatch@41925edcVccsXZXObG444GFvEJ94GQ",
 {st_mode=S_IFREG|0644, st_size=2535, ...}) = 0
      4 stat64("/home/valdis/Downloads/gwc-0.20-07.tgz", {st_mode=S_IFREG|0644, 
st_size=549666, ...}) = 0
      4 stat64("/home/valdis/Downloads/hrtimers-2.6.9-04.11.03.patch", {st_mode=
S_IFREG|0644, st_size=159430, ...}) = 0
      4 stat64("/home/valdis/Downloads/hrtimers-sh-2.6.9-04.11.03.patch", {st_mo
de=S_IFREG|0644, st_size=12046, ...}) = 0
      4 stat64("/home/valdis/Downloads/hrtimers-support-2.1.patch", {st_mode=S_I
FREG|0644, st_size=322538, ...}) = 0
      4 stat64("/home/valdis/Downloads/intel-ia32microcode-12Oct2004.txt.bz2", {
st_mode=S_IFREG|0644, st_size=172606, ...}) = 0

A grand total of 10,461 stat64() calls, taking up to a minute or so to complete.
The strace was started just before clicking 'Save to disk', and ended when the
dialog prompting for target directory was displayed - so this covers *only* the
system calls for displaying the list of directories *once*.  The next time you
save a file to disk, you get hit with this *again*.

The most abusive part is that it's stat64()'ed every file in $HOME between 7 and
10 times, and that's before I've even *selected* that directory as a target.  It
also stat64()'ed every file in $Home/Downloads (the eventual target) 4 times.

In addition, it insists on opening and reading many files:

stat64("/home/valdis/linux-2.6.3-openpax-0.11.patch", {st_mode=S_IFREG|0644, st_
size=62295, ...}) = 0
open("/home/valdis/linux-2.6.3-openpax-0.11.patch", O_RDONLY|O_LARGEFILE) = 32
fstat64(32, {st_mode=S_IFREG|0644, st_size=62295, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7
9f2000
read(32, "diff -urN linux-2.6.3/Makefile l"..., 4096) = 4096
close(32)                               = 0
munmap(0xb79f2000, 4096)                = 0
gettimeofday({1104774647, 517325}, NULL) = 0
gettimeofday({1104774647, 517424}, NULL) = 0

It opens and reads the first 4K of that file *THREE TIMES*.

What it *should* be doing:

1) stat each purported target directory to ensure it's a directory.  On my
laptop, that would be *at most* 11 stat() calls for filesystems, one for $HOME,
one for $HOME/Downloads, and one for /usr/src/valdis (as I've used that as a
target in the past). We're done with this part in 15 stat() calls rather than
10,000+, and no need to open() any files (directory or regular).

2) Put up the dialog box offering choices of directories.

3) *AFTER* a target has been chosen, do the readdir()/stat() loop *once* to
build a list of files *in that directory*.  If I select $HOME/Downloads, that's
only 79 more stat() calls it has to make.

I suspect the problem may be the "Browse for other folders" selector - it's
building a list for itself *before* it's activated to actually do anything.  And
even if it *is* opened, it should only have to stat() each file once.

Also, all the stat() activity totally thrashes the active inode cache, and all
the read() activity impacts the buffer cache, making performance of everything
else on the system piggy as well.

The oddest part?  The *default* directory it selects (/usr/src/valdis - and I
have to change it back to $HOME/Downloads *every time*) is *NOT* walked through
with a readdir() loop. The code does an open("/home/valdis") 7 times, but never
does an open("/usr/src/valdis").

Comment 1

[Stephanie Daugherty [:sdaugherty]]

What operating system/distribution/CPU architecture is this on, and what version of Firefox are you experiencing this with?

Also, does it still happen with a recent trunk build?

Comment 2

[Valdis Kletnieks]

Oh man, this bug is *old*.  It was against a Fedora Core <mumble> Rawhide as of 2 years ago, on a 32-bit Pentium4 laptop, and whatever was in the trunk then.

I'm closing it as 'FIXED', as I've not actually seen this in quite some time - a quick test indicates only about 300 stat64() calls, most of which seem to be totally unrelated to the reported problem. So it's definitely not showing up on this week's 3.0a2pre builds.  It *may* be another manifestation of this bug report against GTK1: https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=178872
though it may be some other related issue resolved when the trunk moved to Gtk2.

Comment 3

[Kevin Brosnan]

Only bugs that can be tracked to known patches are marked as fixed. Worksforme per reporter's comments.