FreeRDP / FreeRDP

FreeRDP is a free remote desktop protocol library and clients
http://www.freerdp.com/
Apache License 2.0
11.03k stars 14.86k forks source link

Keyboard disabled after idle time #7217

Closed UnoSD closed 3 weeks ago

UnoSD commented 3 years ago

Describe the bug When leaving the session inactive for a certain variable amount of time, often the keyboard does not respond anymore when trying to interact again with the remote machine. Mouse still works regularly. Nothing flagged in the logs. Happens on multiple Win 10 machines.

To Reproduce Steps to reproduce the behavior:

  1. Connect to remote machine
  2. Use the remote machine
  3. Stop interacting with the session (either walking away from the machine entirely or just use the client machine, even during Teams meetings on the remote machine).
  4. Try to type something in the session with the keyboard

Expected behavior Input keys to work on remote machine (regular text, control keys, anything on the keyboard)

Application details

Regular log, will update with trace level when it happens again:

[10:51:37:190] [9808:9809] [INFO][com.freerdp.core] - freerdp_connect:freerdp_set_last_error_ex resetting error state
[10:51:37:190] [9808:9809] [INFO][com.freerdp.client.common.cmdline] - loading channelEx rdpdr
[10:51:37:190] [9808:9809] [INFO][com.freerdp.client.common.cmdline] - loading channelEx rdpsnd
[10:51:37:190] [9808:9809] [INFO][com.freerdp.client.common.cmdline] - loading channelEx drdynvc
[10:51:37:500] [9808:9809] [INFO][com.freerdp.primitives] - primitives autodetect, using optimized
[10:51:37:502] [9808:9809] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[10:51:37:502] [9808:9809] [INFO][com.freerdp.core] - freerdp_tcp_connect:freerdp_set_last_error_ex resetting error state
[10:51:41:536] [9808:9809] [INFO][com.freerdp.gdi] - Local framebuffer format  PIXEL_FORMAT_BGRX32
[10:51:41:536] [9808:9809] [INFO][com.freerdp.gdi] - Remote framebuffer format PIXEL_FORMAT_RGB16
[10:51:41:607] [9808:9809] [INFO][com.winpr.clipboard] - initialized POSIX local file subsystem
[10:51:41:617] [9808:9809] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[10:51:41:617] [9808:9809] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[10:51:41:617] [9808:9809] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[10:51:41:620] [9808:9809] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[10:51:41:863] [9808:9840] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[swscaler @ 0x7fd7a43db6c0] Warning: data is not aligned! This can lead to a speed loss

Environment (please complete the following information):

akallabeth commented 3 years ago

Can not reproduce, no changes since 2.0.0, requires additional description.

UnoSD commented 3 years ago

Anything in particular you would like to see? I ran the session on verbose logging and I got 250MB of logs, I can try again to reproduce it in a shorter period.

akallabeth commented 3 years ago

@UnoSD could you check which com.freerdp.client.X11 log messages you got (assuming it was build with -DWITH_DEBUG_X11=ON)? If you get KeyPress Event(<number>): wnd=0x<number> and KeyRelease Event(<number>): wnd=0x<number> messages and the keyboard does not work I´m all ears. (then there might be a problem with FreeRDP or the server)

If you don´t get these, there is something wrong outside xfreerdp (these are the X11 events that are emitted when a window with keyboard focus receives a keypress/release) and we can´t fix your issue.

UnoSD commented 3 years ago

@akallabeth xfreerdp /buildconfig 2>&1 | grep WITH_DEBUG_X11 returns WITH_DEBUG_X11=OFF

keyboard works outside of FreeRDP, so if it's not the application itself may be some issue with X11->FreeRDP.

Should I rebuild it to enable that flag?

akallabeth commented 3 years ago

@UnoSD yes, please rebuild with that. Then we´d at least know if the X11 events arrive within freerdp.

UnoSD commented 3 years ago
[12:22:18:515] [27686:27687] [INFO][com.freerdp.core] - freerdp_connect:freerdp_set_last_error_ex resetting error state
[12:22:18:515] [27686:27687] [INFO][com.freerdp.client.common.cmdline] - loading channelEx rdpdr
[12:22:18:515] [27686:27687] [INFO][com.freerdp.client.common.cmdline] - loading channelEx rdpsnd
[12:22:18:515] [27686:27687] [INFO][com.freerdp.client.common.cmdline] - loading channelEx drdynvc
[12:22:18:826] [27686:27687] [INFO][com.freerdp.primitives] - primitives autodetect, using optimized
[12:22:18:829] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:18:829] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:19:952] [27686:27687] [INFO][com.freerdp.gdi] - Local framebuffer format  PIXEL_FORMAT_BGRX32
[12:22:19:952] [27686:27687] [INFO][com.freerdp.gdi] - Remote framebuffer format PIXEL_FORMAT_RGB16
[12:22:19:050] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:19:050] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:19:050] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:19:052] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:19:130] [27686:27708] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:20:704] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:20:704] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:20:704] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:20:704] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:20:704] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:20:704] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:20:704] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:20:704] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:20:739] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:20:739] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:21:399] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:21:399] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:21:399] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:21:402] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:21:479] [27686:27726] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:22:905] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:22:905] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:22:905] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:22:905] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:22:905] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:22:905] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:22:905] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:22:905] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:22:977] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:22:977] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:23:471] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:23:471] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:23:471] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:23:474] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:24:525] [27686:27745] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:24:933] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:24:933] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:24:933] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:24:933] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:24:933] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:24:933] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:24:933] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:24:933] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:24:953] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:24:953] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:25:418] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:25:418] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:25:418] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:25:420] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:26:777] [27686:27763] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:26:049] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:26:049] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:26:049] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:26:049] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:26:049] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:26:049] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:26:049] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:26:049] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:26:098] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:26:098] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:28:572] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:28:573] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:28:573] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:28:575] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:28:604] [27686:27782] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:28:134] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:28:134] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:28:134] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:28:134] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:28:134] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:28:134] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:28:134] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:28:134] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:28:163] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:28:163] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:30:522] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:30:523] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:30:523] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:30:525] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:30:919] [27686:27801] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:30:146] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:30:146] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:30:146] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:30:146] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:30:146] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:30:146] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:30:146] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:30:146] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:30:202] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:30:202] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:32:796] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:32:796] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:32:796] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:32:798] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:32:127] [27686:27819] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:32:202] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:32:202] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:32:202] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:32:202] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:32:202] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:32:202] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:32:202] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:32:202] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:32:252] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:32:252] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:34:893] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:34:893] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:34:893] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:34:894] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:34:228] [27686:27838] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:35:708] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:35:708] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:35:708] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:35:708] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:35:708] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:35:708] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:35:708] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:35:708] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:35:765] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:35:765] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:37:672] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:37:672] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:37:672] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:37:674] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:37:267] [27686:27858] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:37:440] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:37:440] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:37:440] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:37:440] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:37:440] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:37:440] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:37:440] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:37:440] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:37:473] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:37:473] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:39:163] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:39:163] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:39:163] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:39:166] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:40:545] [27686:27878] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:40:695] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:40:695] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:40:695] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:40:695] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:40:695] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:40:695] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:40:695] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:40:695] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:40:743] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:40:743] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:41:397] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:41:397] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:41:397] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:41:400] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:42:793] [27686:27897] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:42:160] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:42:161] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:42:161] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:42:161] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:42:161] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:42:161] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:42:161] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:42:161] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:42:202] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:42:202] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:44:372] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:44:372] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:44:372] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:44:375] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:45:942] [27686:27917] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:45:249] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:45:249] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:45:249] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:45:249] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:45:249] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:45:249] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:45:249] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:45:249] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:45:294] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:45:294] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:47:338] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:47:338] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:47:339] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:47:341] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:48:959] [27686:27936] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:48:272] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:48:272] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:48:272] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:48:272] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:48:272] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:48:272] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:48:272] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:48:272] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:48:332] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:48:332] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:50:776] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:50:776] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:50:776] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:50:779] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:50:980] [27686:27954] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:50:388] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:50:389] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:50:389] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:50:389] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:50:389] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:50:389] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:50:389] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:50:389] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:50:443] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:50:443] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:52:114] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:52:114] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:52:114] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:52:116] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:52:404] [27686:27976] [INFO][com.freerdp.channels.rdpsnd.client] - [dynamic] Loaded pulse backend for rdpsnd
[12:22:53:683] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support!
[12:22:53:683] [27686:27687] [ERROR][com.freerdp.core.fastpath] - Fastpath update New Pointer [b] failed, status 0
[12:22:53:683] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update() - -1
[12:22:53:683] [27686:27687] [ERROR][com.freerdp.core.fastpath] - fastpath_recv_update_data() fail
[12:22:53:683] [27686:27687] [ERROR][com.freerdp.core.transport] - transport_check_fds: transport->ReceiveCallback() - -3
[12:22:53:683] [27686:27687] [ERROR][com.freerdp.core] - freerdp_check_fds() failed - 0
[12:22:53:683] [27686:27687] [INFO][com.freerdp.client.common] - Network disconnect!
[12:22:53:683] [27686:27687] [INFO][com.freerdp.client.common] - Attempting reconnect (1 of 20)
[12:22:53:749] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_is_hostname_resolvable:freerdp_set_last_error_ex resetting error state
[12:22:53:749] [27686:27687] [INFO][com.freerdp.core] - freerdp_tcp_default_connect:freerdp_set_last_error_ex resetting error state
[12:22:54:291] [27686:27687] [INFO][com.freerdp.channels.rdpsnd.client] - [static] Loaded pulse backend for rdpsnd
[12:22:54:291] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel rdpsnd
[12:22:54:291] [27686:27687] [INFO][com.freerdp.channels.drdynvc.client] - Loading Dynamic Virtual Channel audin
[12:22:54:294] [27686:27687] [INFO][com.freerdp.channels.audin.client] - Loaded pulse backend for audin
[12:22:54:323] [27686:27687] [INFO][com.freerdp.client.x11] - Closed from X11

@akallabeth I cloned and built the repository from GitHub, but when I try and use that version to connect, seems to go in a loop from the logs and just stay on a black window on the UI. I have added the log above, any suggestion? Should I set the repo to a certain tag for a stable version or enable more verbose logging to figure out why it's stuck?

akallabeth commented 3 years ago

@UnoSD well, your command line requests something that is not compiled in: [12:22:20:704] [27686:27687] [WARN][com.freerdp.color] - SmartScaling requested but compiled without libcairo support! install swscale or cairo development headers and retry ;)

UnoSD commented 3 years ago

@akallabeth I managed to reproduce the error with that flag enabled, it's a 480MB log, I have added here the tail, please let me know if you want me to add more lines or upload the entire lot somewhere.

[10:36:31:087] [268915:268916] [TRACE][com.freerdp.client.x11] - xf_lock_x11_:  [1] from xf_Pointer_Free
[10:36:31:087] [268915:268916] [TRACE][com.freerdp.client.x11] - xf_unlock_x11_:[0] from xf_Pointer_Free
[10:36:31:087] [268915:268916] [TRACE][com.freerdp.client.x11] - xf_lock_x11_:  [1] from xf_Pointer_Free
[10:36:31:087] [268915:268916] [TRACE][com.freerdp.client.x11] - xf_unlock_x11_:[0] from xf_Pointer_Free
[10:36:31:087] [268915:268916] [TRACE][com.freerdp.client.x11] - xf_lock_x11_:  [1] from xf_Pointer_Free
[10:36:31:087] [268915:268916] [TRACE][com.freerdp.client.x11] - xf_unlock_x11_:[0] from xf_Pointer_Free
[10:36:31:087] [268915:268916] [TRACE][com.freerdp.client.x11] - xf_lock_x11_:  [1] from xf_Pointer_Free
[10:36:31:087] [268915:268916] [TRACE][com.freerdp.client.x11] - xf_unlock_x11_:[0] from xf_Pointer_Free
[10:36:31:087] [268915:268916] [TRACE][com.freerdp.client.x11] - xf_lock_x11_:  [1] from xf_Pointer_Free
[10:36:31:087] [268915:268916] [TRACE][com.freerdp.client.x11] - xf_unlock_x11_:[0] from xf_Pointer_Free

I kept hitting keys on the keyboard with the focus on the window. I can see key events if I grep the lock/unlock messages out:

grep -v 'xf_unlock\|xf_lock' xfrdp.logs.txt | tail -n 40

[10:36:29:527] [268915:268916] [DEBUG][com.freerdp.client.x11] - KeyRelease Event(3): wnd=0x06600001
[10:36:29:527] [268915:268916] [DEBUG][com.freerdp.client.x11] - KeyPress Event(2): wnd=0x06600001
[10:36:29:599] [268915:268916] [DEBUG][com.freerdp.client.x11] - KeyRelease Event(3): wnd=0x06600001
[10:36:29:647] [268915:268916] [DEBUG][com.freerdp.client.x11] - KeyPress Event(2): wnd=0x06600001
[10:36:29:687] [268915:268916] [DEBUG][com.freerdp.client.x11] - KeyPress Event(2): wnd=0x06600001
[10:36:30:703] [268915:268916] [DEBUG][com.freerdp.client.x11] - KeyRelease Event(3): wnd=0x06600001
[10:36:30:767] [268915:268916] [DEBUG][com.freerdp.client.x11] - KeyRelease Event(3): wnd=0x06600001
[10:36:30:815] [268915:268916] [DEBUG][com.freerdp.client.x11] - KeyRelease Event(3): wnd=0x06600001
[10:36:30:013] [268915:268916] [DEBUG][com.freerdp.core.heartbeat] - received Heartbeat PDU -> period=1, count1=8, count2=8
[10:36:30:063] [268915:268916] [TRACE][com.freerdp.core.update] - BitmapUpdate: 9
[10:36:30:109] [268915:268916] [TRACE][com.freerdp.core.update] - BitmapUpdate: 9
[10:36:30:159] [268915:268916] [TRACE][com.freerdp.core.autodetect] - rdp_recv_autodetect_request_packet: headerLength=6, headerTypeId=0, sequenceNumber=0, requestType=0014
[10:36:30:159] [268915:268916] [TRACE][com.freerdp.core.autodetect] - received Bandwidth Measure Start PDU - time=383460159
[10:36:30:163] [268915:268916] [TRACE][com.freerdp.core.update] - BitmapUpdate: 86
[10:36:30:181] [268915:268916] [TRACE][com.freerdp.core.autodetect] - rdp_recv_autodetect_request_packet: headerLength=6, headerTypeId=0, sequenceNumber=0, requestType=0429
[10:36:30:181] [268915:268916] [TRACE][com.freerdp.core.autodetect] - received Bandwidth Measure Stop PDU -> payloadLength=0
[10:36:30:181] [268915:268916] [TRACE][com.freerdp.core.autodetect] - sending Bandwidth Measure Results PDU -> timeDelta=22, byteCount=14787
[10:36:30:198] [268915:268916] [DEBUG][com.freerdp.client.x11] - LeaveNotify Event(8): wnd=0x06600001
[10:36:30:199] [268915:268916] [DEBUG][com.freerdp.client.x11] - FocusOut Event(10): wnd=0x06600001
[10:36:30:199] [268915:268916] [DEBUG][com.freerdp.client.x11] - FocusIn Event(9): wnd=0x06600001
[10:36:30:210] [268915:268916] [TRACE][com.freerdp.core.autodetect] - rdp_recv_autodetect_request_packet: headerLength=6, headerTypeId=0, sequenceNumber=0, requestType=0014
[10:36:30:210] [268915:268916] [TRACE][com.freerdp.core.autodetect] - received Bandwidth Measure Start PDU - time=383460210
[10:36:30:211] [268915:268916] [TRACE][com.freerdp.core.update] - BitmapUpdate: 92
[10:36:30:219] [268915:268916] [TRACE][com.freerdp.core.autodetect] - rdp_recv_autodetect_request_packet: headerLength=6, headerTypeId=0, sequenceNumber=0, requestType=0429
[10:36:30:219] [268915:268916] [TRACE][com.freerdp.core.autodetect] - received Bandwidth Measure Stop PDU -> payloadLength=0
[10:36:30:219] [268915:268916] [TRACE][com.freerdp.core.autodetect] - sending Bandwidth Measure Results PDU -> timeDelta=9, byteCount=1742
[10:36:30:259] [268915:268916] [TRACE][com.freerdp.core.update] - BitmapUpdate: 10
[10:36:30:307] [268915:268916] [TRACE][com.freerdp.core.update] - BitmapUpdate: 7
[10:36:30:631] [268915:268916] [DEBUG][com.freerdp.client.x11] - EnterNotify Event(7): wnd=0x06600001
[10:36:30:633] [268915:268916] [DEBUG][com.freerdp.client.x11] - FocusOut Event(10): wnd=0x06600001
[10:36:30:634] [268915:268916] [DEBUG][com.freerdp.client.x11] - FocusIn Event(9): wnd=0x06600001
[10:36:30:663] [268915:268916] [DEBUG][com.freerdp.client.x11] - LeaveNotify Event(8): wnd=0x06600001
[10:36:30:670] [268915:268916] [DEBUG][com.freerdp.client.x11] - FocusOut Event(10): wnd=0x06600001
[10:36:30:671] [268915:268916] [DEBUG][com.freerdp.client.x11] - FocusIn Event(9): wnd=0x06600001
[10:36:31:023] [268915:268916] [DEBUG][com.freerdp.client.x11] - ClientMessage Event(33): wnd=0x06600001
[10:36:31:023] [268915:268916] [DEBUG][com.freerdp.client.x11] - Main window closed
[10:36:31:023] [268915:268916] [INFO][com.freerdp.client.x11] - Closed from X11
[10:36:31:067] [268915:268967] [DEBUG][com.freerdp.channels.drdynvc.client] - close_channel_iface: id=14
[10:36:31:068] [268915:268916] [TRACE][com.freerdp.channels.audin.client] - ...
[10:36:31:069] [268915:268916] [DEBUG][com.freerdp.channels.audin.client] - context state PA_CONTEXT_TERMINATED
akallabeth commented 3 years ago

@UnoSD if you see the messages after the keyboard is disabled then it is a server side issue as the keypress/release events are sent.

UnoSD commented 3 years ago

@akallabeth I can't see any keyboard is disabled message in the logs, no results for grep keyboard xfrdp.logs.save.txt

I can see the KeyRelease and KeyPress messages above in the logs and nothing happens on the remote machine.

This happened on more than one remote machine (all Windows 10, but different versions) so I'm skeptical it could be a problem with the target.

Anything else I can do to troubleshoot?

akallabeth commented 3 years ago

@UnoSD that was a reference to the issue title.

UnoSD commented 3 years ago

@akallabeth I wasn't sure as you put it in quotes :), but I also answered to the other thing below. After it is disabled, I still got the messages, but it would be strage if it was up to the server as it happens on multiple machines.

akallabeth commented 3 years ago

@UnoSD well, it is the same as with mouse events, they get sent and the server does something with them. Since both use the same connection there is not much client wise that can fail (e.g. if the mouse works it means the connection is there...)

akallabeth commented 3 years ago

you might try a focus change (that triggers a keyboard state resync, e.g. num/caps/scroll lock sync) and check if that helps.

UnoSD commented 3 years ago

@akallabeth I can try using another client and see if I get the same issue.

As for the focus, I did try that, both in the client and in the server.

Reconnecting helps as it works again.

github-actions[bot] commented 1 month ago

This issue is stale because it has been open for 30 days with no activity.

github-actions[bot] commented 3 weeks ago

This issue was closed because it has been inactive for 14 days since being marked as stale.

UnoSD commented 2 weeks ago

hi all, I am still experiencing the issue. I'm just disconnecting and reconnecting again when it happens. I also noticed that sometimes, after a period of idle, if I resume working (with mouse only, of course), after a random bit of time, the keyboard starts working again.

akallabeth commented 2 weeks ago

@UnoSD then please provide a log that shows it is the client not sending keyboard events (and not just a server stuck in some invalid state) you need:

  1. a build with -DWITH_DEBUG_X11=ON -DWITH_DEBUG_KBD=ON
  2. grep for x11 keycode: and remapped scancode: and KeyRelease Event( and KeyRelease Event(

if you see KeyRelease Event( and KeyRelease Event( not followed by x11 keycode: or remapped scancode: then it is something with the client. if you see them and the remote does not do something check your server

UnoSD commented 2 weeks ago

thanks, @akallabeth I have rebuilt the package with the debug flags and I will use it grepping for the events until it happens again and let you know.

here:

and KeyRelease Event( and KeyRelease Event(

did you mean KeyPress and KeyRelease?

akallabeth commented 2 weeks ago

did you mean KeyPress and KeyRelease?

You got me 😁

UnoSD commented 1 week ago

a small update:

I've been using the version built with the debug flags and /log-level:DEBUG | grep 'x11 keycode:\|remapped scancode:\|KeyPress Event(\|KeyRelease Event('

and I noticed something interesting: when it stops working, if I move the focus to the terminal window and I move it back to the RDP session, it starts working again.

Bad news is that, while I notice this, I also noticed that it wasn't capturing the debug events and it turns out my system updated and replaced the version I built with the debug flags with a new one without it 😅. I'll reinstall the debug version give it another go. Sorry for the wait.