If you think a bug might affect users in the 57 release, please set the correct tracking and status flags for Release Management.

After network problem Firefox stop loading any sites and "Socket Thread" process consume 100% CPU

RESOLVED FIXED in Firefox 38

Status

()

Core
Networking: HTTP
RESOLVED FIXED
3 years ago
2 years ago

People

(Reporter: Mikhail, Assigned: mcmanus)

Tracking

Trunk
mozilla38
x86_64
Linux
Points:
---
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(firefox37 unaffected, firefox38 fixed)

Details

MozReview Requests

()

Submitter Diff Changes Open Issues Last Updated
Loading...
Error loading review requests:

Attachments

(8 attachments, 1 obsolete attachment)

(Reporter)

Description

3 years ago
User Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.12 Safari/537.36

Steps to reproduce:

Don't know


Actual results:

After network problem Firefox stop loading any sites and "Socket Thread" process consume 100% CPU
(Reporter)

Comment 1

3 years ago
stack trace

(gdb) thread apply all bt

Thread 1 (process 10639):
#0  0x00007f89b0d8c3e0 in mozilla::net::nsHttpTransaction::ReadRequestSegment(nsIInputStream*, void*, char const*, unsigned int, unsigned int, unsigned int*) () from /home/mikhail/Downloads/firefox/libxul.so
#1  0x00007f89b0c8065b in nsBufferedInputStream::ReadSegments(tag_nsresult (*)(nsIInputStream*, void*, char const*, unsigned int, unsigned int, unsigned int*), void*, unsigned int, unsigned int*) ()
   from /home/mikhail/Downloads/firefox/libxul.so
#2  0x00007f89b0d8c2c4 in mozilla::net::nsHttpTransaction::ReadSegments(mozilla::net::nsAHttpSegmentReader*, unsigned int, unsigned int*) () from /home/mikhail/Downloads/firefox/libxul.so
#3  0x00007f89b0d51dbd in mozilla::net::Http2Stream::ReadSegments(mozilla::net::nsAHttpSegmentReader*, unsigned int, unsigned int*) () from /home/mikhail/Downloads/firefox/libxul.so
#4  0x00007f89b0d59abd in mozilla::net::Http2Session::ReadSegments(mozilla::net::nsAHttpSegmentReader*, unsigned int, unsigned int*) () from /home/mikhail/Downloads/firefox/libxul.so
#5  0x00007f89b0d7e9cf in mozilla::net::nsHttpConnection::OnSocketWritable() () from /home/mikhail/Downloads/firefox/libxul.so
#6  0x00007f89b0d7ec06 in mozilla::net::nsHttpConnection::OnOutputStreamReady(nsIAsyncOutputStream*) () from /home/mikhail/Downloads/firefox/libxul.so
#7  0x00007f89b0c986ef in nsSocketOutputStream::OnSocketReady(tag_nsresult) () from /home/mikhail/Downloads/firefox/libxul.so
#8  0x00007f89b0c98fe9 in nsSocketTransport::OnSocketReady(PRFileDesc*, short) () from /home/mikhail/Downloads/firefox/libxul.so
#9  0x00007f89b0c9d978 in nsSocketTransportService::DoPollIteration(bool) () from /home/mikhail/Downloads/firefox/libxul.so
#10 0x00007f89b0c9dd1d in nsSocketTransportService::Run() () from /home/mikhail/Downloads/firefox/libxul.so
#11 0x00007f89b094f976 in nsThread::ProcessNextEvent(bool, bool*) () from /home/mikhail/Downloads/firefox/libxul.so
#12 0x00007f89b095752e in NS_ProcessNextEvent(nsIThread*, bool) () from /home/mikhail/Downloads/firefox/libxul.so
#13 0x00007f89b0e3a936 in mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) () from /home/mikhail/Downloads/firefox/libxul.so
#14 0x00007f89b0e30c02 in MessageLoop::Run() () from /home/mikhail/Downloads/firefox/libxul.so
#15 0x00007f89b0c395df in nsThread::ThreadFunc(void*) () from /home/mikhail/Downloads/firefox/libxul.so
#16 0x00007f89b59eb945 in _pt_root () from /home/mikhail/Downloads/firefox/libnspr4.so
#17 0x00007f89b6e5152a in start_thread (arg=0x7f899b6fe700) at pthread_create.c:310
#18 0x00007f89b5f5379d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
(gdb)
(Reporter)

Comment 2

3 years ago
Created attachment 8553141 [details]
htop screenshot
(Reporter)

Comment 3

3 years ago
Created attachment 8553144 [details]
full firefox trace
(Reporter)

Comment 4

3 years ago
While the browser is still running but consumes CPU what information would be helpful?
(Reporter)

Comment 5

3 years ago
Created attachment 8553184 [details]
firefox strace
Component: Untriaged → Networking: HTTP
Product: Firefox → Core
Version: Firefox 38 → Trunk
(Assignee)

Comment 6

3 years ago
you could put a breakpoint on the line in stack 4 and see if it keeps ending up spinning past this, and if so what it is returning.
(Assignee)

Comment 7

3 years ago
when you say "after network problem" what are you referring to?
(Reporter)

Comment 8

3 years ago
(In reply to Patrick McManus [:mcmanus] from comment #6)
> you could put a breakpoint on the line in stack 4 and see if it keeps ending
> up spinning past this, and if so what it is returning.
You means set breakpoint on this line?
#4  0x00007f89b0d59abd in mozilla::net::Http2Session::ReadSegments(mozilla::net::nsAHttpSegmentReader*, unsigned int, unsigned int*) () from /home/mikhail/Downloads/firefox/libxul.so
and sure that we are in cycle?


(In reply to Patrick McManus [:mcmanus] from comment #7)
> when you say "after network problem" what are you referring to?
I forgot to recharge the internet account. When this happens provider puts his stub on all sites. And seems at this time browser tries to update itself.
(Assignee)

Comment 9

3 years ago
(In reply to Mikhail from comment #8)
> (In reply to Patrick McManus [:mcmanus] from comment #6)
> > you could put a breakpoint on the line in stack 4 and see if it keeps ending
> > up spinning past this, and if so what it is returning.
> You means set breakpoint on this line?
> #4  0x00007f89b0d59abd in
> mozilla::net::Http2Session::ReadSegments(mozilla::net::nsAHttpSegmentReader*,
> unsigned int, unsigned int*) () from
> /home/mikhail/Downloads/firefox/libxul.so
> and sure that we are in cycle?
>

yes.. and if you can stand it just hit "next" through the http2stream and http2session readsegments functions.. printing out rv as needed. thanks.

can you make this happen after a restart? if you could then an http log 
https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging would be much more helpful.
(Reporter)

Comment 10

3 years ago
(In reply to Patrick McManus [:mcmanus] from comment #9)
> yes.. and if you can stand it just hit "next" through the http2stream and
> http2session readsegments functions.. printing out rv as needed. thanks.
> 

(gdb) c
Continuing.
^C
Program received signal SIGINT, Interrupt.
0x00007f89b0d8c3e0 in mozilla::net::nsHttpTransaction::ReadRequestSegment(nsIInputStream*, void*, char const*, unsigned int, unsigned int, unsigned int*) () from /home/mikhail/Downloads/firefox/libxul.so
(gdb) s
Single stepping until exit from function _ZN7mozilla3net17nsHttpTransaction18ReadRequestSegmentEP14nsIInputStreamPvPKcjjPj,
which has no line number information.
0x00007f89b0c8065b in nsBufferedInputStream::ReadSegments(tag_nsresult (*)(nsIInputStream*, void*, char const*, unsigned int, unsigned int, unsigned int*), void*, unsigned int, unsigned int*) ()
   from /home/mikhail/Downloads/firefox/libxul.so
(gdb) s
Single stepping until exit from function _ZN21nsBufferedInputStream12ReadSegmentsEPF12tag_nsresultP14nsIInputStreamPvPKcjjPjES3_jS6_,
which has no line number information.
0x00007f89b0c80668 in nsBufferedInputStream::ReadSegments(tag_nsresult (*)(nsIInputStream*, void*, char const*, unsigned int, unsigned int, unsigned int*), void*, unsigned int, unsigned int*) ()
   from /home/mikhail/Downloads/firefox/libxul.so
ptrace: No such process.
(gdb) s
Single stepping until exit from function _ZN21nsBufferedInputStream12ReadSegmentsEPF12tag_nsresultP14nsIInputStreamPvPKcjjPjES3_jS6_,
which has no line number information.
0x00007f89b0c80668 in nsBufferedInputStream::ReadSegments(tag_nsresult (*)(nsIInputStream*, void*, char const*, unsigned int, unsigned int, unsigned int*), void*, unsigned int, unsigned int*) ()
   from /home/mikhail/Downloads/firefox/libxul.so
ptrace: No such process.
(gdb) s
Single stepping until exit from function _ZN21nsBufferedInputStream12ReadSegmentsEPF12tag_nsresultP14nsIInputStreamPvPKcjjPjES3_jS6_,
which has no line number information.
0x00007f89b0c80668 in nsBufferedInputStream::ReadSegments(tag_nsresult (*)(nsIInputStream*, void*, char const*, unsigned int, unsigned int, unsigned int*), void*, unsigned int, unsigned int*) ()
   from /home/mikhail/Downloads/firefox/libxul.so
ptrace: No such process.
(gdb) s
Single stepping until exit from function _ZN21nsBufferedInputStream12ReadSegmentsEPF12tag_nsresultP14nsIInputStreamPvPKcjjPjES3_jS6_,
which has no line number information.
0x00007f89b0c80668 in nsBufferedInputStream::ReadSegments(tag_nsresult (*)(nsIInputStream*, void*, char const*, unsigned int, unsigned int, unsigned int*), void*, unsigned int, unsigned int*) ()
   from /home/mikhail/Downloads/firefox/libxul.so
ptrace: No such process.
(gdb) 
Program terminated with signal SIGTRAP, Trace/breakpoint trap.
The program no longer exists.

The program is not being run.
(gdb) q


sorry it crashed :(




> can you make this happen after a restart? if you could then an http log 
> https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging
> would be much more helpful.

it would be usefull only if i could reproduce this again.
(Reporter)

Comment 11

3 years ago
Created attachment 8553288 [details]
firefox tty output
I ran into the same issue (can't navigate, high CPU usage) with 32-bit Nightly 38 on Win7.
Stack: http://pastebin.mozilla.org/8365924
(Assignee)

Updated

3 years ago
Duplicate of this bug: 1124561
(Assignee)

Updated

3 years ago
Blocks: 1072478
status-firefox37: --- → unaffected
status-firefox38: --- → affected
(Assignee)

Comment 14

3 years ago
mikhail - thanks for a useful report. I was able to make the same thing happen by having an upload stream get queued over the max concurrency limit of h2 or spdy.

patch and test too follow
(Assignee)

Comment 15

3 years ago
Created attachment 8554943 [details]
MozReview Request: bz://1124717/mcmanus

/r/3005 - bug 1124717 - 1/4 h2/spdy fix spin when queuing post/put request over concurrent limit r=hurley
/r/3007 - bug 1124717 - 2/4 update CI to node-http2 3.1.0 to fix flow control issue r=hurley
/r/3009 - bug 1124717 - 3/4 make h2/spdy default peer max concurrent setting configurable r=hurley
/r/3011 - bug 1124717 - 4/4 test r=hurley

Pull down these commits:

hg pull review -r 812395cc0e3ed08aa5051683021caabd181cfcd2
(Assignee)

Updated

3 years ago
Attachment #8554943 - Flags: review?(hurley)
https://reviewboard.mozilla.org/r/3003/#review2327

Pro tip: with MozReview, you don't need to record part numbers in the commit message because it is implicitly part of the repository data! MozReview will always display commits in the order they exist in the repository (unlike Bugzilla, which is patch file based and doesn't have access to this data).
Status: UNCONFIRMED → NEW
Ever confirmed: true
(Assignee)

Comment 17

3 years ago
https://treeherder.mozilla.org/#/jobs?repo=try&revision=5a1e54cec3cb
Comment on attachment 8554943 [details]
MozReview Request: bz://1124717/mcmanus

https://reviewboard.mozilla.org/r/3003/#review2399

LGTM
Attachment #8554943 - Flags: review?(hurley) → review+
(Assignee)

Comment 19

3 years ago
https://hg.mozilla.org/integration/mozilla-inbound/rev/7b7d437f2adf
https://hg.mozilla.org/integration/mozilla-inbound/rev/edee665f5e63
https://hg.mozilla.org/integration/mozilla-inbound/rev/141093a1f646
https://hg.mozilla.org/integration/mozilla-inbound/rev/21cc8ac2fb4c
https://hg.mozilla.org/mozilla-central/rev/7b7d437f2adf
https://hg.mozilla.org/mozilla-central/rev/edee665f5e63
https://hg.mozilla.org/mozilla-central/rev/141093a1f646
https://hg.mozilla.org/mozilla-central/rev/21cc8ac2fb4c
Assignee: nobody → mcmanus
Status: NEW → RESOLVED
Last Resolved: 3 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → mozilla38
status-firefox38: affected → fixed
(Assignee)

Comment 21

2 years ago
Comment on attachment 8554943 [details]
MozReview Request: bz://1124717/mcmanus
Attachment #8554943 - Attachment is obsolete: true
Attachment #8619206 - Flags: review+
Attachment #8619207 - Flags: review+
Attachment #8619208 - Flags: review+
Attachment #8619209 - Flags: review+
(Assignee)

Comment 22

2 years ago
Created attachment 8619206 [details]
MozReview Request: bug 1124717 - 3/4 make h2/spdy default peer max concurrent setting configurable r=hurley
(Assignee)

Comment 23

2 years ago
Created attachment 8619207 [details]
MozReview Request: bug 1124717 - 4/4 test r=hurley
(Assignee)

Comment 24

2 years ago
Created attachment 8619208 [details]
MozReview Request: bug 1124717 - 1/4 h2/spdy fix spin when queuing post/put request over concurrent limit r=hurley
(Assignee)

Comment 25

2 years ago
Created attachment 8619209 [details]
MozReview Request: bug 1124717 - 2/4 update CI to node-http2 3.1.0 to fix flow control issue r=hurley
You need to log in before you can comment on or make changes to this bug.