Open Bug 188318 Opened 22 years ago Updated 2 years ago

typing quickly causes high cpu usage

Categories

(Core :: DOM: Editor, defect, P4)

defect

Tracking

()

People

(Reporter: leon.zhang, Unassigned)

References

(Depends on 2 open bugs)

Details

(Keywords: helpwanted, perf, Whiteboard: EDITORBASE+)

Attachments

(8 files, 3 obsolete files)

User-Agent: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.0.1) Gecko/20020830 Build Identifier: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.0.1) Gecko/20020830 when you input text in composer, url bar or text box, the usage of cpu amount to 70%. you can verify it in windows or linux if you press a char key without lift to input text. This is a big performance problem in many environments. Reproducible: Always Steps to Reproduce: Expected Results: not consume so much cpu time when input text.
Keywords: perf
Priority: -- → P1
Attachment #111037 - Attachment is patch: false
Attachment #111037 - Attachment mime type: text/plain → text/html
Attachment #111037 - Attachment description: jprofile(setenv JPROF_FLAGS "JP_DEFER JP_PERIOD=0.0015" ) → jprofile(setenv JPROF_FLAGS JP_DEFER; setenv JP_PERIOD 0.0015)
So two things jump out at me: 1) 10% of the time is spent in the esd/audiofile system _sound_ libraries. Why? 2) This is reported against 1.0.1; testing with trunk would be much more useful. I know kin landed a bunch of patches for this, then reverted one of them partially, etc.
The very first time a key is pressed, the sound libraries are initialized on Windows, by type ahead find. This is to avoid adding extra startup time. We need the library preloaded, otherwise there is a pause between typing a "not-found" key and the typeaheadfind error sound.
yeah, except this is a profile on _linux_, not windows. And the typing is being done in a textbox, so typeahead find should not be triggering.
Looking at the code, it turns out we do mSoundInterface->Init(); on the first keypress. It doesn't care whether it's a typeaheadfind key. All it's doing is delaying the initialization of the sound system until the first key is pressed, to avoid the increase in startup time
leon, how long did you type for to get that profile? (in that a one-time initialization should not be taking up 7% (10% of 70%) of the CPU for any appreciable length of time)
-->core
Assignee: composer → jfrancis
Component: Editor: Composer → Editor: Core
export JPROF_FLAGS="JP_DEFER" export JP_PERIOD="0.0015" sleep 2 kill -PROF $1 sleep 20 kill -USR1 $1 ./jprof ./mozilla-bin jprof-log > ~/jprof.html
bz: above comments is the test script. I press the key for 20s
Attached file press key about 65s(second jprofile) (deleted) —
sleep 60s in test script
I don't buy the premise. CPU % usage is not an issue. The question is absolute usage. The Jprof log here has no occurances of "editor" in any of the calls. I see /usr/lib/libaudiofile gunk in the places where I would expect to see editor. Jprof is confused. Can someone get a good profile? My guess is that the 10% is actually the editor.
Attachment #111120 - Attachment description: press key about 65s → press key about 65s(second jprofile)
all of the test data is based trunk 20021230.
Ok, I see that the second attachment has a good profile. Here are some notes on it: I'm going to ignore the overall set of 523 samples because I can't read the JProf output well enough to account for all of them. So instead I start with nsWidget::DispatchWindowEvent, which was in the stack 471 times. Of those samples, only 325 make it to nsTextEditorKeyListener::KeyPress, which is the beginning of editor involvement. Of those 325 samples, 199 end up rooted by nsAutoPlaceHolderBatch::~nsAutoPlaceHolderBatch and 125 by nsPlaintextEditor::TypedText. ~nsAutoPlaceHolderBatch is the place in editor where we turn back on layout to handle reflow, and tell the caret to maintain it's state. nsPlaintextEditor::TypedText is the root of where the real work in editor happens. Thus we get: 31% of the time is spent getting the event to the editor 27% of the time is spent in the editor pushing strings and dom changes around 42% of the time is spent in layout/selection/caret code reflecting the new state In previous performance passes through the editor we already did work to try to minimize the number of times we call into layout/selection/caret code, so I'm not sure there are any real wins left there. We could do some caching of recent results in the editor. For instance, there are 15 samples in NodeIsBlockStatic. I bet we are asking about the same node over and over. We might be able to reclaim 10 to 20% of the time in the 125 samples under nsPlaintextEditor::TypedText by doing some caching of results. I was suspicious that we might be spending a lot of time in between typing querying the editor for command enabled status for the editor toolbar, but while I see a significant amount of time spent in nsComposerCommandsUpdater::UpdateCommandGroup (106 samples), I have been unable to track that into editor for any significant time. It looks like the time here might actually be in XUL stuff?
I tested frequency of calling function(nsHTMLEditor::NodeIsBlockStatic). Value below is the number of calling that function before type next character. 51,78,46(if type speed is normal)/14(if type quickly),46/14,46/14,...... if you type very quickly, the first 2 values will change greatly. test env: win2000 + trunk 20021229
maybe this bug should be a meta bug, so that we can resolve it in aother bugs which should be file just to do with one issue.
Severity: major → critical
I make a simple test to functio nsHTMLEditor::NodeIsBlockStatic: just return without running the main body of it. I found there exist not disctinct improvment in the performance. I will make new test to function: nsHTMLEditor::TypedText(const nsAString& aString, PRInt32 aAction).
Changing summary. We need a platform and timing data on how long it takes to type. On my system a debug build does not seem slow to type in text fields or simple documents.
Summary: consume 70% cpu time when input text → typing too slow?
you can verify the severity of this bug esaily if typeing test into the composer without lifting key and open the taskmanager of the window at the same time , you will find that the cpu usage history is always amount to %70 even more. Other big application, such as openofice, cannot consume so many cpu time. my test env: win2000/RH8 + trunk 20030112 I have found a similar bug: http://bugzilla.mozilla.org/show_bug.cgi?id=182150, but guys there don't think that bug is same to this one(the latform of that bug is mac). so i filed this bug.
I don't see how percentage of cpu usage is important. That depends on other factors unrelated to mozilla, such as what else is happening on your machine. The real question is does the typing take too long to happen. So far no has answered that question.
I think 'typing too slow' might not be a good summary for this bug. What we are talking about here is typing in mozilla costs high cpu usage. It might be true that the speed of typing response is still acceptable but mozilla costs more resources to handle typing than the other applications, for example, open office. This bug may not important for the normal desktop but is critical for a server connected with several graphic terminals like SunRay. The result is more serious than just 'typing too slow' on that enviroment. Furthermore, when we talked about cpu usage here, we have tried our best to eliminate unrelated issue that could affect the result. It is a result that can be *always* reproduced .
Summary: typing too slow? → typing quickly causes high cpu usage
lowering severity and futuring unless/until there is poor performance in a consumer environment (ie, not a server).
Severity: critical → minor
Priority: P1 → P4
Target Milestone: --- → Future
In fact, this bug was reported to us by our SunRay consumers.
some complaints from terminal users: >We did some research on the cpu usage of Mozilla and Netscape 7. >The results are rather disappointing. Typing text in Mozilla and >Netscape 7 eats up extreme amounts of cpu cycles. >We tested Mozilla 1.1 and Netscape 7 on a E250. >With one user on Mozilla 1.1 we have: >Slow typing: 10% cpu usage >Normal typing: 20% cpu usage >Bouncing away on the keyboard: 35% cpu usage > >Netscape 7 (based on Mozilla 1.0) is even worse. >We where able to get a 50% load on the cpu by typing (very fast) in the >e-mail program. > >Our experience is that all text input in Mozilla has this problem. >For instance: URL input box, composing e-mail and composing html. > >This is really unnecessary since very fast typing in Staroffice 6 will >only take about 3 percent of the cpu.
Severity: minor → critical
Priority: P4 → P1
Target Milestone: Future → ---
Leon, I don't think you are supposed to undo my milestone/severity/priotity settings. If you think they are wrong make a case for them in the bug.
Severity: critical → minor
Priority: P1 → P4
Target Milestone: --- → Future
I got a new test data from rational quantify: test env: trunk20030112 + sol8 + gcc3.2 tyed text time: > 10minutes becuase the .qv files is about 5M, so I will paste some snapshots here.
Attached image other references(1) (deleted) —
Attachment #112032 - Attachment description: other reference(1) → other references(1)
Attached image other references(2) (deleted) —
To ensure the value of test data, extend the time of typeing text(>10m) and set the default application is composer.
Severity: minor → normal
Additional info: 0) nsHTMLEditor::TypedText((100% -- 82.65% of root)) --> nsEditor::EndPlaceHolderTransaction(79.06% -- 65.34% of root) --> nsPlainTextEditor::TypedText(20.86% -- 17.24% of root) ---------------------------------------------------------------------------- 1) nsEditor::EndPlaceHolderTransaction(100% -- 65.34% of root) --> nsEditor::EndUpdateViewBatch(84.30% -- 55.12% of root) --> nsEditor::ScrollSelectionIntoView(15.66% -- 10.23% of root) 2) nsPlainTextEditor::TypedText(100% -- 17.24% of root) --> nsPlainTextEditor::InsertText(99.93% -- 17.23% of root) --> nsHTMLEditor::Endoperation(46.85% -- 8.07% of root) --> nsHTMLEditorRules::AfterEdit(99.99% -- 8.07% of root) --> nsHTMLEditorRules:: AfterEditInner(94.66 -- 7.64% of root) --> nsHTMLEditRules::RemoveEmptyNodes(35.29% -- 2.70% of root) --> nsTextEditUtils::NodeIsType(39.98% -- 2.46% of root) ...... --> nsHTMLEditRules::PromoteRange(32.49% -- 2.48% of root) --> nsHTMLEditRules::GetPromotedPoint(92.17% --2.29% of root) --> nsHTMLEditorRules::WillDoAction(34.97% -- 6.02% of root) --> nsHTMLEditor::StartOperation(18.06% -- 3.11% of root) ---------------------------------------------------------------------------- 2) nsEditor::EndUpdateViewBatch(100%) --> nsViewManager::EndUpdateViewBatch(52.08% -- 28.70% of root) --> PresShell::EndReflowBatching(30.05% - 16.56% of root) --> nsCaret::SetCaretVisible(10.11% - 23.71% of root) --> nsTypedSlection::EndBatchChanges(7.64% -- 4.21% of root) 3) nsEditor::ScrollSelectionIntoView(100% -- 10.23% of root) --> PresShell::ScrollSelectionIntoView(99.91% -- 10.22% of root) --> nsSelction::ScrollSelectionIntoView(100% -- 10.22% of root) --> nsTypedSelection::ScrollIntoView(99.98% --10.22% of root) --> nsCaret::SetCaretVisible(45.27% -- 23.71% of root) --> nsTypedSelection::ScrollRectIntoView(32.21% -- 3.29% of root) --> nsTypedSelection::GetSelctionRegionRectAndScrollableView(22.40% -- 2.29% of root) ------------------------------------------------------------------------------ 4) nsViewManager::EndUpdateViewBatch(100% -- 28.70% of root) --> nsViewManager::EnableRefresh (100% -- 28.70% of root) --> nsViewManager::Composite(100% -- 28.70% of root) --> nsWindow::Update(100% -- 28.70% of root) 5) PresShell::EndReflowBatching(100% -- 16.56% of root) --> PresShell::FlushPendingNotifications (100% - 16.66% of root) --> PresShell::ProcessReflowCommands ( 100% - 16.66% of root) --> IncrementalReflow::Dispatch (94.71% - 15.91% of root) --> ViepPortFrame::Reflow (95.47% - 15.08% of root) --> nsContainerFrame::ReflowChild (99.60% - 15.02% of root) 6) nsCaret::SetCaretVisible(100% -- 23.71% of root) --> nsCaret::StartBlinking(51.98% -- 12.34% of root) --> nsCaret::DrawCaret(67.24% -- 8.78% of root) -->nsTextFrame::GetPointFromOffset(78.90% -- 9.10% of root) --> nsTextFrame::PrepareUnicodeText (85.10% -- 13.58% of root) --> nsTextTransformer::GetNextWord(76.14% -- 16.37% of root) --> nsTextTransformer::ScanNormalAsciiText_F(99.25% -- 16.25% of root) --> nsCaret::PrimeTimer(32.75% -- 12.34% of root) --> nsCaret::StopBlinking(48.01% --11.39% of root)
67% of the time under the TypedText() call (and 55% overall) is in layout/selection/caret. There are big wins to be had there, but I don't know yet what they are. I suspect there are simple data-space/speed tradeoffs to be had. Of the time in editor proper, I don't think we can reduce our calls into layout (we already turn off layout until we are done with the typed text), but I bet we can avoid a lot of the postprocessing we do if we realize that we can skip it for further typing in the same text node. That currently takes 8% overall, and by avoiding unneeded calcualtions there I bet we can get it down to 1%.
After discussed with jfrancis, have info below: the source of this bug: According to current test data and analysis, this bug mainly is caused by two reasons: 1) Functions in redraw/layout/selection/caret, consumed about 65% of the cpu time of mozilla. These functions finish: redraw window(28.7%), *** reflow process(16.6%), ** scroll selection into view(10.2%) ** selection process(4.2%) * process caret(cusor)(23.7%) *** According to current codes, when user type a character, the char will be inserted into a DOM content node and lead to following actions: (1) Because content tree have changed, so call force reflow process. (2) To ensure the char can be seen, will scroll the window. (3) At same time, window have been redrawn. In addition, Caret have been redrawn again and again(In addition, Caret have been redrawn again and again ( controlled by a timer, its mBlinkRate is about 500ms?, in debug mode, I found it is always 530, even though i changed the initial value of mBlinkRate, why? ). During process above, when user type just one character, will call one time of redrawing window and reflow. 2) Time consumed in editor is about the 14% of the mozilla's cpu time. During this time, create a new Dome node or insert text into an exist node.
In addtion, I am sure there exist an great perf problem in caret module. becuase time consumed in caret is about 23.71% of the whole application. Theres exist an old bug realted to caret perf: http://bugzilla.mozilla.org/show_bug.cgi?id=35296 and another bug may be helpful: http://bugzilla.mozilla.org/show_bug.cgi?id=28068
Depends on: 35296
Depends on: 190239
When I'm typing in a composer window containing a copy of www.mozilla.org, I see that we repaint all the lines of the paragraph in what appear to be separate repaint events (I've turned on paint flashing in Preferences/Debug). That could be a significant source of slowdown. Leon, do you see that? Any chance you could find out why that happens?
Depends on: 190244
hi,robert In current test case, I just typing text without wrap words. I suspect that there may exist bugs in paint, can you list some related functions so that we can count the calling times in current test case?
Whiteboard: EDITORBASE
EDITORBASE+, nsbeta1+ for investigation. Individual bugs should be filed for specific isssues and nominated for EDITORBASE separately.
Keywords: nsbeta1+
Whiteboard: EDITORBASE → EDITORBASE+
Target Milestone: Future → mozilla1.4alpha
Width of composer play an very important role in perf of composer, especailly when words inputed lead to scroll window.
That's because the delays are due to excessive painting and we paint less when the window is smaller. I suspect bug 191474 may help performance in this case. Why don't you try the patch there and tell me if it helps.
Tested the patch (attachment (id=113915)) for bug 191474 in solaris8 + trunk20030212, found that there exist not explict change in ussge of CPU. When type text there, the CPU usage is always almost %36~40%, whether or not the patch have been applyied. Additional info about the width of composer(typed about 500 characters in a line) in windows 2000: width of composer minimized width half of the maximum width maximum width No scroll ??(hard to test) about 19%-22% about 22%~25% scroll 44% ~ 50% about 50%-60% about 63%-72%
Depends on: 194343
QA Contact: sujay → sairuh
Depends on: 174823
Depends on: 195898
Depends on: 199412
Patches for bug 35296 have been checked in, so we have improve perf related to caret about 6% based on newest trunk.
*** Bug 201023 has been marked as a duplicate of this bug. ***
Patch for bug 199412 has been checked in, perf of editor can be improved another about 2% based on current trunk.
Depends on: 204005
Depends on: 28068
Depends on: 205544
Depends on: 204434
1) remove or skip unnessary caret process(including patches for 194343) 2) turn off caret before editing process (including kin's patch for 194343) 3) enhance cache for caret(including patch for 204434)
Attachment #124260 - Attachment is obsolete: true
I made a new test about this bug. Testing env && methods: 1) trunk + quantify + sol8 + gtk1.2 + same profile 2) After type a char which will lead to load libesd.so, then type chars till count of chars amount to 1000. Testing result: Unit: 100,000 cycles trunk trunk trunk 3/26/2003 26/05/2003 26/05/2003 applied last patch .root 15106 13765 11718 TimerTHread:: 756 599 306 Run() nsHTMLEditor:: 11877 11135 9938 TypedText() nsCaret:: 2202 1443 578 SetCaretVisible() nsCaret:: 1273 798 405 DrawCaret()
Depends on: 207469
Depends on: 207936
Depends on: 204493, 208446
Depends on: 212838
Attached patch patch based on mozilla1.4 (deleted) — Splinter Review
Attachment #124337 - Attachment is obsolete: true
*** Bug 194359 has been marked as a duplicate of this bug. ***
Target Milestone: mozilla1.4alpha → ---
Comment on attachment 129214 [details] [diff] [review] patch based on mozilla1.4 Patch is over a year old. It was never submitted for review or superreview. Patch seemed to be finished. Submitting now. Patch will probably be dated, though.
Attachment #129214 - Flags: superreview?(kinmoz)
Attachment #129214 - Flags: review?(mozeditor)
Kin or Simon would have to review this. I don't know enough about the Caret code to address this patch.
Keywords: helpwanted
Depends on: 300797
QA Contact: bugzilla → editor
Assignee: mozeditor → nobody
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: