Closed Bug 1136351 Opened 9 years ago Closed 7 years ago

Intermittent talos xperf mainthreadio | File {something} was accessed and we were not expecting it

Categories

(Testing :: Talos, defect)

x86
Windows 7
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED WORKSFORME

People

(Reporter: jmaher, Unassigned)

Details

(Keywords: intermittent-failure)

      No description provided.
Summary: xperf talos intermittent errors → Intermittent talos xperf mainthreadio | File {something} was accessed and we were not expecting it
Whiteboard: intermittent-failure
seems more and more failing
Flags: needinfo?(jmaher)
The dwrite.dll.mui regression is from gfritzsche's big Telemetry/FHR landing on fx-team.
https://treeherder.mozilla.org/#/jobs?repo=fx-team&filter-searchStr=xperf&fromchange=92c65f60614a&tochange=b83c3fa8c80f
Flags: needinfo?(gfritzsche)
This is probably triggered from the environment data collection here:
https://hg.mozilla.org/mozilla-central/annotate/df3daecd381f/toolkit/components/telemetry/TelemetryEnvironment.jsm#l636

What is this measuring?
This shouldn't happen often, but we want to access graphics info there.
Normally that shouldn't happen quickly after startup or something, but rather on important pref changes, addons going active/inactive or on shutdown.
Flags: needinfo?(gfritzsche)
so dwrite is being used and it wasn't before.  This means that it has >1ms of access on the mainthread during startup.  We can bump up the allowed time to 30ms if we feel that this is the right behavior.

adding vladan, aklotz to weigh in if this is something we should fix in talos or in the code accessing telemetry.
Flags: needinfo?(vdjeric)
Flags: needinfo?(jmaher)
Flags: needinfo?(aklotz)
Ok, if we didn't hit it before we should understand why we do now.
The only likely code in the push (linked above) collects information from "@mozilla.org/gfx/info;1".
I am opposed to adjusting talos to compensate for this change. I think we should get a handle on what's going on with nsGfxInfo and either deal with it there or look into how we're accessing it from JS.
Flags: needinfo?(aklotz)
Filed bug 1137404 for the dwrite errors.
Flags: needinfo?(vdjeric)
Any idea what these recent warnings are about?
Flags: needinfo?(jmaher)
great question vladan.  There are 2 recent issues here- these are sort of a bug list of things which are already annotated in the whitelist.  It seems there is a bug in the code which causes us to miss a lot of data.  As far as I know this is the last issue which I believe is rare (1/week).  With a bit more data I might be able to focus on it :)
Flags: needinfo?(jmaher)
> File 'c:\program files\vim\vim73\gvim.exe'
> File '{appdata}\roaming\microsoft\windows\start menu'
> File '{desktop}.ini'
> File '{profile}\jumplistcache\rcmfdvlcss6n0xab1vmbwg==.ico'
> File '{appdata}\roaming\microsoft\internet explorer\quick launch'

Is someone logging into the machine while it's running? Or is it launching an external viewer?
Hrm, all of these from today have that bit about connections to snippets.cdn.mozilla.net...
Joel: It looks like this is a new, persistent main-thread-IO regression? is there a bug for it?

(In reply to Treeherder Robot from comment #146)
> log:
> https://treeherder.mozilla.org/logviewer.html#?repo=fx-team&job_id=3393740
> repository: fx-team
> start_time: 2015-06-10T05:05:08
> who: tomcat[at]mozilla[dot]com
> machine: t-w732-ix-159
> buildname: Windows 7 32-bit fx-team talos xperf
> revision: 0d6ee6e7ff2a
> 
> FATAL ERROR: Non-local network connections are disabled and a connection
> attempt to snippets.cdn.mozilla.net (93.184.215.191) was made.
> TEST-UNEXPECTED-FAIL | mainthreadio | File '{xre}\dictionaries' was accessed
> and we were not expecting it: {'Count': 1, 'Duration': 0.066431, 'RunCount':
> 1}
> TEST-UNEXPECTED-FAIL | mainthreadio | File '{xre}\dictionaries\en-us.aff'
> was accessed and we were not expecting it: {'Count': 1, 'Duration':
> 0.040703, 'RunCount': 1}
> TEST-UNEXPECTED-FAIL | mainthreadio | File '{xre}\browser\dictionaries' was
> accessed and we were not expecting it: {'Count': 1, 'Duration': 0.027264,
> 'RunCount': 1}
> TEST-UNEXPECTED-FAIL : xperf: File '{profile}\extensions.json' was accessed
> and we were not expecting it.  DiskReadCount: 4, DiskWriteCount: 0,
> DiskReadBytes: 32768, DiskWriteBytes: 0
> PROCESS-CRASH | tp5n | application crashed [@
> nsSocketTransport::InitiateSocket()]
> 0x77020000 -DEBUG : unknown error during cleanup: Traceback (most recent
> call last):
> Return code: 1
> # TBPL WARNING #
Flags: needinfo?(jmaher)
we backed out the changes yesterday and we are green again on xperf.  I emailed dtownsend and aklotz prior to backing out.
Flags: needinfo?(jmaher)
with 15+ months of no instances, I am marking this as resolved.
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.