Websockets not working

classic Classic list List threaded Threaded
7 messages Options
Reply | Threaded
Open this post in threaded view
|

Websockets not working

Colin McGuigan
Hello again.

So I have an SSH connection.  I can connect through Guacamole, but it's
really slow.  Some research says that this is because I'm not using
websockets, and lo and behold, I find this in the logs:

Oct 18 10:36:11 <Computer> server: 10:36:11.625 [http-bio-8080-exec-3] DEBUG
o.a.g.net.InetGuacamoleSocket - Connecting to guacd at localhost:4822.
Oct 18 10:36:11 <Computer> guacd[14498]: Creating new client for protocol
"ssh"
Oct 18 10:36:11 <Computer> guacd[14498]: Connection ID is
"$8f1e574b-9752-4b37-83af-2ac86d78b2c6"
Oct 18 10:36:11 <Computer> guacd[14507]: User
"@cfecdb6e-fa9b-47b7-9d26-a0d7193fc836" joined connection
"$8f1e574b-9752-4b37-83af-2ac86d78b2c6" (1 users now present)
Oct 18 10:36:11 <Computer> server: 10:36:11.671 [http-bio-8080-exec-3] INFO
o.a.g.tunnel.TunnelRequestService - User "<UserId>" connected to connection
"<Computer>".
Oct 18 10:36:11 <Computer> server: 10:36:11.685 [http-bio-8080-exec-3] INFO
o.a.g.tunnel.TunnelRequestService - User "<UserId>" disconnected from
connection "<Computer>". Duration: 14 milliseconds
Oct 18 10:36:11 <Computer> server: 10:36:11.685 [http-bio-8080-exec-3] DEBUG
o.a.g.net.InetGuacamoleSocket - Closing socket to guacd.
Oct 18 10:36:11 <Computer> server: 10:36:11.686 [Thread-18] DEBUG
o.a.g.w.GuacamoleWebSocketTunnelEndpoint - Connection to guacd closed.
Oct 18 10:36:11 <Computer> server:
org.apache.guacamole.GuacamoleConnectionClosedException: Connection to guacd
is closed.
Oct 18 10:36:11 <Computer> server: at
org.apache.guacamole.io.ReaderGuacamoleReader.read(ReaderGuacamoleReader.java:183)
~[guacamole-common-0.9.13-incubating.jar:na]
Oct 18 10:36:11 <Computer> server: at
org.apache.guacamole.io.ReaderGuacamoleReader.readInstruction(ReaderGuacamoleReader.java:195)
~[guacamole-common-0.9.13-incubating.jar:na]
Oct 18 10:36:11 <Computer> server: at
org.apache.guacamole.protocol.FilteredGuacamoleReader.readInstruction(FilteredGuacamoleReader.java:81)
~[guacamole-common-0.9.13-incubating.jar:na]
Oct 18 10:36:11 <Computer> server: at
org.apache.guacamole.protocol.FilteredGuacamoleReader.readInstruction(FilteredGuacamoleReader.java:81)
~[guacamole-common-0.9.13-incubating.jar:na]
Oct 18 10:36:11 <Computer> server: at
org.apache.guacamole.protocol.FilteredGuacamoleReader.read(FilteredGuacamoleReader.java:64)
~[guacamole-common-0.9.13-incubating.jar:na]
Oct 18 10:36:11 <Computer> server: at
org.apache.guacamole.websocket.GuacamoleWebSocketTunnelEndpoint$2.run(GuacamoleWebSocketTunnelEndpoint.java:160)
~[guacamole-common-0.9.13-incubating.jar:na]
Oct 18 10:36:11 <Computer> server: Caused by: java.net.SocketException:
Socket closed
Oct 18 10:36:11 <Computer> server: at
java.net.SocketInputStream.read(SocketInputStream.java:204) ~[na:1.8.0_141]
Oct 18 10:36:11 <Computer> server: at
java.net.SocketInputStream.read(SocketInputStream.java:141) ~[na:1.8.0_141]
Oct 18 10:36:11 <Computer> server: at
sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284) ~[na:1.8.0_141]
Oct 18 10:36:11 <Computer> server: at
sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326) ~[na:1.8.0_141]
Oct 18 10:36:11 <Computer> server: at
sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178) ~[na:1.8.0_141]
Oct 18 10:36:11 <Computer> server: at
java.io.InputStreamReader.read(InputStreamReader.java:184) ~[na:1.8.0_141]
Oct 18 10:36:11 <Computer> server: at
org.apache.guacamole.io.ReaderGuacamoleReader.read(ReaderGuacamoleReader.java:169)
~[guacamole-common-0.9.13-incubating.jar:na]
Oct 18 10:36:11 <Computer> server: ... 5 common frames omitted
Oct 18 10:36:11 <Computer> server: 10:36:11.789 [http-bio-8080-exec-9] DEBUG
o.a.g.net.InetGuacamoleSocket - Connecting to guacd at localhost:4822.
Oct 18 10:36:11 <Computer> guacd[14498]: Creating new client for protocol
"ssh"
Oct 18 10:36:11 <Computer> guacd[14498]: Connection ID is
"$34b0c04f-efa3-4268-b22e-3f580ab6dbeb"
Oct 18 10:36:11 <Computer> guacd[14518]: User
"@d707daa9-09dc-481b-9704-9ee7e1fa616c" joined connection
"$34b0c04f-efa3-4268-b22e-3f580ab6dbeb" (1 users now present)
Oct 18 10:36:11 <Computer> server: 10:36:11.834 [http-bio-8080-exec-9] INFO
o.a.g.tunnel.TunnelRequestService - User "<UserId>" connected to connection
"<Computer>".
Oct 18 10:36:11 <Computer> server: 10:36:11.834 [http-bio-8080-exec-9] INFO
o.a.g.t.h.RestrictedGuacamoleHTTPTunnelServlet - Using HTTP tunnel (not
WebSocket). Performance may be sub-optimal.
Oct 18 10:36:11 <Computer> server: 10:36:11.834 [http-bio-8080-exec-9] DEBUG
o.a.g.s.GuacamoleHTTPTunnelServlet - Registered tunnel
"e960de72-4910-45c8-ae64-2d0afed11351".

Now, I've verified the following things:

1. I am connecting directly through Tomcat on port 8080.  There is no Apache
or nginx reverse proxy.

2. I can go to websocket test sites (like www.websocket.org/echo.html) which
verify that a) my browser supports it (Chrome), b) that it works.  

3. Copying the HTML from www.websocket.org/echo.html and putting it on the
Guacamole server, it also confirms that websockets work.

So, unless I misunderstand something, it does not seem to be a reverse proxy
issue, a firewall issue, or a "client doesn't support websockets" issue.  

My question is, is there any way to determine why there is the initial
connect/disconnect of a connection that lasts 14ms, or why there is an
exception being thrown as if this disconnect is unexpected?  Is there
something I can do to increase the log level, or test what might be
happening?  

Thanks in advance.



--
Sent from: http://apache-guacamole-incubating-users.2363388.n4.nabble.com/
Reply | Threaded
Open this post in threaded view
|

Re: Websockets not working

Mike Jumper
On Wed, Oct 18, 2017 at 8:48 AM, Colin McGuigan
<[hidden email]> wrote:
> Hello again,

> So I have an SSH connection.  I can connect through Guacamole, but it's
> really slow.  Some research says that this is because I'm not using
> websockets, ...

Not necessarily. It is true that the WebSocket tunnel is faster than
the HTTP tunnel, but if you would describe the connection as "really
slow", something else might be at work here. The HTTP tunnel should
still be reasonably fast.

> ...
> Now, I've verified the following things:
>
> 1. I am connecting directly through Tomcat on port 8080.  There is no Apache
> or nginx reverse proxy.
>

What version of Tomcat?

> My question is, is there any way to determine why there is the initial
> connect/disconnect of a connection that lasts 14ms, or why there is an
> exception being thrown as if this disconnect is unexpected?

An exception is thrown normally when a read attempt is made against a
closed TCP socket. As this is not an error per se, at least not from
the perspective of the HTTP tunnel, that particular exception is not
normally logged, but rather handled as another indicator of connection
closure. It's only logged in this case because debug-level logging is
enabled.

- Mike
Reply | Threaded
Open this post in threaded view
|

Re: Websockets not working

Colin McGuigan
Mike Jumper wrote
> What version of Tomcat?

7.0.69.0; as I understand it, websockets have been supported since 7.0.47.




--
Sent from: http://apache-guacamole-incubating-users.2363388.n4.nabble.com/
Reply | Threaded
Open this post in threaded view
|

Re: Websockets not working

Mike Jumper
On Wed, Oct 18, 2017 at 10:31 AM, Colin McGuigan
<[hidden email]> wrote:
> Mike Jumper wrote
>> What version of Tomcat?
>
> 7.0.69.0; as I understand it, websockets have been supported since 7.0.47.
>

Yes, and since 7.0.37 via the Tomcat-specific WebSocket API. Your
version is definitely new enough.

What does Chrome show in the "network" tab of its dev tools when you
try to connect? You'll probably need to open dev tools and reload the
page for the WebSocket connection attempt to be visible.

- Mike
Reply | Threaded
Open this post in threaded view
|

Re: Websockets not working

Colin McGuigan
I see requests associated with loading the page (the final one is
guac-config-dark.png), then I see:

GET
ws://<Computer>:8080/guacamole/websocket-tunnel?token=943D0910D316FE59C5C110AD800DFF7FBDFD7529000C1D7503719FD9828DB69B&GUAC_DATA_SOURCE=saml&GUAC_ID=<Computer>&GUAC_TYPE=c&GUAC_WIDTH=948&GUAC_HEIGHT=998&GUAC_DPI=120&GUAC_AUDIO=audio%2FL8&GUAC_AUDIO=audio%2FL16&GUAC_IMAGE=image%2Fjpeg&GUAC_IMAGE=image%2Fpng&GUAC_IMAGE=image%2Fwebp

This returns:

HTTP/1.1 101 Switching Protocols
Server: Apache-Coyote/1.1
Upgrade: websocket
Connection: upgrade
Sec-WebSocket-Accept: YrB/6V3QNwqCKAKUYGEl4KKHA6s=
Sec-WebSocket-Protocol: guacamole
Sec-WebSocket-Extensions: permessage-deflate;client_max_window_bits=15
Date: Wed, 18 Oct 2017 19:18:40 GMT

The next line is:

POST http://<Computer>:8080/guacamole/tunnel?connect

Which returns a 200 OK and a connectionId
(eb39d30a-50ae-4a68-b619-e85bc32c0b1c); I presume this is the HTTP tunnel.

Following this are various calls to "tunnel?read" and "tunnel?write" with
the same connectionId.  The only exceptions are some image data, and a 404
for sharingProfiles, which I assume is normal.



--
Sent from: http://apache-guacamole-incubating-users.2363388.n4.nabble.com/
Reply | Threaded
Open this post in threaded view
|

Re: Websockets not working

Colin McGuigan
Update: Without changing any configuration (only working on my extension),
this problem resolved itself and I now see the websocket tunnel in use.

I have no idea what caused it to change, other than the possibility of
tomcat restarts.



--
Sent from: http://apache-guacamole-incubating-users.2363388.n4.nabble.com/
Reply | Threaded
Open this post in threaded view
|

Re: Websockets not working

vnick
On Thu, Oct 19, 2017 at 1:36 PM, Colin McGuigan <[hidden email]> wrote:
Update: Without changing any configuration (only working on my extension),
this problem resolved itself and I now see the websocket tunnel in use.

I have no idea what caused it to change, other than the possibility of
tomcat restarts.


Colin,
I did notice something in the following line:

GET
ws://<Computer>:8080/guacamole/websocket-tunnel?token=943D0910D316FE59C5C110AD800DFF7FBDFD7529000C1D7503719FD9828DB69B&GUAC_DATA_SOURCE=saml&GUAC_ID=<Computer>&GUAC_TYPE=c&GUAC_WIDTH=948&GUAC_HEIGHT=998&GUAC_DPI=120&GUAC_AUDIO=audio%2FL8&GUAC_AUDIO=audio%2FL16&GUAC_IMAGE=image%2Fjpeg&GUAC_IMAGE=image%2Fpng&GUAC_IMAGE=image%2Fwebp 

The GUAC_DATA_SOURCE=saml is a bit interesting.  I'm guessing that your SAML extension is only doing authentication, it's not providing any computer data, correct?  If so, this line indicates the issue, that it is/was trying to retrieve the connection from the SAML data source, when it is actually in another data source.  Perhaps the change you made caused it to correct this parameter??

-Nick