Open Bug 75001 Opened 23 years ago Updated 2 years ago

Too many calls to PR_Now in HTMLContentSink::IsTimeToNotify

Categories

(Core :: DOM: HTML Parser, defect)

defect

Tracking

()

People

(Reporter: bratell, Unassigned)

References

()

Details

(Keywords: perf)

Attachments

(1 obsolete file)

When looking at quantify outputs, one thing I noticed with the jdk index page at 
http://www.javasoft.com/j2se/1.3/docs/api/index-files/index-7.html is the cost 
of HTMLContentSink::IsTimeToNotify. Just that function (which should not be 
visible at all) has 2.5% of the total time.

The reason for this is that it's called 64000 times, causing 64000 calls to 
PR_Now which is a function that costs a little. Another slow page, the colour 
table stresscase gets 60000 calls to IsTimeToNotify, but that only results in 
412 calls to PR_Now making it much cheaper. It should be the same for the JDK 
index.

Calling PR_Now 64000 times is like calling it once every ms, which is a little 
ridiculous.
Blocks: 56854
Keywords: perf
More info: HTMLContentSink::IsTimeToNotify is called from DidAddContent which is 
called from FlushText (33000 times) and CloseContainer (31000 times). I would 
reckon that maybe it's not necessary to call it if the diff since last time is 
very small, like a closed <a> or a short added text.

Alternatively, maybe we should make PR_Now faster. All it does now is to call 
ftime. Maybe that's not necessary.
If we need to do so many checks for the time we should (on Windows) use
timeGetTime instead of ftime. timeGetTime is 3-4 times as fast and gives the
necessary information since we only want to now how long time has passed since
last notify.

I just checked NSPR and it seems as if the function PRIntervalTime() is using
timeGetTime sometimes. It could be worth a test to switch to that.
No, PRIntervalTime is no good choice. It uses QueryPerrfomanceCounter normally
and only timeGetTime as a fallback. Why QueryPerfomanceCounter is bad can be
seen from this table:

Function                       Time in us
==========================================
timeGetTime                        209
ftime                              809
QueryPerfomanceCounter            4205

So, either we need a new function in NSPR or reduce the number of calls if we
want to make this better.
HTMLContentSink::IsTimeToNotify => reassigned to Parser/harishd (but maybe it 
should go to Nisheeth)
Assignee: karnaze → harishd
Component: Layout → Parser
QA Contact: petersen → bsharma
(Just a reminder to self: Another possible time function on win32 is 
GetSystemTimeAsFileTime which returns time in 100 ns chunks. It is the function 
used by ftime)
Nisheeth, could you please take a look at this. Thanx.
Assignee: harishd → nisheeth
Daniel, I am reassigning this to you. You seem to be able to figure out what is
the best fix. If you need help in actual fix or checkin, let me know.
Assignee: nisheeth → bratell
QA Contact: bsharma → moied
Any news on that one?
The problem is still there. HTMLContentSink::IsTimeToNotify calls PR_Now 63576 
times on the test page for a total of 3% of the layout time.

According to the NSPR docs, the right thing to do would be to use PR_IntervalNow 
but that function is even slower (bug 124695). Another idea would be to use some 
timer that sets some signal flag when fired and just look at that flag. That 
would probably be better than polling the clock.

Hmm. HTMLContentSink::DidProcessAToken has also started (mis)using time calls 
(bug 124697) for a total of 5% of the page load time.
Depends on: 124695
Daniel, in your comment #2, you said timeGetTime is much faster than ftime.
why not modify ntmisc.c, change PR_Time's implementation from ftime to 
timeGetTime(), does it make sense?


http://lxr.mozilla.org/mozilla/source/nsprpub/pr/src/md/windows/ntmisc.c#85
I don't have access to all the necessary docs right now, but as I recall it 
timeGetTime has the necessary precision for the parser, but the parser uses 
PR_Now which, by the NSPR documentation, should have a minimum precision that 
timeGetTime can't get.

I think we would need another NSPR function |PR_Approximately_Now| that would 
be enough for this and other uses where we don't need millisecond precision.
when I check the source code,I think I get it.

int nsresult SinkContext::CloseContainer() function, 
it will call FlushTextAndRelease() ,
FlushTextAndRelease() will call FlushText(),
FlushText() will do something like create content object, then call 
SinkContext::DidAddContent().

after FlushTextAndRelease(), CloseContainer() will call DidAddContent() again.
that is why mozilla will call PR_Now() so many times.

So I think we should remove one DidAddContent().

add jkeiser to cc list
Hope he can take an look.
DidAddContent() needs to be called for more than one piece of content in the
case you're talking about.  Once for the text node and once for the container
that's being closed.

As for fixing the problem, it seems to me that IsTimeToNotify() logic is just
simulating a timer (badly).  Why not just make it one?
Attachment #77011 - Attachment is obsolete: true
jkeiser is right,DidAddContent is called twice in CloseContainer(), 
one is for text content, another is for container.
so mark my patch as obsolete.

Some more info: the only reason IsTimeToNotify is called is to flush.  The flush
can safely be placed on a timer.  Just look at the only place it is called, you
can see all it does is FlushTags().
Depends on: 144072
John, do you want this bug? Looks like you've already started on it. Feel free
to grab it in that case.
OS: Windows 2000 → All
Hardware: PC → All
Any further findings in the meantime?
A timer may not work because to fire a timer you have to go out to the event
loop.. which means you need to interrupt parsing.

Then again, you need to do that to paint too.  So perhaps there will be no
perceptible change....
Blocks: 254526
Depends on: 58310
Blocks: 203448
QA Contact: moied → parser
We could fix this by migrating the XML side to use nsHtml5TreeOpExecutor, too.
I wonder if TimeStamp::NowLoRes might be an acceptable compromise?

The bug assignee didn't login in Bugzilla in the last 7 months, so the assignee is being reset.

Assignee: bratell → 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: