You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@guacamole.apache.org by Stefan Bogdan Cimpeanu <bo...@cimpeanu.org> on 2021/06/25 22:43:33 UTC
Websocket tunnel issues

Hello,

I have this weird behaviour where for the same user, from the same machine, to the same target (guacamole connection), from the same IP etc, I get either a successful tunnel created, or I don’t. This tunnel creation is affecting sharing profiles and ability to use the shared drive (for copying files in/out of the guacamole remote).

Please see the logs below.

This bit is where a tunnel is successfully created:

127.0.0.1 - - [25/Jun/2021:21:54:07 +0000] "GET /guacamole/api/patches?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 352
127.0.0.1 - - [25/Jun/2021:21:54:07 +0000] "GET /guacamole/translations/en.json HTTP/1.1" 200 47015
127.0.0.1 - - [25/Jun/2021:21:54:07 +0000] "GET /guacamole/api/session/data/ldap/connectionGroups/ROOT/tree?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 108
127.0.0.1 - - [25/Jun/2021:21:54:07 +0000] "GET /guacamole/api/session/data/mysql-shared/self/permissions?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 242
127.0.0.1 - - [25/Jun/2021:21:54:07 +0000] "GET /guacamole/api/session/data/mysql-shared/connectionGroups/ROOT/tree?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 134
127.0.0.1 - - [25/Jun/2021:21:54:07 +0000] "GET /guacamole/api/session/data/ldap/self/permissions?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 26732
127.0.0.1 - - [25/Jun/2021:21:54:07 +0000] "GET /guacamole/api/session/data/mysql/schema/protocols?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 13547
127.0.0.1 - - [25/Jun/2021:21:54:07 +0000] "GET /guacamole/websocket-tunnel?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B&GUAC_DATA_SOURCE=mysql&GUAC_ID=1594&GUAC_TYPE=c&GUAC_WIDTH=2507&GUAC_HEIGHT=1336&GUAC_DPI=96&GUAC_TIMEZONE=Europe%2FBucharest&GUAC_AUDIO=audio%2FL8&GUAC_AUDIO=audio%2FL16&GUAC_IMAGE=image%2Fjpeg&GUAC_IMAGE=image%2Fpng&GUAC_IMAGE=image%2Fwebp HTTP/1.1" 101 -
127.0.0.1 - - [25/Jun/2021:21:54:08 +0000] "GET /guacamole/api/session/data/mysql/connections/1594?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 321
127.0.0.1 - - [25/Jun/2021:21:54:09 +0000] "GET /guacamole/api/session/data/mysql/self/permissions?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 205
127.0.0.1 - - [25/Jun/2021:21:54:10 +0000] "GET /guacamole/api/session/data/mysql/connectionGroups/ROOT/tree?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 74777
127.0.0.1 - - [25/Jun/2021:21:54:15 +0000] "GET /guacamole/api/session/data/ldap/users/Erik.Nguyen?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 53
127.0.0.1 - - [25/Jun/2021:21:54:15 +0000] "GET /guacamole/api/session/data/mysql-shared/self/effectivePermissions?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 242
127.0.0.1 - - [25/Jun/2021:21:54:15 +0000] "GET /guacamole/api/session/data/ldap/self/effectivePermissions?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 26732
127.0.0.1 - - [25/Jun/2021:21:54:15 +0000] "GET /guacamole/api/session/data/ldap/activeConnections?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 12
127.0.0.1 - - [25/Jun/2021:21:54:15 +0000] "GET /guacamole/api/session/data/mysql-shared/activeConnections?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 12
127.0.0.1 - - [25/Jun/2021:21:54:17 +0000] "GET /guacamole/api/session/data/mysql/self/effectivePermissions?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 6464
127.0.0.1 - - [25/Jun/2021:21:54:17 +0000] "GET /guacamole/api/session/data/mysql/activeConnections?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 235
127.0.0.1 - - [25/Jun/2021:21:54:20 +0000] "POST /guacamole/api/tokens HTTP/1.1" 403 269
127.0.0.1 - - [25/Jun/2021:21:54:34 +0000] "GET /guacamole/api/session/tunnels/null/streams/0/1.txt?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 404 189
127.0.0.1 - - [25/Jun/2021:21:55:21 +0000] "POST /guacamole/api/tokens HTTP/1.1" 403 269
127.0.0.1 - - [25/Jun/2021:21:55:22 +0000] "POST /guacamole/api/tokens HTTP/1.1" 200 191
127.0.0.1 - - [25/Jun/2021:21:55:35 +0000] "GET /guacamole/websocket-tunnel?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B&GUAC_DATA_SOURCE=mysql&GUAC_ID=1594&GUAC_TYPE=c&GUAC_WIDTH=2507&GUAC_HEIGHT=1336&GUAC_DPI=96&GUAC_TIMEZONE=Europe%2FBucharest&GUAC_AUDIO=audio%2FL8&GUAC_AUDIO=audio%2FL16&GUAC_IMAGE=image%2Fjpeg&GUAC_IMAGE=image%2Fpng&GUAC_IMAGE=image%2Fwebp HTTP/1.1" 101 -
127.0.0.1 - - [25/Jun/2021:21:55:40 +0000] "GET /guacamole/api/session/tunnels/7ea07586-be77-4f09-b554-28e6a1366ac7/activeConnection/connection/sharingProfiles?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 252
127.0.0.1 - - [25/Jun/2021:21:56:21 +0000] "GET /guacamole/images/action-icons/guac-prev-page.png HTTP/1.1" 200 648
127.0.0.1 - - [25/Jun/2021:21:56:21 +0000] "GET /guacamole/images/action-icons/guac-last-page.png HTTP/1.1" 200 707
127.0.0.1 - - [25/Jun/2021:21:56:21 +0000] "GET /guacamole/images/action-icons/guac-first-page.png HTTP/1.1" 200 690
127.0.0.1 - - [25/Jun/2021:21:56:21 +0000] "GET /guacamole/images/action-icons/guac-next-page.png HTTP/1.1" 200 626
127.0.0.1 - - [25/Jun/2021:21:56:21 +0000] "GET /guacamole/api/session/data/ldap/activeConnections?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 12
127.0.0.1 - - [25/Jun/2021:21:56:21 +0000] "GET /guacamole/api/session/data/mysql-shared/activeConnections?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 12
127.0.0.1 - - [25/Jun/2021:21:56:22 +0000] "POST /guacamole/api/tokens HTTP/1.1" 403 269
127.0.0.1 - - [25/Jun/2021:21:56:23 +0000] "GET /guacamole/api/session/data/mysql/activeConnections?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 235
127.0.0.1 - - [25/Jun/2021:21:56:32 +0000] "GET /guacamole/api/session/tunnels/7ea07586-be77-4f09-b554-28e6a1366ac7/streams/0/1.txt?token=27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 200 11
127.0.0.1 - - [25/Jun/2021:21:57:09 +0000] "DELETE /guacamole/api/tokens/27C1C8D44B19C39E8DA6D3CADB392BAD22E9EE6E3A41ED0F58B9E3C5C9EFE99B HTTP/1.1" 204 -


Here the tunnel 7ea07586-be77-4f09-b554-28e6a1366ac7 was created successfully.

Just a few minutes later, after logout and login again, with the same user:

127.0.0.1 - - [25/Jun/2021:21:58:19 +0000] "GET /guacamole/api/patches?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 352
127.0.0.1 - - [25/Jun/2021:21:58:19 +0000] "GET /guacamole/translations/en.json HTTP/1.1" 200 47015
127.0.0.1 - - [25/Jun/2021:21:58:19 +0000] "GET /guacamole/api/session/data/ldap/connectionGroups/ROOT/tree?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 108
127.0.0.1 - - [25/Jun/2021:21:58:19 +0000] "GET /guacamole/api/session/data/mysql-shared/connectionGroups/ROOT/tree?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 134
127.0.0.1 - - [25/Jun/2021:21:58:19 +0000] "GET /guacamole/api/session/data/ldap/self/permissions?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 26732
127.0.0.1 - - [25/Jun/2021:21:58:19 +0000] "GET /guacamole/api/session/data/mysql-shared/self/permissions?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 242
127.0.0.1 - - [25/Jun/2021:21:58:19 +0000] "GET /guacamole/api/session/data/mysql/schema/protocols?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 13547
127.0.0.1 - - [25/Jun/2021:21:58:19 +0000] "GET /guacamole/websocket-tunnel?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68&GUAC_DATA_SOURCE=mysql&GUAC_ID=1594&GUAC_TYPE=c&GUAC_WIDTH=2507&GUAC_HEIGHT=1279&GUAC_DPI=96&GUAC_TIMEZONE=Europe%2FBucharest&GUAC_AUDIO=audio%2FL8&GUAC_AUDIO=audio%2FL16&GUAC_IMAGE=image%2Fjpeg&GUAC_IMAGE=image%2Fpng&GUAC_IMAGE=image%2Fwebp HTTP/1.1" 101 -
127.0.0.1 - - [25/Jun/2021:21:58:20 +0000] "GET /guacamole/api/session/data/mysql/connections/1594?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 321
127.0.0.1 - - [25/Jun/2021:21:58:20 +0000] "GET /guacamole/api/session/data/mysql/self/permissions?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 205
127.0.0.1 - - [25/Jun/2021:21:58:22 +0000] "GET /guacamole/api/session/data/mysql/connectionGroups/ROOT/tree?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 74777
127.0.0.1 - - [25/Jun/2021:21:58:24 +0000] "POST /guacamole/api/tokens HTTP/1.1" 403 269
127.0.0.1 - - [25/Jun/2021:21:59:00 +0000] "GET /guacamole/api/session/data/mysql-shared/self/effectivePermissions?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 242
127.0.0.1 - - [25/Jun/2021:21:59:00 +0000] "GET /guacamole/api/session/data/ldap/users/Erik.Nguyen?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 53
127.0.0.1 - - [25/Jun/2021:21:59:00 +0000] "GET /guacamole/api/session/data/ldap/self/effectivePermissions?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 26732
127.0.0.1 - - [25/Jun/2021:21:59:00 +0000] "GET /guacamole/api/session/data/ldap/activeConnections?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 12
127.0.0.1 - - [25/Jun/2021:21:59:00 +0000] "GET /guacamole/api/session/data/mysql-shared/activeConnections?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 12
127.0.0.1 - - [25/Jun/2021:21:59:02 +0000] "GET /guacamole/api/session/data/mysql/self/effectivePermissions?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 6464
127.0.0.1 - - [25/Jun/2021:21:59:02 +0000] "GET /guacamole/api/session/data/mysql/activeConnections?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 200 235
127.0.0.1 - - [25/Jun/2021:21:59:26 +0000] "POST /guacamole/api/tokens HTTP/1.1" 403 269
127.0.0.1 - - [25/Jun/2021:22:00:27 +0000] "POST /guacamole/api/tokens HTTP/1.1" 403 269
127.0.0.1 - - [25/Jun/2021:22:01:28 +0000] "POST /guacamole/api/tokens HTTP/1.1" 403 269
127.0.0.1 - - [25/Jun/2021:22:02:29 +0000] "POST /guacamole/api/tokens HTTP/1.1" 403 269
127.0.0.1 - - [25/Jun/2021:22:03:31 +0000] "POST /guacamole/api/tokens HTTP/1.1" 403 269
127.0.0.1 - - [25/Jun/2021:22:03:41 +0000] "GET /guacamole/api/session/tunnels/null/streams/0/1.txt?token=AB4DC5821C5B74925AE4B724CC12935ED129145D25C78A34328830ACBFE9FD68 HTTP/1.1" 404 189

As you can see, the tunnel is null, and the stream operation is returning 404 (due to the missing tunnel).

On the failed tunnel, the /guacamole/websocket-tunnel just stays in pending (network inspector on client browser).

Please help understand what’s causing this.
This is happening regardless of using a reverse proxy or not.
Comparing guacd debug output for a successful for failed tunnel reveals no clues, output is identical.

To complicate things even more, this is happening “consistently” only on some users (meaning the same set of users either get a failed or a successful tunnel), while on others consistently the tunnel is always created, sharing profiles loaded, etc.

Setup:
- guacamole 1.2
- ldap + mysql
- ubuntu 18.04
- nginx as reverse proxy

Regards,
Bogdan