Closed Bug 1332166 Opened 4 years ago Closed 4 years ago
_copy Text .html | undefined assertion name - got "Formatted Text"/"Xdiv12", expected " some text \n to copy 'n paste "
this bug picked up in frequency on March 7th on linux64-debug in e10s mode. I and doing some retriggers to attempt to pinpoint what caused this to start happening: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&filter-searchStr=clipboard%20linux%20debug%20e10s&tochange=81fd3c22387cac585f2242e28edc1dac9e131d0f&fromchange=8cd9e592cc85ff5f48d65160bf64e7dfc9c8c844&selectedJob=82126099 meanwhile this has occurred 44 times since then and we need to start addressing this. here is a screenshot: https://public-artifacts.taskcluster.net/Dukc-A9PTIWAIqGzTEMdBg/0/public/test_info//mozilla-test-fail-screenshot_h3ubdH.png and related log file: https://public-artifacts.taskcluster.net/Dukc-A9PTIWAIqGzTEMdBg/0/public/logs/live_backing.log here is a clip from the log file: [task 2017-03-07T12:33:37.278382Z] 12:33:37 INFO - TEST-START | dom/plugins/test/mochitest/test_copyText.html [task 2017-03-07T12:33:37.334780Z] 12:33:37 INFO - ++DOMWINDOW == 14 (0x7eff2ae7c000) [pid = 7574] [serial = 106] [outer = 0x7eff29f63800] [task 2017-03-07T12:33:37.411094Z] 12:33:37 INFO - For application/x-test found plugin libnptest.so [task 2017-03-07T12:33:37.487690Z] 12:33:37 INFO - TEST-INFO | started process screentopng [task 2017-03-07T12:33:37.852799Z] 12:33:37 INFO - TEST-INFO | screentopng: exit 0 [task 2017-03-07T12:33:37.853162Z] 12:33:37 INFO - TEST-UNEXPECTED-FAIL | dom/plugins/test/mochitest/test_copyText.html | undefined assertion name - got "Formatted Text", expected " some text \n to copy 'n paste " [task 2017-03-07T12:33:37.853356Z] 12:33:37 INFO - SimpleTest.is@SimpleTest/SimpleTest.js:310:5 [task 2017-03-07T12:33:37.853548Z] 12:33:37 INFO - runTests@dom/plugins/test/mochitest/test_copyText.html:19:3 [task 2017-03-07T12:33:37.853746Z] 12:33:37 INFO - onload@dom/plugins/test/mochitest/test_copyText.html:1:1 [task 2017-03-07T12:33:37.854145Z] 12:33:37 INFO - MEMORY STAT | vsize 1649MB | residentFast 112MB | heapAllocated 23MB [task 2017-03-07T12:33:37.854473Z] 12:33:37 INFO - TEST-OK | dom/plugins/test/mochitest/test_copyText.html | took 303ms not very helpful from my eyes, possible others can get useful data form this? here is the source file: https://dxr.mozilla.org/mozilla-central/source/dom/plugins/test/mochitest/test_copyText.html I am not sure where we would write "formatted text", I did fine another test in dom/events that sets the text: https://dxr.mozilla.org/mozilla-central/source/dom/events/test/test_bug1327798.html#38 which runs about 90 seconds before the failing test does, but we do shutdown the browser and recreate a new profile, so I am slightly confused how that could contribute to this. :bsmedberg, can you find someone to look into this? At the current failure rate we will be very anxious to get this resolved in the next week or two.
Whiteboard: [stockwell needswork]
So I don't know why this is happening, but what this test does is: a. put some text in the clipboard using the DOM b. get some text out of the clipboard using the plugin and GTK. The comments around this code say that this triggers a nested event loop (intentionally, that's somehow the point of the test). If step a) fails (or is racy/incomplete) then step b) will print whatever was in the X clipboard before, which easily could be from the previous test even after a Firefox restart. Things to look for in a regression range: IPC changes, plugin changes, GTK changes, or e10s config changes. I can't find somebody to look at this without a regression range. Is it narrowed down to at least a day (nightly->nightly)?
Flags: needinfo?(benjamin) → needinfo?(jmaher)
good point about using something random from the clipboard from a previous test/browser-session. I am still retriggering and will update this with a tighter regression range- leaving ni? until that happens.
after doing some retriggers: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&filter-searchStr=clipboard%20linux%20debug%20e10s%20x64&tochange=81fd3c22387cac585f2242e28edc1dac9e131d0f&fromchange=bfe78e7db8fd08053642798a33dcf54fba1580c9 one push seems to be the culprit for the spike in failures: https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?changeset=fde4cd0aed6d :ehsan, I see you are the author of both patches, can you take a look at this next week?
Flags: needinfo?(jmaher) → needinfo?(ehsan)
Summary: Intermittent dom/plugins/test/mochitest/test_copyText.html | undefined assertion name - got "Xdiv12", expected " some text \n to copy 'n paste " → Intermittent dom/plugins/test/mochitest/test_copyText.html | undefined assertion name - got "Formatted Text"/"Xdiv12", expected " some text \n to copy 'n paste "
(In reply to Joel Maher ( :jmaher) from comment #6) > after doing some retriggers: > https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&filter- > searchStr=clipboard%20linux%20debug%20e10s%20x64&tochange=81fd3c22387cac585f2 > 242e28edc1dac9e131d0f&fromchange=bfe78e7db8fd08053642798a33dcf54fba1580c9 > > one push seems to be the culprit for the spike in failures: > https://hg.mozilla.org/integration/mozilla-inbound/ > pushloghtml?changeset=fde4cd0aed6d > > :ehsan, I see you are the author of both patches, can you take a look at > this next week? I can prove this one isn't my fault! https://hg.mozilla.org/integration/mozilla-inbound/rev/fde4cd0aed6d only affects xpcshell tests, which this one isn't. https://hg.mozilla.org/integration/mozilla-inbound/rev/8086f1e5317b fixes a leak in an xpcshell test, which doesn't even run in this test suite. There should be something wrong with the regression range. :-)
I am doing more retriggers, but reviewing the original data I still believe my original assertion is correct. stay tuned when these are completed: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&filter-searchStr=clipboard%20linux%20debug%20e10s%20x64&tochange=2e025eb770e85de558fb72825539903b3e049172&fromchange=5a1812fe02163bbed19319621f30f95606c398b3&selectedJob=83119827
I stand corrected, more retriggers shows the commit prior is the root cause: https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?changeset=5a64d16d18e5 :mystor, this looks to start with your push, could you take a look at this?
I'm mildly surprised this ever worked. Setting/reading the clipboard is async on some platforms, so we have a helper method for waiting for the updates to propagate around. I'm now waiting for that before I ask the plugin for clipboard data. Hopefully this fixes the intermittent issue. MozReview-Commit-ID: Ea6jZCYjuaY
Attachment #8847186 - Flags: review?(enndeakin)
Assignee: nobody → michael
Pushed by firstname.lastname@example.org: https://hg.mozilla.org/integration/mozilla-inbound/rev/c7d1e31935ce Wait for the clipboard to be updated before checking it, r=enndeakin
Whiteboard: [stockwell needswork] → [stockwell fixed]
You need to log in before you can comment on or make changes to this bug.