882470 - Network log disappears when buffering was completed

Status: NEW

(DevTools :: Netmonitor, defect, P3)

Description

[Alice0775 White]

Build Identifier:
http://hg.mozilla.org/mozilla-central/rev/0414d6d0f60d
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:24.0) Gecko/20130612 Firefox/24.0 ID:20130612031138

Steps To Reproduce:
1. Clear cache if necessary
2. Open Web Console(Ctrl+Shift+K)
3. Open mp3 
    ex. http://radioexpress.com/public/demo_audio/btb_NT_SAMPLE_MUSIC_BEDS_Tune_Up_138bpm_A.mp3
        http://www.fbcdixon.net/sermons/06.09.13.mp3
   --- observe net log
4. Wait to completion buffering
   --- observe net log

Actual Results:
 Network log disappears when buffering was completed

Expected Results:
 Network log should not disappear when buffering was completed

Regression window(m-c)
Good:
http://hg.mozilla.org/mozilla-central/rev/22cb668fd727
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:24.0) Gecko/20130604 Firefox/24.0 ID:20130604174517
Bad:
http://hg.mozilla.org/mozilla-central/rev/8f9ba85eb61c
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:24.0) Gecko/20130605 Firefox/24.0 ID:20130605001414
Pushlog:
http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=22cb668fd727&tochange=8f9ba85eb61c

Regression window(fx)
Good:
http://hg.mozilla.org/integration/fx-team/rev/ce5ab0de1b09
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:24.0) Gecko/20130603 Firefox/24.0 ID:20130603230714
Bad:
http://hg.mozilla.org/integration/fx-team/rev/5dd0e1ec10f5
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:24.0) Gecko/20130604 Firefox/24.0 ID:20130604092317
Pushlog:
http://hg.mozilla.org/integration/fx-team/pushloghtml?fromchange=ce5ab0de1b09&tochange=5dd0e1ec10f5

Regressed by:
5dd0e1ec10f5	Mihai Sucan — Bug 705921 - Option to clear web console messages on page reload; r=robcee,jwalker

Comment 1

[bhavana bajaj [:bajaj]]

Tracking as it appears to be a recent regression, although may not be a blocker given the info at hand.

Comment 2

[Mihai Sucan [:msucan]]

Thanks for the bug report!

Unfortunately, I cannot reproduce the problem. This might be related to plugins. I'm on Linux and it seems you were using Windows? Which plugin do you have for mp3 playback? I have rythmbox.


(In reply to bhavana bajaj [:bajaj] from comment #1)
> Tracking as it appears to be a recent regression, although may not be a
> blocker given the info at hand.

I suggest this is not a blocker, unless the reporter can find a more common use-case / STR. Thanks!

Comment 3

[Alice0775 White]

(In reply to Mihai Sucan [:msucan] from comment #2)
> Thanks for the bug report!
> 
> Unfortunately, I cannot reproduce the problem. This might be related to
> plugins. I'm on Linux and it seems you were using Windows? Which plugin do
> you have for mp3 playback? I have rythmbox.
> 

Please buy Windows7 machine!
No Plugin.
Play with Nightly's windows media foundation

> 
> (In reply to bhavana bajaj [:bajaj] from comment #1)
> > Tracking as it appears to be a recent regression, although may not be a
> > blocker given the info at hand.
> 
> I suggest this is not a blocker, unless the reporter can find a more common
> use-case / STR. Thanks!

This is common use case. Nothing Special!

Comment 4

[Alice0775 White]

You may reproduce with http://videos-cdn.mozilla.net/brand/Mozilla_2011_Story.webm on Linux

Comment 5

[Mihai Sucan [:msucan]]

Confirmed. Thanks!

Comment 6

[Mihai Sucan [:msucan]]

More investigation: we use an nsIWebProgressListener in toolkit/devtools/server/actors/webbrowser.js. We check the flags of each state change to see if there's anything that interests us: a top level window navigates to a different URL (a new page loads). We want to notify the client when such requests start and when they complete, see DPL_onStateChange().

When I load the webm I logged the following flags:

isStart 1 isStop 0 isDocument 131072 isNetwork 262144 isRequest 65536 isWindow 524288
  which sends the tabNavigated start event

isStart 0 isStop 16 isDocument 0 isNetwork 262144 isRequest 0 isWindow 524288
  sends the tabNavigated stop event

isStart 1 isStop 0 isDocument 131072 isNetwork 262144 isRequest 65536 isWindow 524288
  sends the tabNavigated start event again

isStart 0 isStop 16 isDocument 0 isNetwork 262144 isRequest 0 isWindow 524288
  sends the tabNavigated stop event again

Why does this happen? And how can I tell the difference between the two state changes that start/stop? We are definitely missing something here.

Asking Brian Smith for info, as he shows up as one of the Necko peers. Thank you!

Comment 7

[Brian Smith (:briansmith, :bsmith, use NEEDINFO?)]

Sorry for the delay. To be honest, I am not familiar with how nsIWebProgressListener works. It is actually a DocShell thing, not a Necko thing. I recommend asking one of the docshell peers for help. I am interested in the answer as well.

Comment 8

[Mihai Sucan [:msucan]]

Thank you Brian! I am asking now Benjamin, as he is listed as a docshell peer.

Benjamin: can you please look into this bug report? See comment #0 and the investigation results I have in comment #6. Can you provide us with more insight into the problem we have? Thank you!

Comment 9

[Benjamin Smedberg]

I'm not sure I understand exactly what you're asking. I see two different requests, which seems correct. When we load an audio/video stream, we first do either a HEAD or a byte-stream request to get the headers (I'm not sure of the details). Then we do one or more additional requests to get the full body of the video. If the user seeks around, we will attempt to do byte-range requests to fetch that portion of the video directly.

This looks like normal behavior, not a bug.

Comment 10

[Mihai Sucan [:msucan]]

Benjamin, thank you for explaining that. It now makes sense why the bug is occurring. At this point we need to do more investigation inside the web console network monitoring code to see how we can avoid the issue reported.

Comment 11

[Mihai Sucan [:msucan]]

(unassigning for now, since I will not work on this bug too soon)

Comment 12

[bhavana bajaj [:bajaj]]

After talking to Mihai further on this via email I am wontfixing this for Fx24 release as he confirmed this is not a common enough scenario. We did
not see any duplicates either. 

Mihai - please keep in this in your list to reprioritize this as needed.