635883 - firefox tries to open too many files and misbehaves

Status: RESOLVED INCOMPLETE

(Core :: Networking, defect)

Description

[andreala]

User-Agent:       Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:2.0b11) Gecko/20100101 Firefox/4.0b11
Build Identifier: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:2.0b11) Gecko/20100101 Firefox/4.0b11

Seems like firefox leaks file handles and tries to open too many file handles. Result is problems resolving dns and browsing (in general). 

Only resolution is to restart.

Reproducible: Always

Steps to Reproduce:
1. Start firefox
2. Browse merrily for a period of time (30/60min+)
3. Start getting "cannot resolve"-error page on everything not cached (i.e. google.com and other clearly existing domains etc)
Actual Results:  
Getting cannot resolve errors on everything and the log excerpt posted in additional information in /var/log/system.log

Expected Results:  
continue working.

Feb 22 15:01:59 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: *** process 20202 exceeded 500 log message per second limit  -  remainin
g messages this second discarded ***Feb 22 15:02:00 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: dnssd_clientstub deliver_request: socketpair failed 24 (Too many open fi
les)Feb 22 15:02:00: --- last message repeated 499 times ---
Feb 22 15:02:00 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: *** process 20202 exceeded 500 log message per second limit  -  remainin
g messages this second discarded ***Feb 22 15:02:00 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: dnssd_clientstub deliver_request: socketpair failed 24 (Too many open fi
les)Feb 22 15:02:01: --- last message repeated 499 times ---
Feb 22 15:02:01 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: *** process 20202 exceeded 500 log message per second limit  -  remainin
g messages this second discarded ***
Feb 22 15:02:02 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: dnssd_clientstub deliver_request: socketpair failed 24 (Too many open files)
Feb 22 15:02:03: --- last message repeated 499 times ---
Feb 22 15:02:02 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: *** process 20202 exceeded 500 log message per second limit  -  remainin
g messages this second discarded ***
Feb 22 15:02:02 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: dnssd_clientstub deliver_request: socketpair failed 24 (Too many open files)
Feb 22 15:02:03: --- last message repeated 499 times ---
Feb 22 15:02:03 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: *** process 20202 exceeded 500 log message per second limit  -  remainin
g messages this second discarded ***
Feb 22 15:02:03 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: dnssd_clientstub deliver_request: socketpair failed 24 (Too many open files)Feb 22 15:02:15: --- last message repeated 98 times ---
Feb 22 15:02:15 d-173146-dhcp com.apple.backupd[21432]: No pre-backup thinning needed: 4.55 GB requested (including padding), 10.23 GB available
Feb 22 15:02:45 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: dnssd_clientstub deliver_request: socketpair failed 24 (Too many open fi
les)
Feb 22 15:02:45: --- last message repeated 20 times ---
Feb 22 15:02:45 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: dnssd_clientstub ConnectToServer: socket failed 24 Too many open files
Feb 22 15:02:45: --- last message repeated 5 times ---
Feb 22 15:02:45 d-173146-dhcp /Applications/Firefox.app/Contents/MacOS/firefox-bin[20202]: dnssd_clientstub deliver_request: socketpair failed 24 (Too many open fi
les)
Feb 22 15:03:09: --- last message repeated 372 times ---
Feb 22 15:03:09 d-173146-dhcp firefox-bin[20202]: Critical failure: the LastResort font is unavailable.
Feb 22 15:03:13: --- last message repeated 19 times ---
Feb 22 15:03:13 d-173146-dhcp [0x0-0x685685].org.mozilla.firefox[20202]: Adblock Plus: failed to create file /Users/andreala/Library/Application Support/Firefox/Pr
ofiles/nda56vi0.default/adblockplus/patterns.ini-temp: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIFileOutputStream.init]"  n
sresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: chrome://adblockplus-modules/content/FilterStorage.jsm :: <TOP_LEVEL> :: line 491"  data: no]
Feb 22 15:03:14 d-173146-dhcp firefox-bin[20202]: Critical failure: the LastResort font is unavailable.
Feb 22 15:03:32: --- last message repeated 20 times ---
Feb 22 15:03:32 d-173146-dhcp sudo[21438]: andreala : TTY=ttys001 ; PWD=/Users/andreala ; USER=root ; COMMAND=/usr/bin/tail -f /var/log/system.logFeb 22 15:03:41 d-173146-dhcp firefox-bin[20202]: Critical failure: the LastResort font is unavailable.
Feb 22 15:03:43: --- last message repeated 382 times ---
Feb 22 15:03:43 d-173146-dhcp firefox-bin[20202]: __SCPreferencesCreate open() failed: Too many open files
Feb 22 15:03:43: --- last message repeated 2 times ---
Feb 22 15:03:43 d-173146-dhcp firefox-bin[20202]: Critical failure: the LastResort font is unavailable.
Feb 22 15:03:58: --- last message repeated 170 times ---
Feb 22 15:03:58 d-173146-dhcp [0x0-0x685685].org.mozilla.firefox[20202]: NOTE: child process received `Goodbye', closing down

Comment 1

[andreala]

This occurs in 4 beta (verified in both 10 and 11).

Did not occur in 3.6

Comment 2

[Ed Morley [:emorley]]

Could you see if the issue occurs...
- With a new, empty profile:
http://support.mozilla.com/en-US/kb/Basic%20Troubleshooting#w_make-a-new-profile
- Using the latest nightly:
http://nightly.mozilla.org/

If it does occur with the latest nightly, would you be able to try and find the regression range:
http://harthur.github.com/mozregression/

Thanks!

Comment 3

[andreala]

Reproduced with nightly (2011-02-22) with same result behaviour in system.log:

[..]
Feb 23 12:10:42 d-173146-dhcp /Users/andreala/Development/mozregression/moznightlyapp/Mozilla.app/Contents/MacOS/firefox-bin[23349]: *** process 23349 exceeded 500 log message per second limit  -  remaining messages this second discarded ***
Feb 23 12:10:42 d-173146-dhcp /Users/andreala/Development/mozregression/moznightlyapp/Mozilla.app/Contents/MacOS/firefox-bin[23349]: dnssd_clientstub deliver_request: socketpair failed 24 (Too many open files)
[..]

Comment 4

[andreala]

(In reply to comment #3)
> Reproduced with nightly (2011-02-22) with same result behaviour in system.log:
> 
That said, with the same profile.

I'm now running with a fresh profile - time will show.

Comment 5

[andreala]

Unable to reproduce with a fresh profile, trying over the last couple of nightlies (latest 2011-02-26).

Which points towards old profile pecularities.

Comment 6

[Boris Zbarsky [:bzbarsky]]

OK.  Do the two profiles have the same set of extensions?

Comment 7

[andreala]

Have been running nightlies since last comment, and unable to reproduce. However with a slightly reduced set of extensions (due to compatibility).

Propose to close as unreproducible in nightlies?

Comment 8

[Patrick McManus [:mcmanus]]

its likely that the issue here wasn't a leak, but rather just a high peak use of FD - maybe extension related.

this changeset increased the number of fd's on most systems, so could very well be responsible for the fix:

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