Closed Bug 1451284 Opened 7 years ago Closed 6 years ago

ServiceWorkerTarget.js is shown as uncovered even though it is covered

Categories

(Testing :: Code Coverage, defect)

defect
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: marco, Unassigned)

References

(Blocks 1 open bug)

Details

Attachments

(2 files)

I've tried to run the devtools/client/aboutdebugging/test/browser_service_workers tests locally, and ServiceWorkerTarget.js is covered in the report. I'm attaching the report generated locally (JS_CODE_COVERAGE_OUTPUT_DIR=~/tmp/ ./mach test devtools/client/aboutdebugging/test/browser_service_workers). On CI, those tests were run in dt7 (https://treeherder.mozilla.org/logviewer.html#?job_id=171685532&repo=mozilla-central), but ServiceWorkerTarget.js is not covered in the report. I'm attaching the report generated on CI. I'm not sure why there's an incongruity between local and CI results.
Attached file local_extract.info (deleted) —
Attached file ci_extract.info (deleted) —
I've triggered a try build that compresses the original JSVM info files without rewriting them using the lcov rewriter. The result is the same, so we can rule out the lcov rewriter.
Both in the local run and in the CI run, the records containing ServiceWorkerTarget.js are generated by the parent process.
Blocks: js-code-coverage
No longer blocks: code-coverage

As discussed today, we have identified that some methods are marked as covered when a test runs in isolation, but will be flagged as uncovered when running in a suite.

I tried to reduce the test case as much as possible. I pushed the test case to try at https://hg.mozilla.org/try/rev/09fbb0c091fa4306987317917a7d580b5c866813. The setup is still a bit complicated, simplifying more than that I no longer get any coverage. I can explain the devtools specific bits if needed.

STRs:

  • run hg pull -r 09fbb0c091fa4306987317917a7d580b5c866813 https://hg.mozilla.org/try
  • update to this revision
  • build
  • run JS_CODE_COVERAGE_OUTPUT_DIR=~/tmp/ ./mach test devtools/client/aboutdebugging-new/test/browser/
  • look for methodInModule in the coverage results, it should not be considered as covered, even though it is called in the third test browser_aboutdebugging_3.js

If you run the third test only, the method will be covered.
If you comment out the line in browser_aboutdebugging_2.js that forces to load some-module.js and run the whole suite, the method will be covered.

So running two tests with one test that loads the script without using it, and another test that loads the script and uses it seems to confuse the coverage.

(ni just to let you know that the test case is available :) )

Flags: needinfo?(mcastelluccio)

I was trying to reproduce, but the tests are failing with:

devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_1.js
FAIL head.js import threw an exception - Error opening input stream (invalid filename?): chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js
FAIL Uncaught exception - at chrome://mochitests/content/browser/devtools/client/aboutdebugging-new/test/browser/head.js:19 - ReferenceError: pushPref is not defined

Flags: needinfo?(mcastelluccio) → needinfo?(jdescottes)

Ah sorry I forgot some mandatory imports in the browser.ini. They must have been cached when I was testing

diff --git a/devtools/client/aboutdebugging-new/test/browser/browser.ini b/devtools/client/aboutdebugging-new/test/browser/browser.ini
--- a/devtools/client/aboutdebugging-new/test/browser/browser.ini
+++ b/devtools/client/aboutdebugging-new/test/browser/browser.ini
@@ -1,9 +1,11 @@
 [DEFAULT]
 tags = devtools
 subsuite = devtools
 support-files =
   head.js
+  !/devtools/client/shared/test/telemetry-test-helpers.js
+  !/devtools/client/shared/test/shared-head.js
 
 [browser_aboutdebugging_1.js]
 [browser_aboutdebugging_2.js]
 [browser_aboutdebugging_3.js]


Flags: needinfo?(jdescottes)

It looks like we have a script that is not "complete". If I disable the completeness check at https://searchfox.org/mozilla-central/rev/78e8de968efd77ef3b30ea081bce07614cd6776b/js/src/vm/CodeCoverage.cpp#554, I get two SF entries in two info files:

1548004835-8470-46.info-SF:resource://devtools/client/aboutdebugging-new/some-module.js
1548004835-8470-46.info-FN:1,top-level
1548004835-8470-46.info:FN:3,exports.methodInModule
1548004835-8470-46.info-FNDA:1,top-level
1548004835-8470-46.info-FNF:2
1548004835-8470-46.info-FNH:1
1548004835-8470-46.info-BRF:0
1548004835-8470-46.info-BRH:0
1548004835-8470-46.info-DA:3,1
1548004835-8470-46.info-DA:4,0
1548004835-8470-46.info-LF:2
1548004835-8470-46.info-LH:1
1548004835-8470-46.info-end_of_record

1548004835-8470-47.info-SF:resource://devtools/client/aboutdebugging-new/some-module.js
1548004835-8470-47.info:FN:3,exports.methodInModule
1548004835-8470-47.info:FNDA:1,exports.methodInModule
1548004835-8470-47.info-FNF:1
1548004835-8470-47.info-FNH:1
1548004835-8470-47.info-BRF:0
1548004835-8470-47.info-BRH:0
1548004835-8470-47.info-DA:4,1
1548004835-8470-47.info-LF:1
1548004835-8470-47.info-LH:1
1548004835-8470-47.info-end_of_record

They are in two different runtimes.

With the completeness checks enabled, I only get the first SF entry, and so methodInModule is wrongly marked as uncovered.

Adding some logging, I've noticed that the script is loaded in two realms, realm A and realm B. In realm A we have both the script for the top-level (with script counts) and the script for methodInModule (without script counts). In realm B we only have the script for methodInModule (with script counts), so we never write it out to an INFO file because the LcovScript has no top-level.
The order of finalization is 1) top-level from realm A, 2) methodInModule from realm B, 3) methodInModule from realm A.

Any idea why we don't have a top-level in realm B? Or is this a normal situation and we should just disable the completeness check?

This is probably the same issue as bug 1505136.

Flags: needinfo?(nicolas.b.pierron)

In case you want to pull the patch to test locally, here's the updated version with the fix from comment 8:
https://hg.mozilla.org/try/rev/a95cf13ac741ce7750fd1517b60d252064649fa0

hg pull -r a95cf13ac741ce7750fd1517b60d252064649fa0 https://hg.mozilla.org/try

(In reply to Marco Castelluccio [:marco] from comment #9)

Any idea why we don't have a top-level in realm B? Or is this a normal situation and we should just disable the completeness check?

My blind guess would be that we are somehow cloning/duplicating a function into another realm, and as such do not find the corresponding script.

However, I am not sure we can guarantee the garbage collection order across realm. The reason for the top-level check is to ensure that we can find a filename which is still valid on the SourceObject. AFAIK, going across realm would not provide this guarantee.

Ted, do you know if we copy JSScript/JSFunction across realms for modules such as resource://devtools/client/aboutdebugging-new/some-module.js?
Jon, is that correct that we cannot assume any order for the source object across realms? If so, I wonder how do we report error messages which depends on file locations?

Flags: needinfo?(tcampbell)
Flags: needinfo?(nicolas.b.pierron)
Flags: needinfo?(jcoppeard)

(In reply to Nicolas B. Pierron [:nbp] from comment #11)

Jon, is that correct that we cannot assume any order for the source object across realms? If so, I wonder how do we report error messages which depends on file locations?

All realms in a zone are collected at the same time. If there's no CCW between things in separate zones then no finalization order can be assumed. CCWs to things in other zones keep the target alive obviously.

I'm not sure exactly how this works script source objects store a wrapper to the canonical (original) object when cloned, so maybe that's how we get the filename.

Flags: needinfo?(jcoppeard)

I still need to dig into this sometime this week, but here are a few related changes that have occurred in last few months.

  • Bug 1427860 (Dec 2018) fixed handling of partially-initialized cached system scripts under lcov.
  • Bug 1512509 (Oct 2018) changed how ScriptSourceObject cloning worked.

Ted, any news?

I don't have any particular ideas here. I tried to reproduce the steps in Comment 5 and even with the completeness checks removed, I only see one result.

I also see a lot of warnings about: |Warning: LCovRuntime::init: Cannot open file named '/home/tcampbell/tmp/1549310929-7881-0.info'|. I tried to disable the sandbox and still get the same file warning.

One thing to note is that I've been trying this under xvfb-run (which I think is what many of the automation tests are doing?). I'll do a quick check tomorrow on a local machine and see if anything different happens.

My thoughts are that we should capture in rr, then trace back to where the JSScript is coming from.

Flags: needinfo?(tcampbell)

I also see a lot of warnings about: |Warning: LCovRuntime::init: Cannot open file named '/home/tcampbell/tmp/1549310929-7881-0.info'|. I tried to disable the sandbox and still get the same file warning.

This looks like a sign that the sandbox is enabled. I had the same warning when I was using an artifact build, but it disappeared when I built with the sandbox disabled.
I also have "ac_add_options --enable-debug" and "ac_add_options --enable-coverage" in my mozconfig.

I fixed my sandbox issues (I had changed the wrong platform pref. oops!)

I've looked into this and it seems related to the StartupCache. If I disable the cache (--disable-startupcache) I seem to get what I think are the expected results. Can you verify if this is what you expect? The caching might explain the difference between automation and local if things are run multiple times and would explaining interactions of different tests in a suite.

If it is startupcache related I can take in my backlog. Let me know if disabling the startup cache is not an acceptable workaround for the next few weeks.

Depends on: 1525505

I've filed Bug 1525505 which should fix the root cause in XDRScript.

(In reply to Ted Campbell [:tcampbell] from comment #17)

I've looked into this and it seems related to the StartupCache. If I disable the cache (--disable-startupcache) I seem to get what I think are the expected results. Can you verify if this is what you expect? The caching might explain the difference between automation and local if things are run multiple times and would explaining interactions of different tests in a suite.

Yes, if I disable the StartupCache things seem to be working fine, at least for this test.

If it is startupcache related I can take in my backlog. Let me know if disabling the startup cache is not an acceptable workaround for the next few weeks.

Is bug 1525505 fixing this problem? If it is, maybe it's going to be less than a few weeks? If so, we can wait :)

Yes, Bug 1525505 will fix the specific problem in this bug and should land soon. Got lucky in the investigation.

Quickly checked the last report on https://codecov.io/gh/mozilla/gecko-dev/src/master/devtools, and it looks like the issue is fixed for the DevTools files I was looking at! Thanks a lot!

So, FIXED by bug 1525505.

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: