Both success and error callbacks called if timeout is shorter than few seconds

RESOLVED FIXED in Firefox 51

Status

()

defect
RESOLVED FIXED
3 years ago
2 months ago

People

(Reporter: radek.svitil, Assigned: kanru)

Tracking

({regression})

47 Branch
mozilla52
Points:
---
Dependency tree / graph
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(firefox48 wontfix, firefox49 wontfix, firefox50 wontfix, firefox51 fixed, firefox52 fixed)

Details

Attachments

(4 attachments, 3 obsolete attachments)

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/51.0.2704.103 Safari/537.36

Steps to reproduce:

See code at https://jsfiddle.net/Nadradouch/fbqa8fuh/5/
and run it at Firefox 47 or 47.0.1 (tested on Windows 7 and Android).



Actual results:

Both success and error callbacks are called. If there is no timeout set or it is set to ca 5-10 seconds and more, only success is called.


Expected results:

Only one callback should be called.
Component: Untriaged → Geolocation
Product: Firefox → Core
I haven't been able to reproduce this yet, no matter what value between 4000 and 10000 the timeout was set to.
To be clear, I saw some cases where the error callback was called, and some where the success callback was called. I never saw both.
I can't reproduce, either.

Michelangelo, any ideas?
More details on how to reproduce this bug:
1. You MUST use Firefox 47.0.1. It seems earlier versions do not have this problem.
2. You MUST make successful geolocation in your Firefox browser earlies. If there is no earlier position, this script displayes error (it is correct result in that case). If you find geolocate your position e. g. using https://www.google.cz/maps and then go to the https://jsfiddle.net/Nadradouch/fbqa8fuh/5/ , you should at first see SUCCESS and after few seconds ERROR.
(Missed setting ni? in comment 4)
Flags: needinfo?(michelangelo)
Confirmed on 47 on Win32, Win64, OS X, Linux.
Does *NOT* repro on 48 onward.

Thanks for letting us know Radek; interestingly enough, this actually happens only on 47.

Just to be on the safe side, would you please try to reproduce this with beta? You can download it from here: https://beta.mozilla.org/
Status: UNCONFIRMED → NEW
Ever confirmed: true
Flags: needinfo?(michelangelo) → needinfo?(radek.svitil)
Michelangelo, I am sorry to have a bad news: this error DOES reproduce on 48.0b for me... I also tried our real application, where the problem was originally spotted, and it occurs there too.
Flags: needinfo?(radek.svitil)
STR:
1) Open http://www.w3schools.com/html/html5_geolocation.asp and share location
2) Open https://jsfiddle.net/Nadradouch/fbqa8fuh/5/

Regression range:
https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=953741f757abdb9b12719aba565d82209a46ab7b&tochange=9e99bde8d25469407cb1f86965ca7beacde95737

Doug Turner — Bug 1253159 - Remove locationUpdatePending and restore request timeout. r=jdm

I found the issue is only present with e10s disabled, if e10s is on, I can't reproduce it.

Doug, what do you think?
Blocks: 1253159
Flags: needinfo?(dougt)
Keywords: regression
OS: Unspecified → All
Hardware: Unspecified → All
I found/reproduced this (or something like this) in Firefox v47.0 and in (updated today) v48.0 (running on Windows 10 64-bit).

My API call looks like this:

navigator.geolocation.getCurrentPosition(success, error, { timeout: 10000, enableHighAccuracy: true });

I call this API repeatedly about once every 4 or 5 seconds (i.e. after it invokes the success or error callback, I call it again about 4 seconds later).

Approximately half the times I call it, it fails: the error.code is 3 and the error.message is "Position acquisition timed out".

NB that when it fails, it fails immediately, and not after a 10-second timeout. So it looks like it's reporting a earlier (now-expired) timeout which happened after an earlier successful call succeeded.
I found something that looks very strange.

I use the following as a test page (and using a PC not a mobile device, no GPS).


<!DOCTYPE html>
<html>
<head>
    <title>Test Geolocation</title>
    <meta charset="utf-8" />
</head>
<body>
    <h1>Results</h1>
    <ul id="list"></ul>
    <script>
        var $ul = document.getElementById('list');
        function show(text, count) {
            var $li = document.createElement('li');
            $li.textContent = '('+count+') '+text;
            $ul.appendChild($li);
        }
        function testAgain(count) {
            show('Testing', count)
            function success() {
                show('OK', count);
                testAgain(count + 1);
            }
            function error(err) {
                show('Error ' + err.code + ': ' + err.message, count);
                testAgain(count + 1);
            }
            setTimeout(function () {
                navigator.geolocation.getCurrentPosition(success, error, { timeout: 10000, enableHighAccuracy: true });
            }, 4000);
        }
        testAgain(1);
    </script>
</body>
</html>

Then I get results which are e.g. as follows:

Results

    (1) Testing
    (1) OK
    (2) Testing
    (2) OK
    (3) Testing
    (3) OK
    (4) Testing
    (4) OK
    (5) Testing
    (3) Error 3: Position acquisition timed out
    (4) Testing
    (5) OK
    (6) Testing
    (4) Error 3: Position acquisition timed out
    (5) Testing
    (6) OK
    (7) Testing
    (4) OK
    (5) Testing
    (5) Error 3: Position acquisition timed out
    (6) Testing

The strange thing is that invocation #3 returned twice: after "(3) Testing" it returned "(3) OK" fairly promptly; after which it started "(4) Testing", and "(5) Testing"; but sometime after that, there was an error return from the #3 invocation i.e. "(3) Error 3: Position acquisition timed out".

I was expecting either a success callback or a failure callback; never both, and for sure not a failure callback after a success callback.
Posted file 1283563.html
I tested your testcase and I got the same regression range as in comment #9. Waiting for dougt's answer.
47 shipped with it & too late for 48.
Kanru, any ideas here?
Flags: needinfo?(kchen)
I cannot reproduce it locally but I suspect it's due to the location cache. I'll take a look.
Assignee: nobody → kchen
Flags: needinfo?(kchen)
Flags: needinfo?(doug.turner)
I encountered this in 48.0.2, windows 10 64, no GPS hardware. I can reproduce reliably with the test code below: Click the "test" button, wait 5 seconds, then click share in the geolocation permission prompt. The success message appears, followed some time later by the error.

I'm not completely sure if time spent with the prompt open makes a difference.

<!DOCTYPE html>
<html>
<head>
<title>Geolocation test</title>
<script type="text/javascript">
function addStatus(str) {
	var e=document.getElementById('status');
	e.innerHTML = e.innerHTML + '<div>'+str+'</div>';
}
function onSuccess(pos) {
	addStatus("success "+pos.coords.latitude+" "+pos.coords.longitude);
}
function onError(err) {
	addStatus("error "+err.code+" "+err.message);
}
function doTest() {
	navigator.geolocation.getCurrentPosition(onSuccess,onError,{timeout:5000});
}
</script>
</head>
<body>
<button onclick="doTest()">Test</button>
<div id="status"></div>
</body>
</html>
Hi Kan-Ru, could you please take a look at the test case provided in the last comment? Does this help reproduce this locally?
Flags: needinfo?(kchen)
I can't reproduce with a release build. But with a debug build I saw this assertion

Assertion failure: !mShutdown (timeout after shutdown), at /home/kanru/mozilla/gecko/dom/geolocation/nsGeolocation.cpp:394

Which means the error callback was called after the success callback and after shutdown.
Flags: needinfo?(kchen)
Okay, patches on the way. But I need to add a test.
The test test_handlerSpinsEventLoop.html should have caught this but it's broken. geo.wifi.timeToWaitBeforeSending was set to 2000 for tests so errorCallback was always called first.

In this patch I set geo.wifi.timeToWaitBeforeSending to 10 and timeout to 500 to ensure that successCallback is called before errorCallback. And in successCallback I use sleep(1000) to make sure the next spinEventLoop will run the errorCallback if it's in the event queue.
Attachment #8794151 - Flags: review?(josh)
Also make sure all timers are consumed.
Attachment #8794151 - Attachment is obsolete: true
Attachment #8794151 - Flags: review?(josh)
Attachment #8794152 - Flags: review?(josh)
Comment on attachment 8794152 [details] [diff] [review]
Don't reset timeout for oneshot geolocation request. v1.1

Review of attachment 8794152 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/tests/mochitest/geolocation/test_handlerSpinsEventLoop.html
@@ +37,4 @@
>    successCallbackCalled = true;
> +  check_geolocation(position);
> +  sleep(1000);
> +  while (timeoutPassed) {

Shouldn't this be `while (!timeoutPassed)`?
Attachment #8794152 - Flags: review?(josh) → review+
Argh. Timeout won't fire during sync xhr. I need a better idea to test this.
What if you use an nsITimer directly, rather than setTimeout?
I changed the test to a mochitest-chrome test in order to use nsITimer directly. If I use mochitest-plain I get a "Permission denied for <http://mochi.test:8888> to create wrapper for object of class UnamedClass" error when timer callback is called.
Attachment #8794152 - Attachment is obsolete: true
Attachment #8794722 - Flags: review?(josh)
Attachment #8794722 - Flags: review?(josh) → review+
Hi Kan-Ru, this seems a recent regression, I'd be happy to take an uplift to Beta50. Is this going to land in Nightly52 soon?
Flags: needinfo?(kchen)
I fixed one more assertion. Now try looks green

https://treeherder.mozilla.org/#/jobs?repo=try&revision=1cf51e3b441c
Flags: needinfo?(kchen)
Pushed by kchen@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/f54d698d7de7
Don't reset timeout for oneshot geolocation request. r=jdm
https://hg.mozilla.org/mozilla-central/rev/f54d698d7de7
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla52
committed version.
Attachment #8794722 - Attachment is obsolete: true
Attachment #8796493 - Flags: review+
Comment on attachment 8796493 [details] [diff] [review]
Don't reset timeout for oneshot geolocation request. v2.1

Approval Request Comment
[Feature/regressing bug #]: bug 1253159
[User impact if declined]: unexpected location request timeout
[Describe test coverage new/current, TreeHerder]: landed on m-c with tests
[Risks and why]: if the patch was wrong, it might break watch request. But the chance is pretty low.
[String/UUID change made/needed]:
Attachment #8796493 - Flags: approval-mozilla-aurora?
Comment on attachment 8796493 [details] [diff] [review]
Don't reset timeout for oneshot geolocation request. v2.1

Fix a regression related to geolocation. Take it in 51 aurora.
Attachment #8796493 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Hi :kanru,
Since this bug also affects 50, do you think it's worth uplifting to 50?
Flags: needinfo?(kchen)
It turns out there are two errors here. First, mochitest/geolocation/chrome.ini was removed from moz.build in bug 1218627 so the test wasn't actually run on nightly. Second, mochitest-chrome test needs a different URL for network_geolocation.sjs, that's why the test timeouts on aurora.
Flags: needinfo?(kchen)
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Attachment #8797109 - Flags: review?(josh) → review+
Comment on attachment 8797110 [details] [diff] [review]
Follow up. Change geo.wifi.url BASE_URL based on test type

Review of attachment 8797110 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/tests/mochitest/geolocation/geolocation_common.js
@@ +3,5 @@
> +case "chrome":
> +  BASE_URL = "http://mochi.test:8888/chrome/dom/tests/mochitest/geolocation/network_geolocation.sjs";
> +  break;
> +default:
> +  BASE_URL = "http://mochi.test:8888/tests/dom/tests/mochitest/geolocation/network_geolocation.sjs";

Let's do
var harness = SimpleTest.harnessParameters.testRoot == "chrome" ? "chrome" : "test";
var BASE_URL = "http://mochi.test:8888/" + harness + "/dom/tests/mochitest/geolocation/network_geolocation.sjs";
Attachment #8797110 - Flags: review?(josh) → review+
Pushed by kchen@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/a3d11cbf8bfd
Add mochitest/geolocation/chrome.ini back. r=jdm
https://hg.mozilla.org/integration/mozilla-inbound/rev/032113ce311c
Change geo.wifi.url BASE_URL based on test type. r=jdm
I'll prepare a patch for Aurora.
Pushed by kchen@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/af72e3cf941f
Followup - properly finish test in case timeout is really flaky. r=me
Duplicate of this bug: 1312685
Duplicate of this bug: 1282013
pls reopen.

still present with v50.0
see url from 1312685 - https://bilgiprog.github.io/jsders/test/geotest.html A

working fine in 53.0a1 (2016-11-17) (64-bit)
(In reply to Peter Nemsak from comment #48)
> pls reopen.
> 
> still present with v50.0
> see url from 1312685 - https://bilgiprog.github.io/jsders/test/geotest.html A
> 
> working fine in 53.0a1 (2016-11-17) (64-bit)

Read the flags on the right, it's NOT fixed in 50:
status-firefox48: 	wontfix
status-firefox49: 	wontfix
status-firefox50: 	affected
status-firefox51: 	fixed
status-firefox52: 	fixed
sry, didn't know that it overrides the main bug status - RESOLVED FIXED that is - even for current stable. thanks for notifying.
Too late to fix in 50.1.0 release

This issue is still reproducible with Beta 67.0b15 on Mac 10.12, but not on 10.13 or 10.14.

Duplicate of this bug: 860805
You need to log in before you can comment on or make changes to this bug.