Thanks Nick, very interesting. We've rebuilt the Docker image with WITH_FREERDP='2\.2\.0' and are still able to reproduce (again, on the 58th attempt), although not with the same "Major bug" error message (which I think makes sense, the string "Major bug" doesn't appear in any source for https://github.com/FreeRDP/FreeRDP/tree/2.2.0). The log right after it shows though "freerdp_connect:freerdp_set_last_error_ex resetting error state". Full logs from guacd with GUACD_LOG_LEVEL=debug for a failing connection attempt:
2024-01-12 11:24:33 guacd[1]: INFO: Creating new client for protocol "rdp" 2024-01-12 11:24:33 guacd[1]: INFO: Connection ID is "$003920a5-932f-44c4-8279-8c37378990ab" 2024-01-12 11:24:33 guacd[1555]: DEBUG: Processing instruction: size 2024-01-12 11:24:33 guacd[1555]: DEBUG: Processing instruction: audio 2024-01-12 11:24:33 guacd[1555]: DEBUG: Processing instruction: video 2024-01-12 11:24:33 guacd[1555]: DEBUG: Processing instruction: image 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "console" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "console-audio" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "cert-tofu" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "disable-auth" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: INFO: Security mode: NLA 2024-01-12 11:24:33 guacd[1555]: DEBUG: User resolution is 3456x1984 at 192 DPI 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "dpi" omitted. Using default value of 96. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Using resolution of 1728x992 at 96 DPI 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "force-lossless" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "read-only" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "client-name" omitted. Using default value of "Guacamole RDP". 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "enable-theming" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "enable-full-window-drag" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "enable-desktop-composition" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "disable-bitmap-caching" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "disable-offscreen-caching" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "disable-glyph-caching" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Glyph caching is currently universally disabled, regardless of the value of the "disable-glyph-caching" parameter, as glyph caching support is not considered stable by FreeRDP as of the FreeRDP 2.0.0 release. See: https://issues.apache.org/jira/browse/GUACAMOLE-1191 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "disable-audio" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "enable-printing" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "printer-name" omitted. Using default value of "Guacamole Printer". 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "enable-drive" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "drive-name" omitted. Using default value of "Guacamole Filesystem". 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "drive-path" omitted. Using default value of "". 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "create-drive-path" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "disable-download" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "disable-upload" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "enable-sftp" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "sftp-hostname" omitted. Using default value of "35.184.33.74". 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "sftp-port" omitted. Using default value of "22". 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "sftp-username" omitted. Using default value of "assistivlabs". 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "sftp-password" omitted. Using default value of "". 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "sftp-passphrase" omitted. Using default value of "". 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "sftp-root-directory" omitted. Using default value of "/". 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "sftp-server-alive-interval" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "sftp-disable-download" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "sftp-disable-upload" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "recording-name" omitted. Using default value of "recording". 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "recording-exclude-output" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "recording-exclude-mouse" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "recording-exclude-touch" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "recording-include-keys" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "create-recording-path" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: INFO: Resize method: none 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "disable-gfx" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "color-depth" omitted. Using default value of 32. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "enable-touch" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "enable-audio-input" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "gateway-port" omitted. Using default value of 443. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "disable-copy" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "disable-paste" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: INFO: No clipboard line-ending normalization specified. Defaulting to preserving the format of all line endings. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Parameter "wol-send-packet" omitted. Using default value of 0. 2024-01-12 11:24:33 guacd[1555]: INFO: User "@f2ce880f-b4dd-4512-9685-31a1da763c5a" joined connection "$003920a5-932f-44c4-8279-8c37378990ab" (1 users now present) 2024-01-12 11:24:33 guacd[1555]: DEBUG: Client is using protocol version "VERSION_1_5_0" 2024-01-12 11:24:33 guacd[1555]: INFO: Loading keymap "base" 2024-01-12 11:24:33 guacd[1555]: INFO: Loading keymap "en-us-qwerty" 2024-01-12 11:24:33 guacd[1555]: DEBUG: freerdp_connect:freerdp_set_last_error_ex resetting error state 2024-01-12 11:24:33 guacd[1555]: DEBUG: Support for CLIPRDR (clipboard redirection) registered. Awaiting channel connection. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Support for static channel "rdpdr" loaded. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Support for static channel "rdpsnd" loaded. 2024-01-12 11:24:33 guacd[1555]: DEBUG: Local framebuffer format PIXEL_FORMAT_BGRX32 2024-01-12 11:24:33 guacd[1555]: DEBUG: Remote framebuffer format PIXEL_FORMAT_BGRA32 2024-01-12 11:24:34 guacd[1555]: DEBUG: primitives autodetect, using optimized 2024-01-12 11:24:34 guacd[1555]: DEBUG: freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state 2024-01-12 11:24:34 guacd[1555]: DEBUG: freerdp_tcp_connect:freerdp_set_last_error_ex resetting error state 2024-01-12 11:24:34 guacd[1555]: DEBUG: Clipboard data has been received, but cannot be sent to the RDP server because the CLIPRDR channel is not yet connected. 2024-01-12 11:24:34 guacd[1555]: DEBUG: Protocol Security Negotiation Failure 2024-01-12 11:24:34 guacd[1555]: DEBUG: rdp_client_connect:freerdp_set_last_error_ex ERRCONNECT_SECURITY_NEGO_CONNECT_FAILED [0x0002000C] 2024-01-12 11:24:34 guacd[1555]: DEBUG: Error: protocol security negotiation or connection failure 2024-01-12 11:24:34 guacd[1555]: DEBUG: SVC "rdpdr" disconnected. 2024-01-12 11:24:34 guacd[1555]: DEBUG: SVC "rdpsnd" disconnected. 2024-01-12 11:24:34 guacd[1555]: INFO: RDP server closed/refused connection: Security negotiation failed (wrong security type?) 2024-01-12 11:24:34 guacd[1555]: INFO: User "@f2ce880f-b4dd-4512-9685-31a1da763c5a" disconnected (0 users remain) 2024-01-12 11:24:34 guacd[1555]: INFO: Last user of connection "$003920a5-932f-44c4-8279-8c37378990ab" disconnected 2024-01-12 11:24:34 guacd[1555]: DEBUG: Requesting termination of client... 2024-01-12 11:24:34 guacd[1555]: DEBUG: Client terminated successfully. 2024-01-12 11:24:34 guacd[1]: INFO: Connection "$003920a5-932f-44c4-8279-8c37378990ab" removed. 2024-01-12 11:24:34 guacd[1]: DEBUG: Unable to request termination of client process: No such process 2024-01-12 11:24:34 guacd[1]: DEBUG: All child processes for connection "$003920a5-932f-44c4-8279-8c37378990ab" have been terminated. Is there another dependency that's worth testing an image built to match your version? On Fri, Jan 12, 2024 at 12:10 AM michael böhm <[email protected]> wrote: > Hello, > > I can confirm Weston's observations. I could reproduce it by connecting 59 > times to to an RDP desktop with SSH enabled. On the 60th attempt it did not > work anymore (I might have got the count wrong by 1, so it could have very > well also been after the 58th attempt). > > On the failing attempts there is the following in docker host's dmesg: > > [Fri Jan 12 08:54:09 2024] guacd[2454882]: segfault at 8 ip > 00007fe9c9b5a7a2 sp 00007fe9c6c4b0b8 error 4 in > ld-musl-x86_64.so.1[7fe9c9b18000+4c000] > [Fri Jan 12 08:54:09 2024] Code: e8 ef 16 00 00 31 c0 5a c3 31 c0 c3 b8 16 > 00 00 00 c3 b9 0a 00 00 00 31 c0 48 89 fa f3 ab 48 85 f6 74 04 8b 06 89 02 > 31 c0 c3 <8b> 07 83 e0 0f 74 07 31 f6 e9 15 00 00 00 ba 10 00 00 00 f0 0f b1 > [Fri Jan 12 08:54:40 2024] guacd[2455844]: segfault at 8 ip > 00007fe9c9b5a7a2 sp 00007fe9c6c4b0b8 error 4 in > ld-musl-x86_64.so.1[7fe9c9b18000+4c000] > [Fri Jan 12 08:54:40 2024] Code: e8 ef 16 00 00 31 c0 5a c3 31 c0 c3 b8 16 > 00 00 00 c3 b9 0a 00 00 00 31 c0 48 89 fa f3 ab 48 85 f6 74 04 8b 06 89 02 > 31 c0 c3 <8b> 07 83 e0 0f 74 07 31 f6 e9 15 00 00 00 ba 10 00 00 00 f0 0f b1 > [Fri Jan 12 08:55:10 2024] guacd[2456174]: segfault at 8 ip > 00007fe9c9b5a7a2 sp 00007fe9c6c620b8 error 4 in > ld-musl-x86_64.so.1[7fe9c9b18000+4c000] > [Fri Jan 12 08:55:10 2024] Code: e8 ef 16 00 00 31 c0 5a c3 31 c0 c3 b8 16 > 00 00 00 c3 b9 0a 00 00 00 31 c0 48 89 fa f3 ab 48 85 f6 74 04 8b 06 89 02 > 31 c0 c3 <8b> 07 83 e0 0f 74 07 31 f6 e9 15 00 00 00 ba 10 00 00 00 f0 0f b1 > [Fri Jan 12 08:55:40 2024] guacd[2456750]: segfault at 8 ip > 00007fe9c9b5a7a2 sp 00007fe9c6c620b8 error 4 in > ld-musl-x86_64.so.1[7fe9c9b18000+4c000] > [Fri Jan 12 08:55:40 2024] Code: e8 ef 16 00 00 31 c0 5a c3 31 c0 c3 b8 16 > 00 00 00 c3 b9 0a 00 00 00 31 c0 48 89 fa f3 ab 48 85 f6 74 04 8b 06 89 02 > 31 c0 c3 <8b> 07 83 e0 0f 74 07 31 f6 e9 15 00 00 00 ba 10 00 00 00 f0 0f b1 > [Fri Jan 12 08:56:42 2024] guacd[2457875]: segfault at 8 ip > 00007fe9c9b5a7a2 sp 00007fe9c6c620b8 error 4 in > ld-musl-x86_64.so.1[7fe9c9b18000+4c000] > [Fri Jan 12 08:56:42 2024] Code: e8 ef 16 00 00 31 c0 5a c3 31 c0 c3 b8 16 > 00 00 00 c3 b9 0a 00 00 00 31 c0 48 89 fa f3 ab 48 85 f6 74 04 8b 06 89 02 > 31 c0 c3 <8b> 07 83 e0 0f 74 07 31 f6 e9 15 00 00 00 ba 10 00 00 00 f0 0f b1 > [Fri Jan 12 08:58:39 2024] guacd[2460389]: segfault at 8 ip > 00007fe9c9b5a7a2 sp 00007fe9c6c620b8 error 4 in > ld-musl-x86_64.so.1[7fe9c9b18000+4c000] > [Fri Jan 12 08:58:39 2024] Code: e8 ef 16 00 00 31 c0 5a c3 31 c0 c3 b8 16 > 00 00 00 c3 b9 0a 00 00 00 31 c0 48 89 fa f3 ab 48 85 f6 74 04 8b 06 89 02 > 31 c0 c3 <8b> 07 83 e0 0f 74 07 31 f6 e9 15 00 00 00 ba 10 00 00 00 f0 0f b > > guacd's docker logs on a failing connection: > > guacd[1]: INFO: Creating new client for protocol "rdp" > guacd[1]: INFO: Connection ID is "$d39d01e0-5101-4d79-bd8d-a8620c389efa" > guacd[1800]: WARNING: FreeRDP initialization may fail: Writability of > the current user's home directory ("/home/guacd") could not be determined: > Read-only file system > guacd[1800]: INFO: No security mode specified. Defaulting to security > mode negotiation with server. > guacd[1800]: INFO: Resize method: display-update > guacd[1800]: INFO: No clipboard line-ending normalization specified. > Defaulting to preserving the format of all line endings. > guacd[1800]: INFO: User "@ad5b9532-c914-4fc0-be0f-3e7a247157c7" joined > connection "$d39d01e0-5101-4d79-bd8d-a8620c389efa" (1 users now present) > guacd[1800]: ERROR: SSH handshake failed. > guacd[1]: INFO: Connection "$d39d01e0-5101-4d79-bd8d-a8620c389efa" > removed. > > More info on my environment in my thread in this mailing list on Tuesday, > January 9, 2024 8:03:04 PM GMT+1. > > I added a nightly "docker restart guacd" cronjob to the host as a quick > workaround. > > Best wishes > > Michael > *Gesendet:* Freitag, 12. Januar 2024 um 02:42 Uhr > *Von:* "Nick Couchman" <[email protected]> > *An:* [email protected] > *Betreff:* Re: Major bug message log in guacd 1.5.4 > On Thu, Jan 11, 2024 at 5:42 PM Weston Thayer <[email protected]> > wrote: > >> Overall. Our test is just 1 user re-connecting to the same VM over RDP >> over and over. >> > > Thanks for clarifying. FWIW, I'm running Guacamole 1.5.4 (native > build/install), on CentOS 7 (FreeRDP 2.2.0), and I've gone waaaaay past the > 58th successive connection without hitting this issue. > > -Nick > >> >> >> --------------------------------------------------------------------- To > unsubscribe, e-mail: [email protected] For additional > commands, e-mail: [email protected]
