ubuntu karmic firefox 3.5.4 slow on ecryptfs

[Jim Leinweber]

Binary package hint: firefox-3.5

Firefox 3.5.4 is incredibly slow running on ubuntu 9.10 karmic, fresh install, ext4 filesystem, ecryptfs encrypted home directory. This seems to be peculiar to firefox; konqueror is normal, applications other than firefox are normal. Firefox performs normally for a different user with an ordinary unencrypted home directory.

ProblemType: Bug
Architecture: amd64
Date: Sun Nov 1 22:17:11 2009
DistroRelease: Ubuntu 9.10
InstallationMedia: Ubuntu 9.10 "Karmic Koala" - Release Candidate amd64 (20091020.3)
Package: firefox 3.5.4+nobinonly-0ubuntu0.9.10.1
PackageArchitecture: all
ProcEnviron:
 PATH=(custom, user)
 LANG=en_US.UTF-8
 SHELL=/bin/bash
ProcVersionSignature: Ubuntu 2.6.31-14.48-generic
SourcePackage: firefox-3.5
Uname: Linux 2.6.31-14-generic x86_64
XsessionErrors:
 (gnome-settings-daemon:3825): GLib-CRITICAL **: g_propagate_error: assertion `src != NULL' failed
 (gnome-settings-daemon:3825): GLib-CRITICAL **: g_propagate_error: assertion `src != NULL' failed
 (nautilus:3925): Eel-CRITICAL **: eel_preferences_get_boolean: assertion `preferences_is_initialized ()' failed
 (polkit-gnome-authentication-agent-1:3957): GLib-CRITICAL **: g_once_init_leave: assertion `initialization_value != 0' failed
 (gnome-panel:3924): Gtk-WARNING **: gtk_widget_size_allocate(): attempt to allocate widget with width -5 and height 24

[Jim Leinweber (jiml-mail)]

I forgot to mention that while firefox is being slow (2-5 minutes to load pages that konqueror loads in 2-5 seconds), CPU utilization is normal. It's not running away with CPU or memory. I haven't had time to study the disk I/O pattern yet.

[WeatherGod (ben-v-root)]

I think I heard of this bug before on encrypted Windows partitions. If I remember correctly, the problem was due to Firefox reading the contents of the firefox profile in order to initialize a random number generator for SSL connections. However, you are stating that this happens for each loaded page, so I don't know if this is the same.

[Jim Leinweber (jiml-mail)]

Hmmm. It's not generically slow; I just tried a test install of 32bit Karmic to an ext4 partition on a different laptop (Dell latitude D620), and an ecryptfs home user had normal firefox speed. I'll do more testing tonight to see if I can pin down what the problem laptop (Toshiba Satellite A215) is doing differently. (Wireless versus wired, 64-bit versus 32-bit, Cable modem charter.net DNS versus good DNS, default bookmarks versus imported .json file, ...).

[Jim Leinweber (jiml-mail)]

The puzzle continues. I did "adduser --encrypt-home" to make a third user with an encrypted home directory. So I have 3 users, call them A, B, C:
A is the first user (adm group, ecryptfs home) - firefox is very slow, konqueror is normal
B is the second user (adm group, regular home) - firefox is normal
C is the third user (ecryptfs home) - firefox is normal

This is with the same .json file imported as bookmarks into A and C. And with A and C logged in simultaneously.

So I have one slow user on one computer, and many fast users on many computers. Any bright ideas before I sink to strace or something?

[Peter Antoniac (pan1nx)]

Thanks for the bug report. Sink to strace :D There are some issues with firefox-3.5. Are you using kubuntu or ubuntu (as I see konqueror) for the main window manager?

[Jim Leinweber (jiml-mail)]

Ubuntu 9.10 64-bit, installed fresh on ext4 around alpha6 and upgraded continually since. Kbuntu-desktop is _not_ installed, but some KDE applications are.

"dpkg-query -l firefox" shows "3.5.4+nobinonly-0ubuntu0.9.10.1"
"cat /proc/version_signature" shows "Ubuntu 2.6.31-14.48-generic"
lspci identifies the video chip as "ATI Technologies Inc RS690M [Radeon X1200 Series]";
Xorg driver is radeon.

Hardware is a Toshiba Satellite A215 laptop.

I'm attaching strace files of the slow and fast firefox users loading www.ubuntu.com. "wc" shows:
    37920 354071 4065616 /tmp/firefox.ecryptfs.fast.strace
  162123 1932668 21868806 /tmp/firefox.ecryptfs.slow.strace

[Jim Leinweber (jiml-mail)]

And now for the slow strace

[Michael Rooney (mrooney)]

I'll open up an ecryptfs task since it might be relevant there; if after evaluation of the info/trace it isn't please mark that task as Invalid.

I also use Firefox with an encrypted home and don't remember any performance issues off-hand but if there any specific steps that reproduce certain symptoms, please let me know and I can try to reproduce.

[Robert K. Tompsett (n8juq)]

Ubuntu 9.04 with Firefox 3.5.4 extremely slow when browsing. Times out.

[Dustin Kirkland  (kirkland)]

Hmm, okay, I ran a little analysis on your histograms...

cat firefox.ecryptfs.slow.strace | sed "s/(.*//" | sort -u > words
for i in $(cat words); do echo -n "$i "; grep -c "^$i" firefox.ecryptfs.fast.strace; done | sort -k 2 -n > /tmp/histogram_fast
for i in $(cat words); do echo -n "$i "; grep -c "^$i" firefox.ecryptfs.slow.strace; done | sort -k 2 -n > /tmp/histogram_slow
tail -n 10 /tmp/histogram_*

==> /tmp/histogram_fast <==
lseek 1057
close 1089
futex 1260
open 1502
madvise 2249
stat 2661
writev 2937
write 3851
poll 8600
read 11722

==> /tmp/histogram_slow <==
lseek 1087
close 1102
open 1529
stat 2841
madvise 3828
futex 13392
writev 15315
write 20113
poll 49424
read 64545

Looks like your slow version is doing a *lot* more futex, writev, write, poll, and read.

Specifically, there's a lot of:
read(3, 0x7f93049ae074, 4096) = -1 EAGAIN (Resource temporarily unavailable)

grep "Resource temporarily unavailable" firefox.ecryptfs.fast.strace | wc
   6407 57691 557685
grep "Resource temporarily unavailable" firefox.ecryptfs.slow.strace | wc
  46904 422249 4081862

I don't really know what's at that address, and I don't yet see what eCryptfs might be doing wrong here. Considering that firefox is working well with your other users on eCryptfs, this is strange.

On the user with the "slow" firefox, could you mv ~/.mozilla ~/.mozilla.orig. The next time you open Firefox, it will recreate the .mozilla directory (losing your bookmarks, cookies, passwords, etc). You can restore it again by moving it back into place. But see if your firefox is any faster with a brand new .mozilla config.

:-Dustin

:-Dustin

:-Dustin

[Ian! D. Allen (idallen)]

Ubuntu 9.10 64 bit with all updates
Linux 2.6.31-17-generic #54-Ubuntu SMP Thu Dec 10 17:01:44 UTC 2009 x86_64 GNU/Linux
ii firefox 3.5.7+nobinonl meta package for the popular mozilla web bro
ii firefox-3.5 3.5.7+nobinonl safe and easy web browser from Mozilla
ii firefox-3.5-br 3.5.7+nobinonl Package that ships the firefox branding
ii firefox-3.5-gn 3.5.7+nobinonl Support for Gnome in Mozilla Firefox
ii firefox-gnome- 3.5.7+nobinonl meta package pointing to the latest gnome-su
Using ecryptfs $HOME

My strace shows Firefox looping getting thousands of poll() followed by
"read()-1 EAGAIN (Resource temporarily unavailable)" errors. This is
nothing new - Firefox did the same thing under Ubuntu 8.10 last year.
(Last year I think there were more time syscalls in the mix, and the
looping would occasionally eat 100% of the CPU until I killed Firefox
and restarted it.)

poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}, {fd=64, events=POLLIN|POLLPRI}, {fd=79, events=POLLIN|POLLPRI}, {fd=81, events=POLLIN|POLLPRI}, {fd=84, events=POLLIN|POLLPRI}, {fd=94, events=POLLIN}, {fd=70, events=POLLIN|POLLPRI}, {fd=116, events=POLLIN}, {fd=124, events=POLLIN}, {fd=86, events=POLLIN}], 11, 3205) = 1 ([{fd=86, revents=POLLIN}])
read(86, "\372", 1) = 1
read(3, 0x7f003b6ab074, 4096) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}, {fd=64, events=POLLIN|POLLPRI}, {fd=79, events=POLLIN|POLLPRI}, {fd=81, events=POLLIN|POLLPRI}, {fd=84, events=POLLIN|POLLPRI}, {fd=94, events=POLLIN}, {fd=70, events=POLLIN|POLLPRI}, {fd=116, events=POLLIN}, {fd=124, events=POLLIN}, {fd=86, events=POLLIN}], 11, 0) = 0 (Timeout)
read(3, 0x7f003b6ab074, 4096) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}, {fd=64, events=POLLIN|POLLPRI}, {fd=79, events=POLLIN|POLLPRI}, {fd=81, events=POLLIN|POLLPRI}, {fd=84, events=POLLIN|POLLPRI}, {fd=94, events=POLLIN}, {fd=70, events=POLLIN|POLLPRI}, {fd=116, events=POLLIN}, {fd=124, events=POLLIN}, {fd=86, events=POLLIN}], 11, 3204) = 1 ([{fd=86, revents=POLLIN}])
read(86, "\372", 1) = 1
read(3, 0x7f003b6ab074, 4096) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}, {fd=64, events=POLLIN|POLLPRI}, {fd=79, events=POLLIN|POLLPRI}, {fd=81, events=POLLIN|POLLPRI}, {fd=84, events=POLLIN|POLLPRI}, {fd=94, events=POLLIN}, {fd=70, events=POLLIN|POLLPRI}, {fd=116, events=POLLIN}, {fd=124, events=POLLIN}, {fd=86, events=POLLIN}], 11, 0) = 0 (Timeout)
read(3, 0x7f003b6ab074, 4096) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}, {fd=64, events=POLLIN|POLLPRI}, {fd=79, events=POLLIN|POLLPRI}, {fd=81, events=POLLIN|POLLPRI}, {fd=84, events=POLLIN|POLLPRI}, {fd=94, events=POLLIN}, {fd=70, events=POLLIN|POLLPRI}, {fd=116, events=POLLIN}, {fd=124, events=POLLIN}, {fd=86, events=POLLIN}], 11, 3184) = 1 ([{fd=86, revents=POLLIN}])
read(86, "\372", 1) = 1
read(3, 0x7f003b6ab074, 4096) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=P...

[Bao Liang (timbao)]

My problem is similar but it doesn't show up during normal browsing. However, everytime when I try to select a file to upload in a website, or just use File->Open File. One of the CPU core will get ~100% and browsing in the file selection dialog will be extremely slow. I am going to file another bug.

[Dustin Kirkland  (kirkland)]

Okay, any one who is experiencing this problem, can you please test the following...

 1) Close all of your Firefox sessions
 2) mv $HOME/.mozilla $HOME/.mozilla.orig
 3) Launch a new Firefox

This will re-seed $HOME/.mozilla with a fresh profile. Do you still experience the problem?

Remove the new .mozilla and move your .mozilla.orig back into place to restore your history/cookies/bookmarks, etc.

[Launchpad Janitor (janitor)]

[Expired for firefox-3.5 (Ubuntu) because there has been no activity for 60 days.]

[Launchpad Janitor (janitor)]

[Expired for ecryptfs-utils (Ubuntu) because there has been no activity for 60 days.]