Closed Bug 919391 Opened 11 years ago Closed 7 years ago

Incorrect Navigation Timing API: performance.timing.responseStart - performance.timing.requestStart <0

Categories

(Core :: Networking, defect)

24 Branch
x86_64
Windows 7
defect
Not set
normal

Tracking

()

RESOLVED FIXED

People

(Reporter: gao_yanting, Assigned: valentin)

References

(Blocks 1 open bug)

Details

(Keywords: addon-compat, Whiteboard: [bugday-20140113][necko-next])

Attachments

(2 files)

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:24.0) Gecko/20100101 Firefox/24.0 (Beta/Release)
Build ID: 20130910160258

Steps to reproduce:

1. Open FF and open the dev tools (F12)
2. Paste following code in the dev window: 
requestTime = performance.timing.responseStart - performance.timing.requestStart;
alert("request: " + requestTime.toString());
3.Render one website, eg: https://www.google.com/ 
4.Select above code and run, to make request value pop up. Screenshot attached.
5.Usually you should try several times to get result requestTime <0.
  It is easy to reproduce.
Severity: normal → major
Keywords: 64bit
Priority: -- → P1
Whiteboard: Incorrect Navigation Timing API
You are using Firebug in your screenshot. Does this bug affect the Firefox console, too? Please try to reproduce in safe-mode.
Severity: major → normal
Flags: needinfo?(gao_yanting)
Keywords: 64bit
Priority: P1 → --
Whiteboard: Incorrect Navigation Timing API → [bugday-20140113]
We are seeing this on navigations on github.com (I'm a GitHub engineer). We're seeing it across many Firefox versions (at least v16-v27) and OSes (Mac, Windows, Linux). Here's a sample performance.timing dump:

            0 redirectEnd
            0 unloadEventStart
            0 unloadEventEnd
            0 redirectStart
1392331282549 navigationStart
1392331282556 connectEnd
1392331282556 domainLookupStart
1392331282556 domainLookupEnd
1392331282556 connectStart
1392331282556 fetchStart
1392331282770 responseStart
1392331283446 requestStart
1392331283676 responseEnd
1392331283686 domLoading
1392331284345 domInteractive
1392331284465 domContentLoadedEventStart
1392331284468 domContentLoadedEventEnd
1392331286649 domComplete
1392331286649 loadEventStart
1392331286654 loadEventEnd
Keywords: addon-compat
Hello Reporter, thank for reporting this issue. I tried duplicating this problem on the latest released version of Firefox (43.0.4) by executing your Javascript several times (25-30 times) on different websites but never saw any negative value. I tried on Windows 7 64 bit machine using:

Name 	Firefox
Version 	43.0.4
Build ID 	20160105164030
Update Channel 	release
User Agent 	Mozilla/5.0 (Windows NT 6.1; WOW64; rv:43.0) Gecko/20100101 Firefox/43.0

If you have not upgraded so far, may I request you to try again on the latest FF version and let us know if you still see the problem.
Component: Untriaged → Developer Tools: Console
Resolved-Incomplete due to time since last communication/update by reporter.
Please feel free to reopen if the error occurs in a current Firefox version.
Status: UNCONFIRMED → RESOLVED
Closed: 8 years ago
Resolution: --- → INCOMPLETE
Reopening based on report of this happening on some Google sites as well.  Note that response start as defined in the spec can in fact chronologically precede request start in some situations (e.g. http/2 push),  but the spec also says to lie and clamp response start to be no earlier than request start and it's possible we're not doing that clamping...

Valentin, could you take a look please?
Status: RESOLVED → REOPENED
Component: Developer Tools: Console → Networking
Ever confirmed: true
Flags: needinfo?(valentin.gosu)
Product: Firefox → Core
Resolution: INCOMPLETE → ---
Whiteboard: [bugday-20140113] → [bugday-20140113][necko-next]
platform-rel: --- → ?
Whiteboard: [bugday-20140113][necko-next] → [bugday-20140113][necko-next][platform-rel-Google]
Blocks: 1290858
This also fixes the following bug with: gzip_xml.py

0:35.80 LOG: Thread-14 wptserve WARNING Traceback (most recent call last):
  File "mozilla-central/testing/web-platform/tests/tools/wptserve/wptserve/handlers.py", line 246, in __call__
    rv = self.func(request, response)
  File "mozilla-central/testing/web-platform/tests/resource-timing/resources/gzip_xml.py", line 5, in main
    f = open('resource-timing/resources/resource_timing_test0.xml', 'r')
IOError: [Errno 2] No such file or directory: 'resource-timing/resources/resource_timing_test0.xml'
Flags: needinfo?(valentin.gosu)
Comment on attachment 8817313 [details]
Bug 919391 - Incorrect Navigation Timing API: performance.timing.responseStart - performance.timing.requestStart < 0

https://reviewboard.mozilla.org/r/97648/#review97972

Looks good to me. I didn't review the WPT part.
Attachment #8817313 - Flags: review?(amarchesini) → review+
Comment on attachment 8817313 [details]
Bug 919391 - Incorrect Navigation Timing API: performance.timing.responseStart - performance.timing.requestStart < 0

https://reviewboard.mozilla.org/r/97648/#review97992

::: testing/web-platform/tests/resource-timing/resources/gzip_xml.py:7
(Diff revision 1)
>  from cStringIO import StringIO
> +import os
>  
>  def main(request, response):
> -    f = open('resource-timing/resources/resource_timing_test0.xml', 'r')
> +    dir_path = os.path.dirname(os.path.realpath(__file__))
> +    f = open(dir_path+'/resource_timing_test0.xml', 'r')

This should use `os.path.join` rather than assuming that the separator is a `/`
Attachment #8817313 - Flags: review?(james) → review+
https://hg.mozilla.org/integration/mozilla-inbound/rev/b3b5af78a162b11a9a838087c0f6ad3567eeb55e
Bug 919391 - Incorrect Navigation Timing API: performance.timing.responseStart - performance.timing.requestStart < 0 r=baku,jgraham
Valentin, are you able to pick this back up again?
platform-rel: ? → ---
Flags: needinfo?(valentin.gosu)
Whiteboard: [bugday-20140113][necko-next][platform-rel-Google] → [bugday-20140113][necko-next]
Yes, I'll try to fix and land the patch in the next few days.
Assignee: nobody → valentin.gosu
Flags: needinfo?(valentin.gosu)
Keywords: leave-open
Depends on: 1392260
Pushed by valentin.gosu@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/4a471c993ab6
Incorrect Navigation Timing API: performance.timing.responseStart - performance.timing.requestStart < 0 r=baku
https://hg.mozilla.org/integration/mozilla-inbound/rev/4a471c993ab69ec865e40ab9a94342761d9ef0a5
Bug 919391 - Incorrect Navigation Timing API: performance.timing.responseStart - performance.timing.requestStart < 0 r=baku
Status: REOPENED → RESOLVED
Closed: 8 years ago7 years ago
Flags: needinfo?(valentin.gosu)
Flags: needinfo?(gao_yanting)
Resolution: --- → FIXED
Removing leave-open keyword from resolved bugs, per :sylvestre.
Keywords: leave-open
You need to log in before you can comment on or make changes to this bug.