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
