Dynamic Resolution can cause distortion with FreeRDP

[yaroslavros]

It seems that with a certain chance changing size of FreeRDP client window when dynamic resolution is enabled (/dynamic-resolution) can cause graphic distortion in right column of random width.

I observe this behaviour on Linux and Mac of XFreeRDP 2.0.0rc4 as well as master.

This happens randomly (~50% chance) and width of distorted column is also random.

After another window resize this problem may go away or re-appear with different width of distorted column.

I do not see anything relevant in FreeRDP or Redemption logs.

Problem does not occur with any other RDP client or when FreeRDP connects to windows machine directly.

I tried 7.3.41, 7.3.13 and 7.4.1

[yaroslavros]

Note sure if that's relevant or helpful in troubleshooting this, but few times during a lot of resizing I got TLS session disconnected between redemption and server (Windows 10) with following error message:
partial_recv_tls error:1408F119:SSL routines:ssl3_get_record:decryption failed or bad record mac

Here is complete log:
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- LOOPING on PDUs: 13
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- Deactivate All PDU
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- LOOPING on PDUs: 457
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_synchronise
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_synchronise done
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_control
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_control done
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_control
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_control done
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- use rdp5
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_fonts
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_fonts done
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_input_fastpath: Synchronize Event toggleFlags=0x0
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- LOOPING on PDUs: 42
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- PDUTYPE_DATAPDU
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- WAITING_SYNCHRONIZE
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- Rdp::receiving the server-to-client Monitor Layout PDU MonitorLayoutPDU monitorCount=1 ((left=0, top=0, right=1689, bottom=761, primary=yes(0x1)))
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- Front::server_relayout: Send to client MonitorLayoutPDU monitorCount=1 ((left=0, top=0, right=1689, bottom=761, primary=yes(0x1)))
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- Dimension=Dimension(1690 762)
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- LOOPING on PDUs: 22
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- PDUTYPE_DATAPDU
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- WAITING_SYNCHRONIZE
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- Resizing to 1690x762x16
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- Front::server_resize: Resizing client to : 1690 x 762 x 16
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- Front::server_resize: ACTIVATED (resize)
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- LOOPING on PDUs: 26
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- PDUTYPE_DATAPDU
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- WAITING_CTL_COOPERATE
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- LOOPING on PDUs: 26
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- PDUTYPE_DATAPDU
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- WAITING_GRANT_CONTROL_COOPERATE
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- LOOPING on PDUs: 26
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- PDUTYPE_DATAPDU
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- PDUTYPE2_FONTMAP
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_input_fastpath: Synchronize Event toggleFlags=0x0
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- Front::can_be_start_capture: Capture is not necessary
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- Front::incoming: (Fast-Path) Synchronize Event toggleFlags=0x2
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_input_fastpath: Synchronize Event toggleFlags=0x2
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- Front::incoming: (Fast-Path) Synchronize Event toggleFlags=0x2
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_input_fastpath: Synchronize Event toggleFlags=0x2
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- LOOPING on PDUs: 13
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- Deactivate All PDU
Nov 29 08:19:13 x.y.z rdpproxy[30485]: WARNING (30485/30485) -- LOOPING on PDUs: 457
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_synchronise
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_synchronise done
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_control
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_control done
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_control
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_control done
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- use rdp5
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_fonts
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_fonts done
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- mod_rdp::send_input_fastpath: Synchronize Event toggleFlags=0x0
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- partial_recv_tls error:00000001:lib(0):func(0):reason(1)
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- partial_recv_tls error:1408F119:SSL routines:ssl3_get_record:decryption failed or bad record mac
Nov 29 08:19:13 x.y.z rdpproxy[30485]: ERR (30485/30485) -- SocketTransport::do_partial_read: Failed to read from socket! (RDP Target)
Nov 29 08:19:13 x.y.z rdpproxy[30485]: ERR (30485/30485) -- Session::Session exception (2) = Exception ERR_TRANSPORT_NO_MORE_DATA no: 1501
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- ----------> ACL invoke_close_box <--------
Nov 29 08:19:13 x.y.z rdpproxy[30485]: [rdpproxy] psid="157501180830485" user="richard.crosno" type="TARGET_DISCONNECTION" reason="Exception ERR_TRANSPORT_NO_MORE_DATA no: 1501"
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- ~mod_rdp(): Recv bmp cache count = 0
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- ~mod_rdp(): Recv order count = 1926
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- ~mod_rdp(): Recv bmp update count = 1201
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- BmpCache: Mod_rdp (0=>0, 121) (1=>0, 121) (2=>0, 2554, persistent) (3=>0, 0) (4=>0, 0)
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- RDP Target (-1): total_received=7818049, total_sent=66623
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- ----------> ACL new_mod <--------
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- target_module=MODULE_INTERNAL_CLOSE(5)
Nov 29 08:19:13 x.y.z rdpproxy[30485]: ERR (30485/30485) -- OutCryptoTransport::close Renaming file "red-TKdWt3.tmp" -> "" failed, errno=2 : No such file or directory
Nov 29 08:19:13 x.y.z rdpproxy[30485]: ERR (30485/30485) -- Session::Session exception (2) = Exception ERR_TRANSPORT_WRITE_FAILED no: 1502
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- ----------> ACL invoke_close_box <--------
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- ----------> ACL new_mod <--------
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- target_module=MODULE_INTERNAL_CLOSE(5)
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- ModuleManager::Creation of new mod 'INTERNAL::Close'
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- WabCloseMod: Ending session in 600 seconds
Nov 29 08:19:13 x.y.z rdpproxy[30485]: INFO (30485/30485) -- ModuleManager::internal module Close ready