1078376 - missing websockets sent text messages on win8

Status: UNCONFIRMED

(Core :: Networking: WebSockets, defect, P3)

Description

[e]

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Firefox/31.0 Iceweasel/31.1.0
Build ID: 20140903072827

Steps to reproduce:

I open a websocket from JS:
new WebSocket('ws://'+location.hostname+':8765/start');

while the client is:
Mozilla Firefox 32.0.3 (with 64bit Windows 8 OS)
the server is: "cowboy"


Actual results:

Firefox refuses to open connection (while getting a correct reply from the server).

here is the dialog:

GET /start HTTP/1.1
Host: 376.su:8765
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:32.0) Gecko/20100101
Firefox/32.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: ru,ru-ru;q=0.8,en-us;q=0.5,en;q=0.3
Accept-Encoding: gzip, deflate
Sec-WebSocket-Version: 13
Origin: http://376.su
Sec-WebSocket-Key: EHV/YhFPQcalkhTZssc2RA==
Connection: keep-alive, Upgrade
Pragma: no-cache
Cache-Control: no-cache
Upgrade: websocket

Cowboy answers to FIrefox (sec-websocket-accept is a correct sha1 hash):

HTTP/1.1 101 Switching Protocols
connection: Upgrade
upgrade: websocket
sec-websocket-accept: kCXkB4sO3IFyKHjAzm9v7VXHqiA=


Expected results:

Websocket connection shoud be established.
other browsers do.
Opera, Chrome, IE -- all successfully open connection.

Comment 1

[Patrick McManus [:mcmanus]]

wfm on both 32 and 35 using 64 bit linux and 64 bit win 7

<script>
var socket = new WebSocket('ws://376.su:8765/start');
socket.onopen = function(){alert("Socket has been opened!"); }
</script>

can you use that script (or let me know what's wrong with it) and reproduce with a websockets-amended http logging file?

To do that.. 
1] follow the directions here https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging
2] add nsWebSocket:5 to the list of NSPR_LOG_MODULES

thanks!

Comment 2

[e]

here is the log
http://376.su/img/log.txt

this time is surprisingly accepted handshake and then dropped the connection.

Comment 3

[e]

by the way this is publicly accessible server, feel free to abuse it with all sort of requests you need for investigation

Comment 4

[Patrick McManus [:mcmanus]]

Thanks for the log. I don't see a protocol level problem in the trace I'm looking at.. at 17:53:19 I see a successful handhshake and then the client sending a message.. then silence until 17:57:00 when something calls the c++ Close() method and then we shut things down normally.

Now that could be your javascript, or it could be some other part of gecko. Is there any kind of reload or navigation going on? We've got an existing bug with loadgroups related to that.

Do you have (or can make) a public page with the JS that illustrate the issue? because at this point it doesn't look like the close trigger is on the protocol side.

Comment 5

[e]

i made a minimal test suite:
http://376.su/tst/

try it in several browsers.
normal output is:

open handler: .....
recieved: lobby
received: error

Comment 6

[Patrick McManus [:mcmanus]]

the websockets server associated with your tests appears down now

18:20:54.152684 IP 192.168.16.226.40451 > 148.251.153.2.8765: Flags [S], seq 3533632092, win 29200, options [mss 1460,sackOK,TS val 160412949 ecr 0,nop,wscale 7], length 0
18:20:54.276761 IP 148.251.153.2.8765 > 192.168.16.226.40451: Flags [R.], seq 0, ack 3533632093, win 0, length 0


all three browsers report ws ERROR: see the console

Comment 7

[e]

pardon me, the server went down for a moment.
it should work by now.
does it?

Comment 8

[Patrick McManus [:mcmanus]]

FF 32, FF 35, and Chrome all show the same output for me:
open handler: ws://376.su:8765/start
received: lobby
received: error

I assume that's a passed test based on your characterization of normal. What are you seeing instead? Can you provide the matching HTTP_LOG as from above? How long does it take to happen for you?

Comment 9

[e]

i see no output, or only the first line.
 
it ALWAYS fail on a Win8(64) machine with FF30 or FF32
(i also asked few other Win8(64) users, they experience the same)

HTTP_LOG is coming soon.
(win8 machine is not mine, i have to wait for another guy, i apologize for the delay)

Comment 10

[Honza Bambas (:mayhemer)]

I have a Win8 (x86) machine, will try to reproduce.

Comment 11

[Honza Bambas (:mayhemer)]

Works for me on Win8 x86.  Is there any A/V software involved?  I remember we've had a bug with McAfee that was somehow sensitive to how we send out few headers.

Comment 12

[Honza Bambas (:mayhemer)]

And BTW, are using x64 or x86 build?

Comment 13

[e]

here are two logs:
http://376.su/img/log1.txt
http://376.su/img/log2.txt

Comment 14

[Patrick McManus [:mcmanus]]

(In reply to Honza Bambas (:mayhemer) from comment #12)
> And BTW, are using x64 or x86 build?

the logs show a 32 bit build

Comment 15

[Patrick McManus [:mcmanus]]

so I'm looking at the WebSocketChannel identified by ptr a8ff800 in log1.txt

it shows successful writes of text websocket messages of 15 and 13 bytes (21 and 19 after framing).. PR_Write returns 21 and 19 indicating the OS accepted the writes.

pretty much nothing happens after that for 16 seconds - until it looks like you shut down the browser to get the log.. at which point we send a close message and actually hear the close come back from the server.

the log just looks like the server didn't respond with anything.

honza's question about AV software is interesting - though I am surprised we read the close if that's happening.

what are you using for a websockets server? Are you absolutely sure its handling things ok?

It would be extremely interesting to run a wireshark capture on port 8765 on both the client and the server. That seems like the next step, especially as honza couldn't repro on win8.

Comment 16

[e]

A/V: the built-in "windows defender" (according to the machine owner testimony)

server: cowboy (and i am sure it works, see for yourself, we all have 376.su/tst running correctly)

Comment 17

[Honza Bambas (:mayhemer)]

(In reply to e from comment #16)
> A/V: the built-in "windows defender" (according to the machine owner
> testimony)

I have the same, it's actually integrated MSE, a regular AV.  Wireshark capture would be interesting.  Beside that I don't thing we can more forward on this.

Comment 18

[e]

http://376.su/img/ws1.pcapng -- FF wireshark log
http://376.su/img/ws2.pcapng -- Chrome wireshark log

filter "ip.addr == 148.251.153.2 and tcp.port == 8765".

no FF addons.
supposedly no AV or firewall interfering.

Comment 19

[Patrick McManus [:mcmanus]]

thanks for running the capture.

I'm puzzled. I'm going to assume that the trace in comment 18 would have the same log as comment 13 even though they weren't actually from the same event just because the problem is consistent for the reporter.

The log shows us writing 2 text websocket messages after the handshake.. and then PR_Write() accepting them. That generally means they have made it to the OS TCP socket buffers and we can expect them to move on out from there.

The capture in comment 18 doesn't show the websocket messages. I just shows the handshake and the 101 and then nothing. Presumably the server doesn't send any websocket messages until it receives these - so that silence is to be expected in this case.

it almost looks like some bit of buffering is waiting for a trigger.. but honza's comments indicate it isn't happening in his win8... I'm trying to figure out how widespread this is.. e - I presume this also works for you on platforms other than win8?

Comment 20

[e]

the test suite works well on:
FF 32.0.3 + Win7 SP 1
FF 32.0.3 + Mac Os X 10.9

i have no access to other configurations for now
if it may help, i use IceWeasel + Debian and it works fine.

only Win8 is found susceptible for the issue so far.

Comment 21

[Firefox Bug Husbandry Bot]

Bulk change to priority: https://bugzilla.mozilla.org/show_bug.cgi?id=1399258