What the correct way to get statusCode for incoming data?

[zebox]

I'm use your library for implement websocket (with Zero-copy upgrade). I have two object - Server and Client.
The Client has handler method Receive which listen data for each connection.

func (ch *Channel) Receive(c chan []byte) {
	log.Println("Read client data")
	msg := make([]wsutil.Message, 0, 4)
        

for {
        msg, err := wsutil.ReadClientMessage(ch.conn, msg[:0])
	if err != nil {
		log.Printf("read message error: %v", err)
		return
	}

	for _, m := range msg {

			if m.OpCode.IsControl() {

				// do something for this ...

			}

			if m.OpCode.IsData() {
				statusCode, reason := ws.ParseCloseFrameData(m.Payload)
				log.Printf("Try get statusCode %q, and reason %q", statusCode, reason)

			}
				
		}
  }
}

For connect to my WebSocket server i use Nginx as reverse-proxy and all works fine exclude one moment.
When on the nginx come proxy_read_timeout event I can't catch it in my code. After it event i get OpContinuation code and my Receive handler go to infinity loop (that load CPU to 100%).
I tried use ws.ParseCloseFrameData function, but payload data has lenght=0 and statusCode=0.

On the other side (web-browser client) gets event 1006 from nginx and browser disconnect properly.

Could you help me. What am I doing wrong?

[gobwas]

Hi @zebox! When nginx's proxy_read_timeout occur, it just closes both ends of connections – from browser and to your server. So the browser does not receive 1006 code really – it just handles connection close in such way. And, inside your loop you will not receive CloseFrame from nginx too – again, just because it simply close the connection.

So what we expect your loop to receive is io.EOF error.

Could you run this simple example and put it behind your nginx with some proxy_read_timeout set? Something like this:

package main

import (
	"log"
	"net"

	"github.com/gobwas/ws"
	"github.com/gobwas/ws/wsutil"
)

func main() {
	ln, err := net.Listen("tcp", "localhost:8989")
	if err != nil {
		log.Fatal(err)
	}
	for {
		conn, err := ln.Accept()
		if err != nil {
			log.Fatal(err)
		}
		name := conn.RemoteAddr().String()
		log.Printf("accept from %s", name)
		go func() {
			_, err := ws.Upgrade(conn)
			if err != nil {
				log.Printf("upgrade %s error: %v", name, err)
			}
			log.Printf("upgrade %s ok", name)
			for {
				msgs, err := wsutil.ReadClientMessage(conn, nil)
				if err != nil {
					log.Printf("read message from %s error: %v", name, err)
					return
				}
				for _, msg := range msgs {
					log.Printf("received message from %s: %#x", name, msg.OpCode)
				}
			}
		}()
	}
}

[zebox]

Hi @gobwas. Thank you for reply.
I tested nginx as reverse proxy with your code. I set proxy_read_timeout=30s.
Nginx address is 192.168.56.102:9999 ----reverse-to-ws--> 192.168.56.1:8080
Debug console output bellow:

2018/04/14 15:33:17 accept from 192.168.56.102:51642
2018/04/14 15:33:17 upgrade 192.168.56.102:51642 ok

2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
....
....infinity loop
....
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
2018/04/14 15:33:47 received message from 192.168.56.102:51636: 0x0
...
...
...

Nginx error.log
2018/04/14 15:36:32 [error] 1621#1621: *5 recv() failed (104: Connection reset by peer) while proxying upgraded connection, client: 192.168.56.1, server: 192.168.56.102, request: "GET /ws HTTP/1.1", upstream: "http://192.168.56.1:8080/ws", host: "192.168.56.102:9999"
This error occur after websocket service stops (for interrupt infinite loop).

I temporary solved issue by insert if condition to Receiver handler, but I don't sure that it right way

if m.OpCode == ws.OpContinuation {
	ch.state = false
	break
}

[gobwas]

Wow. Looks like a bug currently. I will try to reproduce it tomorrow and investigate deeper in the problem (today I have no good Internet connection 😄).

[zebox]

Thank you very much! I looking forward to you reply....
Also I tried using gorilla/websocket lib and it got 1006 code from nginx when timeout disconnect .

[gobwas]

Hi @zebox! The bug has been reproduced and localized. I will think for a while to choose the way how to fix it. Will ping you when it will be fixed. Thanks!

By the way, gorilla/websocket returns 1006 code accordingly to the RFC6455:

1006 is a reserved value and MUST NOT be set as a status code in a
Close control frame by an endpoint. It is designated for use in
applications expecting a status code to indicate that the
connection was closed abnormally, e.g., without sending or
receiving a Close control frame.

[zebox]

Good! I will be wait for your fix. Thanks!