Steps To Reproduce: 1. Make sure a lot of history (attachment if necessary) 2. Open Library(ctrl+shift+h) or Sidebar(ctrl+h) 3. Click "Today", "November 2013", "October 2013", "Older than 6 months" in left tree by order Actual Results: It takes a lot of time than before(Firefox28beta) Regression window(m-i): Good: http://hg.mozilla.org/integration/mozilla-inbound/rev/dffbfd00ac4e Mozilla/5.0 (Windows NT 6.1; WOW64; rv:29.0) Gecko/20100101 Firefox/29.0 ID:20140131185210 Bad: http://hg.mozilla.org/integration/mozilla-inbound/rev/6199eb8d2f3e Mozilla/5.0 (Windows NT 6.1; WOW64; rv:29.0) Gecko/20100101 Firefox/29.0 ID:20140131191643 Pushlog: http://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=dffbfd00ac4e&tochange=6199eb8d2f3e Regressed by Bug 902587

Aurora29.0a2 is not affected. Maybe, '--enable-profiling' triggers the problem.

(In reply to Alice0775 White from comment #1) > Maybe, '--enable-profiling' triggers the problem. Pls ignore the above sentence.

On local build Last Good: 61a591c422b7 First Bad: de11fdd37b20 Triggered by de11fdd37b20 Aaron Klotz — Bug 902587 - Part 3: IO Interpose Reporter for Telemetry; r=froydnj

Is the I/O telemetry stuff making I/O slower?

well, if it's intercepting write calls to system libs and doing something on each call, and we do thousands of calls I suppose the overhead may become interesting. If Observe is the main method invoked every time (https://bugzilla.mozilla.org/page.cgi?id=splinter.html&bug=902587&attachment=8369009) it seems to be doing a lot of strings manipulation... Maybe as a beginning that should be enabled only in Nightly, but still...

Curious; Main thread I/O *is* only enabled in Nightly.

Well, that reduces a lot impact and priority of the issue. Still, the overhead here should be investigated and reduced.

That's consistent with comment 1, right? So not so curious :) Do we have plans to enable it for non-Nightly?

(In reply to :Gavin Sharp (email gavin@gavinsharp.com) from comment #8) > That's consistent with comment 1, right? So not so curious :) But inconsistent with comment 2 ;) > > Do we have plans to enable it for non-Nightly? Bug 966496, once bugs like this one get ironed out.

> But inconsistent with comment 2 ;) Er, how so?

I think he meant comment 7, I suggested it to be enabled only in Nightly, I didn't have a clue it was already, sorry.

ehr comment 5...

Sorry, I was thinking about the "--enable-profiling" part, not the "Aurora29.0a2 is not affected" part. *Sigh* Mondays. Never mind that :-) Anyway, there are some efficiencies to be had with the string stuff in there. Bug 972577 will also improve things when the profiler is turned on.

aklotz, is likely more up-to-date than me, but I recall two concerns that could cause this: A) While reporting an I/O observation all other I/O operations are blocked from being reported due to a global lock on the list of observers: http://dxr.mozilla.org/mozilla-central/source/tools/profiler/IOInterposer.cpp#169 B) All main-thread I/O reports for telemetry calls Observation::Filename() which looks up the filename from the file handle. Mitigation: A) Could be mitigated by a shared read-only lock as suggested in bug 913653, I note for the record that the tests carried out in bug 913653 assumes a different method for resolving filenames from file handles. See bug 902587#c50 for details on the alternatives I tested. Current implementation uses `CreateFileMapping` which I never tested. B) Could be mitigated by a file handle to filename cache in PoisonIOInterposerWin.cpp. You would have to clear the cache when file handles are closed by interposing NtClose. And as suggested above, alternative methods for resolving filenames from file handles could be tested, but even a small cache would probably go far. If I recall correctly I had lots of hits with a cache size of 50.

(A) This is probably the bigger issue with respect to storage I/O. I am planning to completely eliminate the need to take that lock during IOInterposer observer callouts. (B) I have previously measured the cost of the handle to filename mapping and it is not significant enough to be the cause of user-observable delays. I'm not saying that a cache wouldn't help at all, but I think that there is much lower hanging fruit.

This is a Nightly-only issue until bug 966496 is fixed, so no need to track.