Closed Bug 1517538 Opened 7 years ago Closed 3 years ago

Intermittent Wd | <random> - setup error (Bad canary value 0x534dc0f5 in FromData)

Categories

(Remote Protocol :: Marionette, defect, P5)

Version 3
x86
Windows 7
defect

Tracking

(firefox66 affected, firefox67 affected)

RESOLVED WORKSFORME
Tracking Status
firefox66 --- affected
firefox67 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: crash, intermittent-failure)

Filed by: archaeopteryx [at] coole-files.de https://treeherder.mozilla.org/logviewer.html#?job_id=219517171&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/eIb_A6NhQIeCzw5wp678Ww/runs/0/artifacts/public/logs/live_backing.log 21:13:27 INFO - STDOUT: > _current_session.start() 21:13:27 INFO - STDOUT: capabilities = {} 21:13:27 INFO - STDOUT: caps = {'alwaysMatch': {'moz:firefoxOptions': {'binary': 'Z:\task_1546376327\build\application\firefox\firefox.exe', 'prefs':...w1.not-web-platform.test,www.not-web-platform.test,www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test'}}}} 21:13:27 INFO - STDOUT: configuration = {'capabilities': {'moz:firefoxOptions': {'binary': 'Z:\task_1546376327\build\application\firefox\firefox.exe', 'prefs'...b-platform.test,www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test'}}}, 'host': '127.0.0.1', 'port': 4444} 21:13:27 INFO - STDOUT: request = <SubRequest 'session' for <Function 'test_null_response_value'>> 21:13:27 INFO - STDOUT: tests\web-platform\tests\webdriver\tests\support\fixtures.py 21:13:27 INFO - STDOUT: :150: 21:13:27 INFO - STDOUT: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 21:13:27 INFO - STDOUT: tests\web-platform\tests\tools\webdriver\webdriver\client.py 21:13:27 INFO - STDOUT: :421: in start 21:13:27 INFO - STDOUT: value = self.send_command("POST", "session", body=body) 21:13:27 INFO - STDOUT: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 21:13:27 INFO - STDOUT: self = <Session (disconnected)>, method = 'POST', url = 'session' 21:13:27 INFO - STDOUT: body = {'capabilities': {'alwaysMatch': {'moz:firefoxOptions': {'binary': 'Z:\task_1546376327\build\application\firefox\firef...1.not-web-platform.test,www.not-web-platform.test,www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test'}}}}} 21:13:27 INFO - STDOUT: def send_command(self, method, url, body=None): 21:13:27 INFO - STDOUT: """ 21:13:27 INFO - STDOUT: Send a command to the remote end and validate its success. 21:13:27 INFO - STDOUT: 21:13:27 INFO - STDOUT: :param method: HTTP method to use in request. 21:13:27 INFO - STDOUT: :param uri: "Command part" of the HTTP request URL, 21:13:27 INFO - STDOUT: e.g. `window/rect`. 21:13:27 INFO - STDOUT: :param body: Optional body of the HTTP request. 21:13:27 INFO - STDOUT: 21:13:27 INFO - STDOUT: :return: `None` if the HTTP response body was empty, otherwise 21:13:27 INFO - STDOUT: the `value` field returned after parsing the response 21:13:27 INFO - STDOUT: body as JSON. 21:13:27 INFO - STDOUT: 21:13:27 INFO - STDOUT: :raises error.WebDriverException: If the remote end returns 21:13:27 INFO - STDOUT: an error. 21:13:27 INFO - STDOUT: :raises ValueError: If the response body does not contain a 21:13:27 INFO - STDOUT: `value` key. 21:13:27 INFO - STDOUT: """ 21:13:27 INFO - STDOUT: response = self.transport.send( 21:13:27 INFO - STDOUT: method, url, body, 21:13:27 INFO - STDOUT: encoder=protocol.Encoder, decoder=protocol.Decoder, 21:13:27 INFO - STDOUT: session=self) 21:13:27 INFO - STDOUT: 21:13:27 INFO - STDOUT: if response.status != 200: 21:13:27 INFO - STDOUT: err = error.from_response(response) 21:13:27 INFO - STDOUT: 21:13:27 INFO - STDOUT: if isinstance(err, error.InvalidSessionIdException): 21:13:27 INFO - STDOUT: # The driver could have already been deleted the session. 21:13:27 INFO - STDOUT: self.session_id = None 21:13:27 INFO - STDOUT: 21:13:27 INFO - STDOUT: > raise err 21:13:27 INFO - STDOUT: E UnknownErrorException: unknown error (500): permission denied 21:13:27 INFO - STDOUT: body = {'capabilities': {'alwaysMatch': {'moz:firefoxOptions': {'binary': 'Z:\task_1546376327\build\application\firefox\firef...1.not-web-platform.test,www.not-web-platform.test,www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test'}}}}} 21:13:27 INFO - STDOUT: err = <UnknownErrorException http_status=500> 21:13:27 INFO - STDOUT: method = 'POST' 21:13:27 INFO - STDOUT: response = <Response status=500 error=<UnknownErrorException http_status=500>> 21:13:27 INFO - STDOUT: self = <Session (disconnected)> 21:13:27 INFO - STDOUT: url = 'session' 21:13:27 INFO - STDOUT: tests\web-platform\tests\tools\webdriver\webdriver\client.py 21:13:27 INFO - STDOUT: :472: UnknownErrorException 21:13:27 INFO - STDOUT: ============================== warnings summary =============================== 21:13:27 INFO - STDOUT: <undetermined location> 21:13:27 INFO - STDOUT: Module already imported so cannot be rewritten: mozlog 21:13:27 INFO - STDOUT: -- Docs: http://doc.pytest.org/en/latest/warnings.html 21:13:27 INFO - STDOUT: ================ 1 passed, 1 warnings, 1 error in 6.01 seconds ================ 21:13:27 INFO - 21:13:27 INFO - TEST-UNEXPECTED-ERROR | /webdriver/tests/delete_all_cookies/delete.py | test_null_response_value - setup error
The problematic part here is: > 21:13:21 INFO - PID 5624 | 1546377201588 mozrunner::runner INFO Running command: "Z:\\task_1546376327\\build\\application\\firefox\\firefox.exe" "-marionette" "-foreground" "-no-remote" "-profile" "C:\\Users\\task_1546376327\\AppData\\Local\\Temp\\rust_mozprofile.m1pt53PQtiEC" > 21:13:21 INFO - PID 5624 | 1546377201593 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1:2828 > 21:13:21 INFO - PID 5624 | [2136, Main Thread] WARNING: Failed to load startupcache file correctly, removing!: file z:/build/build/src/startupcache/StartupCache.cpp, line 204 > 21:13:21 INFO - PID 5624 | Hit MOZ_CRASH(Bad canary value 0x534dc0f5 in FromData) at z:/build/build/src/xpcom/string/nsSubstring.cpp:330 > 21:13:22 INFO - PID 5624 | 1546377202695 mozrunner::runner DEBUG Killing process 6084 > 21:13:22 INFO - PID 5624 | 1546377202695 webdriver::server DEBUG <- 500 Internal Server Error {"value":{"error":"unknown error","message":"permission denied","stacktrace":""}} There is a startup crash happening: "Bad canary value 0x534dc0f5 in FromData". Sadly we don't have any further crash information here, so not sure if this bug is actionable yet. But maybe it is related to the startupcache failure a line before. Paul, do you have any idea?
Flags: needinfo?(pbone)
Severity: normal → critical
Keywords: crash
Summary: Intermittent /webdriver/tests/delete_all_cookies/delete.py | test_null_response_value - setup error → Intermittent /webdriver/tests/delete_all_cookies/delete.py | test_null_response_value - setup error (Bad canary value 0x534dc0f5 in FromData)
I don't have any good idea. How reproducible is it? Does it happen when running with rr? We added this change because we thought something in the JS GC might have been corrupting DOM data, or corrupting the JS heap so that it pointed to bad DOM data. We never found such corruption, but it has caught several unrelated bugs. However none of them have been in code that I'm familiar with but because I added the canary people ask me (which is fine, just how it is). So I'm afraid I probably don't know for this one either. I suggest finding a regression range so that you can ask someone who might know. Or work on reproducibility & capturing an execution with rr. However I'll NI mccr8 in case he knows.
Depends on: 1410276
Flags: needinfo?(pbone) → needinfo?(continuation)
Orange Factor shows only a single instance of the crash for a windows7-32 debug build. It means at this point it is very unlikely a regression check would be helpful. Maybe we should just wait and see if more of those crashes happen.

Like whimboo said, a crash that only happened once is going to be hard to debug.

Flags: needinfo?(continuation)

At the risk of stepping on anyone's toes I'll close this and it can be re-opened if there are more crashes / crashes increase.

It could be any other bug that had a different signature this one time :-(.

Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → WORKSFORME
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
Summary: Intermittent /webdriver/tests/delete_all_cookies/delete.py | test_null_response_value - setup error (Bad canary value 0x534dc0f5 in FromData) → Intermittent /webdriver/tests/<random> | <random> - setup error (Bad canary value 0x534dc0f5 in FromData)

As other crashes show this is a Windows7 32 bit related crash.

OS: Unspecified → Windows 7
Hardware: Unspecified → x86
Status: REOPENED → RESOLVED
Closed: 7 years ago6 years ago
Resolution: --- → INCOMPLETE
Summary: Intermittent /webdriver/tests/<random> | <random> - setup error (Bad canary value 0x534dc0f5 in FromData) → Intermittent Wd | <random> - setup error (Bad canary value 0x534dc0f5 in FromData)

Not a single failure within the last 6 months. I'm going to close.

Severity: critical → S3
Status: REOPENED → RESOLVED
Closed: 6 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

(In reply to Treeherder Bug Filer from comment #47)

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=365562308&repo=mozilla-esr91

This is bug 1720748 and not that one.

Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → WORKSFORME
Moving bug to Remote Protocol::Marionette component per bug 1815831.
Component: geckodriver → Marionette
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.