AJAX call on a Drupal site freezes in non-javascript area, high CPU usage.

NEW
Assigned to

Status

()

Core
Layout
5 years ago
a year ago

People

(Reporter: antony lovric, Assigned: mats)

Tracking

({perf, regression})

17 Branch
perf, regression
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(3 attachments)

(Reporter)

Description

5 years ago
Created attachment 765480 [details]
LabelsForeverAjaxHang.png

User Agent: Mozilla/5.0 (compatible; MSIE 10.0; Windows NT 6.1; WOW64; Trident/6.0; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C; .NET4.0E)

Steps to reproduce:

Windows XP/7 connecting to a Drupal 7 Install on Ubuntu, 

Opened a page on a Drupal site that uses AJAX:

http://labelsforever.com/en/content/photo-labels

Switch the theme, once or twice, the spinner freezes, that's the issue.

Tried to diagnose with a trial version of AxaxDynaTrace, JavaScript/Rendering/Network appear almost idle, CPU is maxed out.


Actual results:

  Seems that after the AJAX request is sent AND a reply received, Firefox goes into some kind of busy loop, CPU increases until loop/block clears.


Expected results:

  Form content should have been replaced.
(Reporter)

Comment 1

5 years ago
By 'Switch the theme, once or twice', I mean the label's theme (choosing a photo border from the slider), not the Drupal theme, sorry for the confusion.
(Reporter)

Comment 2

5 years ago
  One other small note, I tried to reproduce the issue with an older build of FF (sitting on a VM in the office here, FF 12) and the issue was not present.

Comment 3

5 years ago
Is there any chance you could help narrow the regression range by using http://mozilla.github.com/mozregression/?
(Reporter)

Comment 4

5 years ago
  Hey Josh, sure I can run the regression (cool tool btw).  I started at 2010-01-01 and let the tool run from there.

mozregression --good=2010-01-01

[OK] 			10.0a1  (2011-09-28)
[OK] 			17.0a1 (2012-08-10)
[BAD] 			21.0a1 (2013-01-16)
[NOT AS BAD] 	        19.0a1 (2012-10-28)
[OK]	 		18.0a1 (2012-09-18)
[BAD]			18.0a1 (2012-10-08)
[BAD]			18.0a1 (2012-09-28)
[BAD]			18.0a1 (2012-09-23)
[BAD]			18.0a1 (2012-09-20)
[BAD]			18.0a1 (2012-09-19)

-more targeted
mozregression --good=2012-09-17 --bad=2012-9-19

'19.0a1 (2012-10-28)' might be a error in my judgement but 2012-09-18 is clearly good and all nightly builds AFTER have the hang / pause after the request completes.

Comment 5

5 years ago
Thanks! Going by the revisions of the Windows builds for 9/18 and 9/19, that suggests the following regression range: http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=0d3b17a88d5f&tochange=80499f04e875

Comment 6

5 years ago
I can reproduce this easily on Fedora, too.
Status: UNCONFIRMED → NEW
Ever confirmed: true
OS: Windows 7 → All
Hardware: x86_64 → All
(Reporter)

Comment 7

5 years ago
  Thanks Josh.

Comment 8

5 years ago
Figuring out what's happening in the busy loop would be really useful. Would you mind gathering some profiling data by following the steps at https://developer.mozilla.org/en-US/docs/Performance/Reporting_a_Performance_Problem? I'd do it myself, but the profiler doesn't give useful data on Linux systems.
Flags: needinfo?(antonylovric)
(Reporter)

Comment 9

5 years ago
Created attachment 766680 [details]
Profiler Run #1

  Profiler output from 1st run
Flags: needinfo?(antonylovric)
(Reporter)

Comment 10

5 years ago
Created attachment 766682 [details]
Profiler Run #2

Should have zipped these together....
It's actually easier to upload the profile results to the server, since you then receive a link you can share in Bugzilla.
(Reporter)

Comment 12

5 years ago
doh!
Antony, given that I haven't figured out how to use the files you attached yet, could you just do another profiler run and paste the link to the uploaded profile here?
Flags: needinfo?(antonylovric)
(Reporter)

Comment 14

5 years ago
  Hey Josh, the profiler is not working right now.  On the nightly build it fails to load the url for the profiler-consuming site.  

From:https://addons.mozilla.org/en-US/firefox/addon/gecko-profiler/?src=api

'Not available for Firefox 25.0' - Nightly is @ 25.01a right now ;(

  I can't install 24.X right now, try the profiler analyse, download the file: (not explaining that)

goto:http://people.mozilla.com/~bgirard/cleopatra/ with FF, and click upload.
Flags: needinfo?(antonylovric)
(Reporter)

Comment 15

5 years ago
  (sorry, forgot to mention to select the file in comment #14)
(Reporter)

Comment 17

5 years ago
Couldn't get the built-in profile to save/share the profile, also, it doesn't show the red (busy) portion of the request? 

Anyways, I uploaded the profile files to the link in comment #14 and said 'share' on the bottom left, here are the links to the shared profiles.

http://people.mozilla.com/~bgirard/cleopatra/#report=6aba5fc4c84a8d4b42ba3b2cfb813f877b2de035

http://people.mozilla.com/~bgirard/cleopatra/#report=4395f6920521c10c45f351f7e319e77b79cee242
Perfect! The profiles show us spending about ~40% of time performing layout (and the timeline shows lots of synchronous layout calls occurring, which would make sense), especially font shaping, and about ~5% of time executing Dupal AJAX code. Alice, would you be able to bisect the regression range any further for us?
Keywords: regressionwindow-wanted
(Reporter)

Comment 19

5 years ago
..I was looking at the profiler output and noticed that @ 49% of the time was spent in NtUserWaitMessage called from nsBaseAppShell::OnProcessNextEvent(nsIThreadInternal *,bool,unsigned int).  I don't know much about the code though...

Comment 20

5 years ago
Regression window(m-c)
Good:
http://hg.mozilla.org/mozilla-central/rev/2e429432490c
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:18.0) Gecko/18.0 Firefox/18.0 ID:20120918023002
Bad:
http://hg.mozilla.org/mozilla-central/rev/e4757379b99a
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:18.0) Gecko/18.0 Firefox/18.0 ID:20120918044902
Pushlog:
http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=2e429432490c&tochange=e4757379b99a


Regression window(m-i)
Good:
http://hg.mozilla.org/integration/mozilla-inbound/rev/27f122beb4f5
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:18.0) Gecko/18.0 Firefox/18.0 ID:20120917154902
Bad:
http://hg.mozilla.org/integration/mozilla-inbound/rev/49bc46738815
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:18.0) Gecko/18.0 Firefox/18.0 ID:20120917164302
Pushlog:
http://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=27f122beb4f5&tochange=49bc46738815

In local build
Last Good: e016faeb6b15
First Bad: 1d8ff0faf0fa

Triggered by:
	1d8ff0faf0fa	Mats Palmgren — Bug 791601. r=roc
Blocks: 791601
Component: General → Layout
Keywords: regressionwindow-wanted → perf, regression
Version: 21 Branch → 17 Branch
Assignee: nobody → matspal
You need to log in before you can comment on or make changes to this bug.