search

neutrinolabs / xrdp

xrdp: an open source RDP server
http://www.xrdp.org/
Apache License 2.0
5.77k stars 1.73k forks source link

Connection failure when using mstsc to connect to xrdp through freerdp-proxy version 3.x.x #3256

Closed StudyAndGrow closed 3 weeks ago

StudyAndGrow commented 1 month ago

xrdp version

0.10.1

Detailed xrdp version, build options

Paste the result between `~~~`.  Please DO NOT remove `~~~`!

Operating system & version

oraclelinux:9

Installation method

dnf / apt / zypper / pkg / etc

Which backend do you use?

Xvnc

What desktop environment do you use?

No response

Environment xrdp running on

No response

What's your client?

freerdp-proxy

Area(s) with issue?

No response

Steps to reproduce

Connection failure when using mstsc to connect to xrdp through freerdp-proxy version 3.x.x The xrdp log is as follows:

[2024-09-24T06:04:21.298+0000] [INFO ] Socket 13: connection accepted from [::ffff:192.168.0.199]:42090
[2024-09-24T06:04:21.318+0000] [DEBUG] Closed socket 13 ([::ffff:172.20.0.2]:3389)
[2024-09-24T06:04:21.318+0000] [DEBUG] Closed socket 12 ([::]:3389)
[2024-09-24T06:04:21.319+0000] [DEBUG] item ini_version, value 1
[2024-09-24T06:04:21.320+0000] [DEBUG] item fork, value true
[2024-09-24T06:04:21.320+0000] [DEBUG] item port, value 3389
[2024-09-24T06:04:21.320+0000] [DEBUG] item use_vsock, value false
[2024-09-24T06:04:21.320+0000] [DEBUG] item tcp_nodelay, value true
[2024-09-24T06:04:21.321+0000] [DEBUG] item tcp_keepalive, value true
[2024-09-24T06:04:21.321+0000] [DEBUG] item security_layer, value negotiate
[2024-09-24T06:04:21.321+0000] [DEBUG] item crypt_level, value none
[2024-09-24T06:04:21.321+0000] [DEBUG] item certificate, value 
[2024-09-24T06:04:21.322+0000] [INFO ] Using default X.509 certificate: /etc/xrdp/cert.pem
[2024-09-24T06:04:21.322+0000] [DEBUG] item key_file, value 
[2024-09-24T06:04:21.322+0000] [INFO ] Using default X.509 key file: /etc/xrdp/key.pem
[2024-09-24T06:04:21.322+0000] [DEBUG] item ssl_protocols, value TLSv1.2, TLSv1.3
[2024-09-24T06:04:21.323+0000] [DEBUG] TLSv1.3 enabled
[2024-09-24T06:04:21.323+0000] [DEBUG] TLSv1.2 enabled
[2024-09-24T06:04:21.323+0000] [DEBUG] item autorun, value 
[2024-09-24T06:04:21.323+0000] [DEBUG] item allow_channels, value true
[2024-09-24T06:04:21.324+0000] [DEBUG] item allow_multimon, value true
[2024-09-24T06:04:21.324+0000] [DEBUG] item bitmap_cache, value true
[2024-09-24T06:04:21.324+0000] [DEBUG] item bitmap_compression, value true
[2024-09-24T06:04:21.324+0000] [DEBUG] item bulk_compression, value true
[2024-09-24T06:04:21.325+0000] [DEBUG] item max_bpp, value 24
[2024-09-24T06:04:21.325+0000] [DEBUG] item new_cursors, value true
[2024-09-24T06:04:21.325+0000] [DEBUG] item use_fastpath, value both
[2024-09-24T06:04:21.325+0000] [DEBUG] item blue, value 009cb5
[2024-09-24T06:04:21.326+0000] [DEBUG] item grey, value dedede
[2024-09-24T06:04:21.326+0000] [DEBUG] item ls_top_window_bg_color, value 009cb5
[2024-09-24T06:04:21.326+0000] [DEBUG] item ls_width, value 350
[2024-09-24T06:04:21.326+0000] [DEBUG] item ls_height, value 430
[2024-09-24T06:04:21.326+0000] [DEBUG] item ls_bg_color, value dedede
[2024-09-24T06:04:21.327+0000] [DEBUG] item ls_logo_filename, value 
[2024-09-24T06:04:21.327+0000] [DEBUG] item ls_logo_x_pos, value 55
[2024-09-24T06:04:21.327+0000] [DEBUG] item ls_logo_y_pos, value 50
[2024-09-24T06:04:21.327+0000] [DEBUG] item ls_label_x_pos, value 30
[2024-09-24T06:04:21.328+0000] [DEBUG] item ls_label_width, value 65
[2024-09-24T06:04:21.328+0000] [DEBUG] item ls_input_x_pos, value 110
[2024-09-24T06:04:21.328+0000] [DEBUG] item ls_input_width, value 210
[2024-09-24T06:04:21.328+0000] [DEBUG] item ls_input_y_pos, value 220
[2024-09-24T06:04:21.329+0000] [DEBUG] item ls_btn_ok_x_pos, value 142
[2024-09-24T06:04:21.329+0000] [DEBUG] item ls_btn_ok_y_pos, value 370
[2024-09-24T06:04:21.329+0000] [DEBUG] item ls_btn_ok_width, value 85
[2024-09-24T06:04:21.329+0000] [DEBUG] item ls_btn_ok_height, value 30
[2024-09-24T06:04:21.330+0000] [DEBUG] item ls_btn_cancel_x_pos, value 237
[2024-09-24T06:04:21.330+0000] [DEBUG] item ls_btn_cancel_y_pos, value 370
[2024-09-24T06:04:21.330+0000] [DEBUG] item ls_btn_cancel_width, value 85
[2024-09-24T06:04:21.330+0000] [DEBUG] item ls_btn_cancel_height, value 30
[2024-09-24T06:04:21.331+0000] [INFO ] Security protocol: configured [SSL|RDP], requested [SSL|HYBRID|RDP], selected [SSL]
[2024-09-24T06:04:21.341+0000] [DEBUG] Using TLS security, and setting RDP security crypto to LEVEL_NONE and METHOD_NONE
[2024-09-24T06:04:21.394+0000] [DEBUG] [MCS Connection Sequence] receive connection request
[2024-09-24T06:04:21.395+0000] [INFO ] Connected client computer name: LAPTOP-EU0D7GPQ
[2024-09-24T06:04:21.395+0000] [WARN ] client requested gfx protocol with insufficient color depth
[2024-09-24T06:04:21.395+0000] [WARN ] Physical desktop dimensions (0x0) are invalid
[2024-09-24T06:04:21.396+0000] [DEBUG] The connection is using TLS, skipping RDP crypto negotiation
[2024-09-24T06:04:21.396+0000] [WARN ] Received [MS-RDPBCGR] TS_UD_HEADER type 0xc006 is unknown (ignored)
[2024-09-24T06:04:21.396+0000] [WARN ] Received [MS-RDPBCGR] TS_UD_HEADER type 0xc00a is unknown (ignored)
[2024-09-24T06:04:21.396+0000] [DEBUG] [MCS Connection Sequence] construct connection response
[2024-09-24T06:04:21.397+0000] [DEBUG] using no security
[2024-09-24T06:04:21.397+0000] [DEBUG] [MCS Connection Sequence] send connection response
[2024-09-24T06:04:21.397+0000] [DEBUG] [MCS Connection Sequence] receive erect domain request
[2024-09-24T06:04:21.398+0000] [DEBUG] [MCS Connection Sequence] receive attach user request
[2024-09-24T06:04:21.398+0000] [DEBUG] [MCS Connection Sequence] send attach user confirm
[2024-09-24T06:04:21.399+0000] [DEBUG] [MCS Connection Sequence (TLS)] receive channel join request
[2024-09-24T06:04:21.399+0000] [ERROR] Parsed [ITU-T T.125] DomainMCSPDU choice index expected 14, received 25
[2024-09-24T06:04:21.399+0000] [ERROR] [MCS Connection Sequence (TLS)] receive channel join request failed
[2024-09-24T06:04:21.400+0000] [ERROR] xrdp_sec_incoming: xrdp_mcs_incoming failed
[2024-09-24T06:04:21.400+0000] [ERROR] xrdp_rdp_incoming: xrdp_sec_incoming failed
[2024-09-24T06:04:21.400+0000] [ERROR] xrdp_process_main_loop: libxrdp_process_incoming failed
[2024-09-24T06:04:21.400+0000] [DEBUG] Closed socket 13 ([::ffff:172.20.0.2]:3389)
[2024-09-24T06:04:21.403+0000] [INFO ] Socket 13: connection accepted from [::ffff:192.168.0.199]:42092
[2024-09-24T06:04:21.404+0000] [DEBUG] Closed socket 13 ([::ffff:172.20.0.2]:3389)
[2024-09-24T06:04:21.404+0000] [DEBUG] Closed socket 12 ([::]:3389)
[2024-09-24T06:04:21.405+0000] [DEBUG] item ini_version, value 1
[2024-09-24T06:04:21.405+0000] [DEBUG] item fork, value true
[2024-09-24T06:04:21.406+0000] [DEBUG] item port, value 3389
[2024-09-24T06:04:21.406+0000] [DEBUG] item use_vsock, value false
[2024-09-24T06:04:21.406+0000] [DEBUG] item tcp_nodelay, value true
[2024-09-24T06:04:21.407+0000] [DEBUG] item tcp_keepalive, value true
[2024-09-24T06:04:21.407+0000] [DEBUG] item security_layer, value negotiate
[2024-09-24T06:04:21.407+0000] [DEBUG] item crypt_level, value none
[2024-09-24T06:04:21.407+0000] [DEBUG] item certificate, value 
[2024-09-24T06:04:21.408+0000] [INFO ] Using default X.509 certificate: /etc/xrdp/cert.pem
[2024-09-24T06:04:21.408+0000] [DEBUG] item key_file, value 
[2024-09-24T06:04:21.408+0000] [INFO ] Using default X.509 key file: /etc/xrdp/key.pem
[2024-09-24T06:04:21.409+0000] [DEBUG] item ssl_protocols, value TLSv1.2, TLSv1.3
[2024-09-24T06:04:21.409+0000] [DEBUG] TLSv1.3 enabled
[2024-09-24T06:04:21.409+0000] [DEBUG] TLSv1.2 enabled
[2024-09-24T06:04:21.409+0000] [DEBUG] item autorun, value 
[2024-09-24T06:04:21.410+0000] [DEBUG] item allow_channels, value true
[2024-09-24T06:04:21.410+0000] [DEBUG] item allow_multimon, value true
[2024-09-24T06:04:21.410+0000] [DEBUG] item bitmap_cache, value true
[2024-09-24T06:04:21.410+0000] [DEBUG] item bitmap_compression, value true
[2024-09-24T06:04:21.411+0000] [DEBUG] item bulk_compression, value true
[2024-09-24T06:04:21.411+0000] [DEBUG] item max_bpp, value 24
[2024-09-24T06:04:21.411+0000] [DEBUG] item new_cursors, value true
[2024-09-24T06:04:21.411+0000] [DEBUG] item use_fastpath, value both
[2024-09-24T06:04:21.412+0000] [DEBUG] item blue, value 009cb5
[2024-09-24T06:04:21.412+0000] [DEBUG] item grey, value dedede
[2024-09-24T06:04:21.412+0000] [DEBUG] item ls_top_window_bg_color, value 009cb5
[2024-09-24T06:04:21.412+0000] [DEBUG] item ls_width, value 350
[2024-09-24T06:04:21.413+0000] [DEBUG] item ls_height, value 430
[2024-09-24T06:04:21.413+0000] [DEBUG] item ls_bg_color, value dedede
[2024-09-24T06:04:21.413+0000] [DEBUG] item ls_logo_filename, value 
[2024-09-24T06:04:21.413+0000] [DEBUG] item ls_logo_x_pos, value 55
[2024-09-24T06:04:21.415+0000] [DEBUG] item ls_logo_y_pos, value 50
[2024-09-24T06:04:21.415+0000] [DEBUG] item ls_label_x_pos, value 30
[2024-09-24T06:04:21.415+0000] [DEBUG] item ls_label_width, value 65
[2024-09-24T06:04:21.415+0000] [DEBUG] item ls_input_x_pos, value 110
[2024-09-24T06:04:21.416+0000] [DEBUG] item ls_input_width, value 210
[2024-09-24T06:04:21.416+0000] [DEBUG] item ls_input_y_pos, value 220
[2024-09-24T06:04:21.416+0000] [DEBUG] item ls_btn_ok_x_pos, value 142
[2024-09-24T06:04:21.417+0000] [DEBUG] item ls_btn_ok_y_pos, value 370
[2024-09-24T06:04:21.417+0000] [DEBUG] item ls_btn_ok_width, value 85
[2024-09-24T06:04:21.417+0000] [DEBUG] item ls_btn_ok_height, value 30
[2024-09-24T06:04:21.417+0000] [DEBUG] item ls_btn_cancel_x_pos, value 237
[2024-09-24T06:04:21.418+0000] [DEBUG] item ls_btn_cancel_y_pos, value 370
[2024-09-24T06:04:21.418+0000] [DEBUG] item ls_btn_cancel_width, value 85
[2024-09-24T06:04:21.418+0000] [DEBUG] item ls_btn_cancel_height, value 30
[2024-09-24T06:04:21.419+0000] [INFO ] Security protocol: configured [SSL|RDP], requested [SSL|RDP], selected [SSL]
[2024-09-24T06:04:21.429+0000] [DEBUG] Using TLS security, and setting RDP security crypto to LEVEL_NONE and METHOD_NONE
[2024-09-24T06:04:21.429+0000] [DEBUG] [MCS Connection Sequence] receive connection request
[2024-09-24T06:04:21.429+0000] [INFO ] Connected client computer name: LAPTOP-EU0D7GPQ
[2024-09-24T06:04:21.430+0000] [WARN ] client requested gfx protocol with insufficient color depth
[2024-09-24T06:04:21.430+0000] [WARN ] Physical desktop dimensions (0x0) are invalid
[2024-09-24T06:04:21.430+0000] [DEBUG] The connection is using TLS, skipping RDP crypto negotiation
[2024-09-24T06:04:21.430+0000] [WARN ] Received [MS-RDPBCGR] TS_UD_HEADER type 0xc006 is unknown (ignored)
[2024-09-24T06:04:21.430+0000] [WARN ] Received [MS-RDPBCGR] TS_UD_HEADER type 0xc00a is unknown (ignored)
[2024-09-24T06:04:21.431+0000] [DEBUG] [MCS Connection Sequence] construct connection response
[2024-09-24T06:04:21.431+0000] [DEBUG] using no security
[2024-09-24T06:04:21.431+0000] [DEBUG] [MCS Connection Sequence] send connection response
[2024-09-24T06:04:21.431+0000] [DEBUG] [MCS Connection Sequence] receive erect domain request
[2024-09-24T06:04:21.432+0000] [DEBUG] [MCS Connection Sequence] receive attach user request
[2024-09-24T06:04:21.432+0000] [DEBUG] [MCS Connection Sequence] send attach user confirm
[2024-09-24T06:04:21.432+0000] [DEBUG] [MCS Connection Sequence (TLS)] receive channel join request
[2024-09-24T06:04:21.432+0000] [ERROR] Parsed [ITU-T T.125] DomainMCSPDU choice index expected 14, received 25
[2024-09-24T06:04:21.433+0000] [ERROR] [MCS Connection Sequence (TLS)] receive channel join request failed
[2024-09-24T06:04:21.433+0000] [ERROR] xrdp_sec_incoming: xrdp_mcs_incoming failed
[2024-09-24T06:04:21.433+0000] [ERROR] xrdp_rdp_incoming: xrdp_sec_incoming failed
[2024-09-24T06:04:21.433+0000] [ERROR] xrdp_process_main_loop: libxrdp_process_incoming failed
[2024-09-24T06:04:21.433+0000] [DEBUG] Closed socket 13 ([::ffff:172.20.0.2]:3389)

✔️ Expected Behavior

No response

❌ Actual Behavior

No response

Anything else?

No response

matt335672 commented 1 month ago

As @akallabeth remarked in FreeRDP/FreeRDP#10667 (which this is linked to), there's no configuration here. Can you add detail to both requests as to how you have configured the proxy, and any proxy logs please?

From the little I can see, there's a mismatch between the number of channels on the xrdp and proxy ends of the connection. This message :-

[2024-09-24T06:04:21.432+0000] [ERROR] Parsed [ITU-T T.125] DomainMCSPDU choice index expected 14, received 25

while admittedly rather cryptic tells us that xrdp is expecting a channel join request (14), but instead is getting a send data request.

StudyAndGrow commented 1 month ago

As @akallabeth remarked in FreeRDP/FreeRDP#10667 (which this is linked to), there's no configuration here. Can you add detail to both requests as to how you have configured the proxy, and any proxy logs please?

From the little I can see, there's a mismatch between the number of channels on the xrdp and proxy ends of the connection. This message :-

[2024-09-24T06:04:21.432+0000] [ERROR] Parsed [ITU-T T.125] DomainMCSPDU choice index expected 14, received 25

while admittedly rather cryptic tells us that xrdp is expecting a channel join request (14), but instead is getting a send data request.

Sorry for not providing the config file the first time. The following is the configuration file of 0.10.1 xrdp

[Globals]
; xrdp.ini file version number
ini_version=1

; fork a new process for each incoming connection
fork=true

port=3389
use_vsock=false
tcp_nodelay=true
tcp_keepalive=true
security_layer=negotiate
crypt_level=high
certificate=
key_file=
ssl_protocols=TLSv1.2, TLSv1.3
autorun=

allow_channels=true
allow_multimon=true
bitmap_cache=true
bitmap_compression=true
bulk_compression=true
#hidelogwindow=true
max_bpp=32
new_cursors=true
; fastpath - can be 'input', 'output', 'both', 'none'
use_fastpath=both

blue=009cb5
grey=dedede

ls_top_window_bg_color=009cb5
ls_width=350
ls_height=430
ls_bg_color=dedede

ls_logo_filename=
ls_logo_x_pos=55
ls_logo_y_pos=50

; for positioning labels such as username, password etc
ls_label_x_pos=30
ls_label_width=65

; for positioning text and combo boxes next to above labels
ls_input_x_pos=110
ls_input_width=210

; y pos for first label and combo box
ls_input_y_pos=220

; OK button
ls_btn_ok_x_pos=142
ls_btn_ok_y_pos=370
ls_btn_ok_width=85
ls_btn_ok_height=30

; Cancel button
ls_btn_cancel_x_pos=237
ls_btn_cancel_y_pos=370
ls_btn_cancel_width=85
ls_btn_cancel_height=30

[Logging]
; Note: Log levels can be any of: core, error, warning, info, debug, or trace
LogFile=xrdp.log
LogLevel=INFO
EnableSyslog=true

[LoggingPerLogger]
; Note: per logger configuration is only used if xrdp is built with
; --enable-devel-logging
#xrdp.c=INFO
#main()=INFO

[Channels]
rdpdr=true
rdpsnd=true
drdynvc=true
cliprdr=true
rail=true
xrdpvr=true
tcutils=true
appload=true

[Xvnc]
name=Xvnc
lib=libvnc.so
username=ask
password=ask
ip=127.0.0.1
port=-1

The following is the configuration file of 3.6.0 freerdp-proxy

[Server]
Host = 0.0.0.0
Port = 3389

[Target]
; If this value is set to TRUE, the target server info will be parsed using the
; load balance info setting at runtime. The format is
; "Cookie: msts=", and can be set in an rdp file for windows/mac,
; and the /load-balance-info: CLI option for xfreerdp. Otherwise, the server
; will always connect to the same target, using the configured values of Host
; and Port.
FixedTarget = TRUE
Host = 192.168.0.156
Port = 13389

[Input]
Mouse = TRUE
Keyboard = TRUE

[Security]
ServerTlsSecurity = TRUE
ServerRdpSecurity = TRUE
ClientTlsSecurity = TRUE
ClientRdpSecurity = TRUE
ClientNlaSecurity = TRUE
ClientAllowFallbackToTls = TRUE

[Channels]
GFX = TRUE
DisplayControl = TRUE
Clipboard = TRUE
AudioOutput = TRUE
RemoteApp = TRUE
; a list of comma seperated static channels that will be proxied. This feature is useful,
; for example when there's a custom static channel that isn't implemented in freerdp/proxy, and is needed to be proxied when connecting through the proxy.
PassthroughIsBlacklist=TRUE
DeviceRedirection = TRUE
; Passthrough = rdpdr

[Clipboard]
TextOnly = FALSE
MaxTextLength = 10 # 0 for no limit.

[GFXSettings]
DecodeGFX = FALSE

[Plugins]
; An optional, comma separated list of paths to modules that the proxy should load at startup.
;
; Modules = "proxy-demo-plugin.so"

; An optional, comma separated list of required plugins (names),
; that the proxy won't start without having them loaded.
;
; Required = "demo"
;
[Certificates]
CertificateFile="/root/git/freerdp-build/server/proxy/server.crt"
PrivateKeyFile="/root/git/freerdp-build/server/proxy/server.key"

The following is the log file of 3.6.0 freerdp-proxy

[07:21:22:433] [63352:0000f779] [DEBUG][com.winpr.timezone] - [winpr_get_timezone_from_link]: tzid: America/New_York
[07:21:22:433] [63352:0000f779] [DEBUG][com.winpr.timezone] - [winpr_get_timezone_from_link]: tzid: America/New_York
[07:21:22:434] [63352:0000f779] [DEBUG][com.winpr.timezone] - [winpr_get_timezone_from_link]: tzid: America/New_York
[07:21:22:435] [63352:0000f779] [DEBUG][com.winpr.timezone] - [winpr_get_timezone_from_link]: tzid: America/New_York
[07:21:22:444] [63352:0000f779] [DEBUG][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B335694D3A2B3BEA721D0338875AB995]: Added peer, 1 connected
[07:21:22:444] [63352:0000f779] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c000b60]: CONNECTION_STATE_INITIAL --> CONNECTION_STATE_INITIAL
[07:21:22:444] [63352:0000f779] [INFO][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B335694D3A2B3BEA721D0338875AB995]: new connection: proxy address: 0.0.0.0, client address: 192.168.0.231
[07:21:22:444] [63352:0000f779] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c000b60]: CONNECTION_STATE_INITIAL --> CONNECTION_STATE_NEGO
[07:21:22:444] [63352:0000f779] [DEBUG][com.freerdp.core.nego] - [nego_read_request_token_or_cookie]: received cookie [Cookie: mstshash=root]
[07:21:22:444] [63352:0000f779] [DEBUG][com.freerdp.core.nego] - [nego_process_negotiation_request]: RDP_NEG_REQ: RequestedProtocol: [SSL|HYBRID|HYBRID_EX][0x0000000b]
[07:21:22:444] [63352:0000f779] [DEBUG][com.freerdp.core.connection] - [rdp_server_accept_nego]: Client Security: RDSTLS:0 NLA:1 TLS:1 RDP:0
[07:21:22:444] [63352:0000f779] [DEBUG][com.freerdp.core.connection] - [rdp_server_accept_nego]: Server Security: RDSTLS:0 NLA:0 TLS:1 RDP:1
[07:21:22:444] [63352:0000f779] [DEBUG][com.freerdp.core.connection] - [rdp_server_accept_nego]: Negotiated Security: RDSTLS:0 NLA:0 TLS:1 RDP:0
[07:21:22:460] [63352:0000f779] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c000b60]: CONNECTION_STATE_NEGO --> CONNECTION_STATE_MCS_CREATE_REQUEST
[07:21:22:487] [63352:0000f779] [DEBUG][com.freerdp.core.transport] - [transport_check_fds]: transport_check_fds: transport_read_pdu() - -1
[07:21:22:487] [63352:0000f779] [DEBUG][com.freerdp.core.rdp] - [rdp_check_fds][0x7fe51c000b60]: transport_check_fds() - -1
[07:21:22:487] [63352:0000f779] [INFO][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B335694D3A2B3BEA721D0338875AB995]: starting shutdown of connection
[07:21:22:487] [63352:0000f779] [INFO][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B335694D3A2B3BEA721D0338875AB995]: stopping proxy's client
[07:21:22:487] [63352:0000f779] [INFO][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B335694D3A2B3BEA721D0338875AB995]: freeing server's channels
[07:21:22:487] [63352:0000f779] [INFO][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B335694D3A2B3BEA721D0338875AB995]: freeing proxy data
[07:21:22:487] [63352:0000f779] [DEBUG][com.winpr.thread] - [ThreadCloseHandle]: Thread running, setting to detached state!
[07:21:22:487] [63352:0000f779] [DEBUG][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B335694D3A2B3BEA721D0338875AB995]: Removed peer, 0 connected
[07:21:22:487] [63352:0000f779] [ERROR][com.freerdp.core.transport] - [transport_read_layer]: BIO_read returned a system error 104: Connection reset by peer
[07:21:22:487] [63352:0000f779] [ERROR][com.freerdp.core.peer] - [transport_read_layer]: ERRCONNECT_CONNECT_TRANSPORT_FAILED [0x0002000D]
[07:21:22:487] [63352:0000f779] [ERROR][com.freerdp.core.transport] - [transport_default_write]: BIO_should_retry returned a system error 32: Broken pipe
[07:21:24:940] [63352:0000f77a] [DEBUG][com.winpr.timezone] - [winpr_get_timezone_from_link]: tzid: America/New_York
[07:21:24:940] [63352:0000f77a] [DEBUG][com.winpr.timezone] - [winpr_get_timezone_from_link]: tzid: America/New_York
[07:21:24:942] [63352:0000f77a] [DEBUG][com.winpr.timezone] - [winpr_get_timezone_from_link]: tzid: America/New_York
[07:21:24:942] [63352:0000f77a] [DEBUG][com.winpr.timezone] - [winpr_get_timezone_from_link]: tzid: America/New_York
[07:21:24:951] [63352:0000f77a] [DEBUG][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: Added peer, 1 connected
[07:21:24:951] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_INITIAL --> CONNECTION_STATE_INITIAL
[07:21:24:951] [63352:0000f77a] [INFO][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: new connection: proxy address: 0.0.0.0, client address: 192.168.0.231
[07:21:24:951] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_INITIAL --> CONNECTION_STATE_NEGO
[07:21:24:951] [63352:0000f77a] [DEBUG][com.freerdp.core.nego] - [nego_read_request_token_or_cookie]: received cookie [Cookie: mstshash=root]
[07:21:24:951] [63352:0000f77a] [DEBUG][com.freerdp.core.nego] - [nego_process_negotiation_request]: RDP_NEG_REQ: RequestedProtocol: [SSL|HYBRID|HYBRID_EX][0x0000000b]
[07:21:24:951] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_accept_nego]: Client Security: RDSTLS:0 NLA:1 TLS:1 RDP:0
[07:21:24:951] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_accept_nego]: Server Security: RDSTLS:0 NLA:0 TLS:1 RDP:1
[07:21:24:951] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_accept_nego]: Negotiated Security: RDSTLS:0 NLA:0 TLS:1 RDP:0
[07:21:24:966] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_NEGO --> CONNECTION_STATE_MCS_CREATE_REQUEST
[07:21:24:966] [63352:0000f77a] [DEBUG][com.freerdp.core.gcc] - [gcc_read_client_core_data]: Received EarlyCapabilityFlags=RNS_UD_CS_SUPPORT_ERRINFO_PDU|RNS_UD_CS_SUPPORT_STATUSINFO_PDU|RNS_UD_CS_STRONG_ASYMMETRIC_KEYS|RNS_UD_CS_VALID_CONNECTION_TYPE|RNS_UD_CS_SUPPORT_NETCHAR_AUTODETECT|RNS_UD_CS_SUPPORT_DYNVC_GFX_PROTOCOL|RNS_UD_CS_SUPPORT_DYNAMIC_TIME_ZONE|RNS_UD_CS_SUPPORT_HEARTBEAT_PDU|RNS_UD_CS_SUPPORT_SKIP_CHANNELJOIN|[0x00000fad]
[07:21:24:966] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_accept_mcs_connect_initial]: Accepted client: LAPTOP-EU0D7GPQ
[07:21:24:966] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_accept_mcs_connect_initial]: Accepted channels:
[07:21:24:966] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_accept_mcs_connect_initial]: rdpdr [1004]
[07:21:24:966] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_accept_mcs_connect_initial]: rdpsnd [1005]
[07:21:24:966] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_accept_mcs_connect_initial]: cliprdr [1006]
[07:21:24:966] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_accept_mcs_connect_initial]: drdynvc [1007]
[07:21:24:966] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_MCS_CREATE_REQUEST --> CONNECTION_STATE_MCS_CREATE_RESPONSE
[07:21:24:966] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_MCS_CREATE_RESPONSE --> CONNECTION_STATE_MCS_ERECT_DOMAIN
[07:21:24:973] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_MCS_ERECT_DOMAIN --> CONNECTION_STATE_MCS_ATTACH_USER
[07:21:24:973] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_MCS_ATTACH_USER --> CONNECTION_STATE_MCS_ATTACH_USER_CONFIRM
[07:21:24:973] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_skip_mcs_channel_join]: rdpdr [1004]
[07:21:24:973] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_skip_mcs_channel_join]: rdpsnd [1005]
[07:21:24:973] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_skip_mcs_channel_join]: cliprdr [1006]
[07:21:24:973] [63352:0000f77a] [DEBUG][com.freerdp.core.connection] - [rdp_server_skip_mcs_channel_join]: drdynvc [1007]
[07:21:24:973] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_MCS_ATTACH_USER_CONFIRM --> CONNECTION_STATE_RDP_SECURITY_COMMENCEMENT
[07:21:24:982] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_RDP_SECURITY_COMMENCEMENT --> CONNECTION_STATE_SECURE_SETTINGS_EXCHANGE
[07:21:24:982] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_SECURE_SETTINGS_EXCHANGE --> CONNECTION_STATE_CONNECT_TIME_AUTO_DETECT_REQUEST
[07:21:24:982] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_CONNECT_TIME_AUTO_DETECT_REQUEST --> CONNECTION_STATE_CONNECT_TIME_AUTO_DETECT_RESPONSE
[07:21:24:985] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_CONNECT_TIME_AUTO_DETECT_RESPONSE --> CONNECTION_STATE_LICENSING
[07:21:24:985] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_LICENSING --> CONNECTION_STATE_MULTITRANSPORT_BOOTSTRAPPING_REQUEST
[07:21:24:985] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_MULTITRANSPORT_BOOTSTRAPPING_REQUEST --> CONNECTION_STATE_MULTITRANSPORT_BOOTSTRAPPING_RESPONSE
[07:21:31:339] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_MULTITRANSPORT_BOOTSTRAPPING_RESPONSE --> CONNECTION_STATE_CAPABILITIES_EXCHANGE_DEMAND_ACTIVE
[07:21:31:339] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_CAPABILITIES_EXCHANGE_DEMAND_ACTIVE --> CONNECTION_STATE_CAPABILITIES_EXCHANGE_MONITOR_LAYOUT
[07:21:31:339] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_CAPABILITIES_EXCHANGE_MONITOR_LAYOUT --> CONNECTION_STATE_CAPABILITIES_EXCHANGE_CONFIRM_ACTIVE
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_read_share_control_header][0x7fe51c067550]: type=PDU_TYPE_CONFIRM_ACTIVE[0x00000003], tpktLength=585, remainingLength=579
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.peer] - [peer_recv_tpkt_pdu]: Received PDU_TYPE_CONFIRM_ACTIVE[0x00000003]
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_CAPABILITIES_EXCHANGE_CONFIRM_ACTIVE --> CONNECTION_STATE_FINALIZATION_CLIENT_SYNC
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_send_data_pdu][0x7fe51c067550]: sending data (type=0x1f size=37 channelId=1009)
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_FINALIZATION_CLIENT_SYNC --> CONNECTION_STATE_FINALIZATION_CLIENT_COOPERATE
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_send_data_pdu][0x7fe51c067550]: sending data (type=0x14 size=41 channelId=1009)
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_finalize_reset_flags][0x7fe51c067550]: [CONNECTION_STATE_FINALIZATION_CLIENT_COOPERATE] reset finalize_sc_pdus
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_FINALIZATION_CLIENT_COOPERATE --> CONNECTION_STATE_FINALIZATION_SYNC
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_read_share_control_header][0x7fe51c067550]: type=PDU_TYPE_DATA[0x00000007], tpktLength=22, remainingLength=16
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.peer] - [peer_recv_tpkt_pdu]: Received PDU_TYPE_DATA[0x00000007]
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_finalize_set_flag][0x7fe51c067550]: [CONNECTION_STATE_FINALIZATION_SYNC] received flag FINALIZE_CS_SYNCHRONIZE_PDU [0x00000010]
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_FINALIZATION_SYNC --> CONNECTION_STATE_FINALIZATION_COOPERATE
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_read_share_control_header][0x7fe51c067550]: type=PDU_TYPE_DATA[0x00000007], tpktLength=26, remainingLength=20
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.peer] - [peer_recv_tpkt_pdu]: Received PDU_TYPE_DATA[0x00000007]
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_finalize_set_flag][0x7fe51c067550]: [CONNECTION_STATE_FINALIZATION_COOPERATE] received flag FINALIZE_CS_CONTROL_COOPERATE_PDU [0x00000020]
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_FINALIZATION_COOPERATE --> CONNECTION_STATE_FINALIZATION_REQUEST_CONTROL
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_read_share_control_header][0x7fe51c067550]: type=PDU_TYPE_DATA[0x00000007], tpktLength=26, remainingLength=20
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.peer] - [peer_recv_tpkt_pdu]: Received PDU_TYPE_DATA[0x00000007]
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_finalize_set_flag][0x7fe51c067550]: [CONNECTION_STATE_FINALIZATION_REQUEST_CONTROL] received flag FINALIZE_CS_CONTROL_REQUEST_PDU [0x00000040]
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_send_data_pdu][0x7fe51c067550]: sending data (type=0x14 size=41 channelId=1009)
[07:21:31:350] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_FINALIZATION_REQUEST_CONTROL --> CONNECTION_STATE_FINALIZATION_PERSISTENT_KEY_LIST
[07:21:31:353] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_FINALIZATION_PERSISTENT_KEY_LIST --> CONNECTION_STATE_FINALIZATION_FONT_LIST
[07:21:31:353] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_read_share_control_header][0x7fe51c067550]: type=PDU_TYPE_DATA[0x00000007], tpktLength=26, remainingLength=20
[07:21:31:353] [63352:0000f77a] [DEBUG][com.freerdp.core.peer] - [peer_recv_tpkt_pdu]: Received PDU_TYPE_DATA[0x00000007]
[07:21:31:353] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_finalize_set_flag][0x7fe51c067550]: [CONNECTION_STATE_FINALIZATION_FONT_LIST] received flag FINALIZE_CS_FONT_LIST_PDU [0x00000100]
[07:21:31:353] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_FINALIZATION_FONT_LIST --> CONNECTION_STATE_FINALIZATION_CLIENT_FONT_MAP
[07:21:31:353] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_send_data_pdu][0x7fe51c067550]: sending data (type=0x28 size=41 channelId=1009)
[07:21:31:353] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_FINALIZATION_CLIENT_FONT_MAP --> CONNECTION_STATE_ACTIVE
[07:21:31:353] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_server_transition_to_state][0x7fe51c067550]: CONNECTION_STATE_ACTIVE --> CONNECTION_STATE_ACTIVE
[07:21:31:353] [63352:0000f77a] [INFO][com.freerdp.proxy.server] - [pf_server_post_connect]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: Accepted client: LAPTOP-EU0D7GPQ
[07:21:31:353] [63352:0000f77a] [INFO][com.freerdp.proxy.server] - [pf_server_setup_channels]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: Accepted channel: rdpdr (1004)
[07:21:31:353] [63352:0000f77a] [DEBUG][com.freerdp.proxy.utils] - [pf_utils_get_channel_mode]: rdpdr -> passthrough
[07:21:31:353] [63352:0000f77a] [INFO][com.freerdp.proxy.server] - [pf_server_setup_channels]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: Accepted channel: rdpsnd (1005)
[07:21:31:353] [63352:0000f77a] [DEBUG][com.freerdp.proxy.utils] - [pf_utils_get_channel_mode]: rdpsnd -> passthrough
[07:21:31:353] [63352:0000f77a] [INFO][com.freerdp.proxy.server] - [pf_server_setup_channels]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: Accepted channel: cliprdr (1006)
[07:21:31:353] [63352:0000f77a] [DEBUG][com.freerdp.proxy.utils] - [pf_utils_get_channel_mode]: cliprdr -> passthrough
[07:21:31:353] [63352:0000f77a] [INFO][com.freerdp.proxy.server] - [pf_server_setup_channels]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: Accepted channel: drdynvc (1007)
[07:21:31:353] [63352:0000f77a] [DEBUG][com.freerdp.proxy.utils] - [pf_utils_get_channel_mode]: drdynvc -> passthrough
[07:21:31:354] [63352:0000f77a] [DEBUG][com.winpr.timezone] - [winpr_get_timezone_from_link]: tzid: America/New_York
[07:21:31:355] [63352:0000f77a] [DEBUG][com.winpr.timezone] - [winpr_get_timezone_from_link]: tzid: America/New_York
[07:21:31:356] [63352:0000f77a] [DEBUG][com.winpr.timezone] - [winpr_get_timezone_from_link]: tzid: America/New_York
[07:21:31:356] [63352:0000f77a] [DEBUG][com.winpr.timezone] - [winpr_get_timezone_from_link]: tzid: America/New_York
[07:21:31:360] [63352:0000f77a] [INFO][com.freerdp.proxy.server] - [pf_server_post_connect]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: remote target is 192.168.0.156:13389
[07:21:31:360] [63352:0000f77b] [INFO][com.freerdp.proxy.client] - [pf_client_connect]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: connecting using client info: Username: a, Domain: (null)
[07:21:31:360] [63352:0000f77b] [INFO][com.freerdp.proxy.client] - [pf_client_connect]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: connecting using security settings: rdp=1, tls=1, nla=1
[07:21:31:360] [63352:0000f77b] [DEBUG][com.freerdp.core] - [freerdp_connect_begin]: resetting error state
[07:21:31:361] [63352:0000f77b] [INFO][com.freerdp.proxy.client] - [pf_client_load_channels]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: Loading addins
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.proxy.utils] - [pf_utils_get_channel_mode]: rdpdr -> passthrough
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.proxy.config] - [config_plugin_channel_create]: rdpdr [static]: true
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.proxy.utils] - [pf_utils_get_channel_mode]: rdpsnd -> passthrough
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.proxy.config] - [config_plugin_channel_create]: rdpsnd [static]: true
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.proxy.utils] - [pf_utils_get_channel_mode]: cliprdr -> passthrough
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.proxy.config] - [config_plugin_channel_create]: cliprdr [static]: true
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.proxy.utils] - [pf_utils_get_channel_mode]: drdynvc -> passthrough
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.proxy.config] - [config_plugin_channel_create]: drdynvc [static]: true
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_set_negotiation_enabled]: Enabling security layer negotiation: TRUE
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_set_restricted_admin_mode_required]: Enabling restricted admin mode: FALSE
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_set_RCG_required]: Enabling remoteCredentialGuards: FALSE
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_enable_rdp]: Enabling RDP security: TRUE
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_enable_tls]: Enabling TLS security: TRUE
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_enable_nla]: Enabling NLA security: TRUE
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_enable_ext]: Enabling NLA extended security: FALSE
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_enable_rdstls]: Enabling RDSTLS security: FALSE
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_enable_aad]: Enabling RDS AAD security: FALSE
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_INITIAL --> CONNECTION_STATE_NEGO
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core] - [freerdp_tcp_is_hostname_resolvable]: resetting error state
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core] - [freerdp_tcp_default_connect]: resetting error state
[07:21:31:361] [63352:0000f77b] [DEBUG][com.freerdp.core] - [freerdp_tcp_default_connect]: connecting to peer 192.168.0.156
[07:21:31:362] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_connect]: state: NEGO_STATE_NLA
[07:21:31:362] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_attempt_nla]: Attempting NLA security
[07:21:31:362] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_send_negotiation_request]: RequestedProtocols: [SSL|HYBRID][0x00000003]
[07:21:31:365] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_process_negotiation_response]: RDP_NEG_RSP::flags = { [0x01] |EXTENDED_CLIENT_DATA_SUPPORTED }
[07:21:31:365] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_recv]: selected_protocol: [SSL][0x00000001]
[07:21:31:365] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_attempt_nla]: state: NEGO_STATE_FINAL
[07:21:31:365] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_connect]: Negotiated [SSL][0x00000001] security
[07:21:31:365] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_try_connect]: nego_security_connect with PROTOCOL_SSL
[07:21:31:431] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_NEGO --> CONNECTION_STATE_MCS_CREATE_REQUEST
[07:21:31:431] [63352:0000f77b] [DEBUG][com.freerdp.core.gcc] - [gcc_write_client_core_data]: Sending highColorDepth=HIGH_COLOR_24BPP, supportedColorDepths=RNS_UD_32BPP_SUPPORT|RNS_UD_24BPP_SUPPORT|RNS_UD_16BPP_SUPPORT|RNS_UD_15BPP_SUPPORT, earlyCapabilityFlags=RNS_UD_CS_SUPPORT_ERRINFO_PDU|RNS_UD_CS_SUPPORT_STATUSINFO_PDU|RNS_UD_CS_STRONG_ASYMMETRIC_KEYS|RNS_UD_CS_VALID_CONNECTION_TYPE|RNS_UD_CS_SUPPORT_NETCHAR_AUTODETECT|RNS_UD_CS_SUPPORT_DYNVC_GFX_PROTOCOL|RNS_UD_CS_SUPPORT_DYNAMIC_TIME_ZONE|RNS_UD_CS_SUPPORT_HEARTBEAT_PDU|RNS_UD_CS_SUPPORT_SKIP_CHANNELJOIN|[0x00000fad]
[07:21:31:431] [63352:0000f77b] [DEBUG][com.freerdp.core.gcc] - [gcc_write_client_monitor_data]: MonitorCount=0
[07:21:31:431] [63352:0000f77b] [DEBUG][com.freerdp.core.gcc] - [gcc_write_client_monitor_data]: FINISHED
[07:21:31:431] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_MCS_CREATE_REQUEST --> CONNECTION_STATE_MCS_CREATE_RESPONSE
[07:21:31:433] [63352:0000f77b] [DEBUG][com.freerdp.core.gcc] - [gcc_read_server_security_data]: Server rdp encryption method: NONE
[07:21:31:433] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_MCS_CREATE_RESPONSE --> CONNECTION_STATE_MCS_ERECT_DOMAIN
[07:21:31:433] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_MCS_ERECT_DOMAIN --> CONNECTION_STATE_MCS_ATTACH_USER
[07:21:31:433] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_MCS_ATTACH_USER --> CONNECTION_STATE_MCS_ATTACH_USER_CONFIRM
[07:21:31:433] [63352:0000f77b] [DEBUG][com.freerdp.core.connection] - [rdp_client_skip_mcs_channel_join]: rdpdr [1004]
[07:21:31:433] [63352:0000f77b] [DEBUG][com.freerdp.core.connection] - [rdp_client_skip_mcs_channel_join]: rdpsnd [1005]
[07:21:31:433] [63352:0000f77b] [DEBUG][com.freerdp.core.connection] - [rdp_client_skip_mcs_channel_join]: cliprdr [1006]
[07:21:31:433] [63352:0000f77b] [DEBUG][com.freerdp.core.connection] - [rdp_client_skip_mcs_channel_join]: drdynvc [1007]
[07:21:31:433] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_MCS_ATTACH_USER_CONFIRM --> CONNECTION_STATE_SECURE_SETTINGS_EXCHANGE
[07:21:31:433] [63352:0000f77b] [DEBUG][com.freerdp.core.info] - [rdp_write_info_packet]: Client Info Packet Flags = INFO_MOUSE|INFO_DISABLECTRLALTDEL|INFO_AUTOLOGON|INFO_UNICODE|INFO_MAXIMIZESHELL|INFO_COMPRESSION|INFO_ENABLEWINDOWSKEY|INFO_FORCE_ENCRYPTED_CS_PDU|INFO_LOGONERRORS|INFO_MOUSE_HAS_WHEEL|INFO_AUDIOCAPTURE
[07:21:31:433] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_SECURE_SETTINGS_EXCHANGE --> CONNECTION_STATE_CONNECT_TIME_AUTO_DETECT_REQUEST
[07:21:31:435] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_CONNECT_TIME_AUTO_DETECT_REQUEST --> CONNECTION_STATE_LICENSING
[07:21:31:435] [63352:0000f77b] [INFO][com.freerdp.core] - [rdp_print_errinfo]: ERRINFO_LOGOFF_BY_USER (0x0000000C):The disconnection was initiated by the user logging off their session on the server.
[07:21:31:435] [63352:0000f77b] [INFO][com.freerdp.core] - [rdp_print_errinfo]: ERRINFO_LOGOFF_BY_USER (0x0000000C):The disconnection was initiated by the user logging off their session on the server.
[07:21:31:435] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_send_data_pdu][0x7fe51c050fe0]: sending data (type=0x2f size=37 channelId=0)
[07:21:31:435] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_read_header][0x7fe51c050fe0]: DisconnectProviderUltimatum: reason: 3
[07:21:31:436] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_recv_callback_int][0x7fe51c050fe0]: CONNECTION_STATE_LICENSING - rdp_client_connect_license() - STATE_RUN_FAILED [-1]
[07:21:31:436] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_check_fds][0x7fe51c050fe0]: transport_check_fds() - -1
[07:21:31:437] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_finalize_reset_flags][0x7fe51c050fe0]: [CONNECTION_STATE_LICENSING] reset finalize_sc_pdus
[07:21:31:437] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_LICENSING --> CONNECTION_STATE_INITIAL
[07:21:31:437] [63352:0000f77b] [DEBUG][com.freerdp.core] - [freerdp_connect_begin]: resetting error state
[07:21:31:438] [63352:0000f77b] [INFO][com.freerdp.proxy.client] - [pf_client_load_channels]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: Loading addins
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.proxy.utils] - [pf_utils_get_channel_mode]: rdpdr -> passthrough
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.proxy.config] - [config_plugin_channel_create]: rdpdr [static]: true
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.proxy.utils] - [pf_utils_get_channel_mode]: rdpsnd -> passthrough
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.proxy.config] - [config_plugin_channel_create]: rdpsnd [static]: true
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.proxy.utils] - [pf_utils_get_channel_mode]: cliprdr -> passthrough
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.proxy.config] - [config_plugin_channel_create]: cliprdr [static]: true
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.proxy.utils] - [pf_utils_get_channel_mode]: drdynvc -> passthrough
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.proxy.config] - [config_plugin_channel_create]: drdynvc [static]: true
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_set_negotiation_enabled]: Enabling security layer negotiation: TRUE
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_set_restricted_admin_mode_required]: Enabling restricted admin mode: FALSE
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_set_RCG_required]: Enabling remoteCredentialGuards: FALSE
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_enable_rdp]: Enabling RDP security: TRUE
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_enable_tls]: Enabling TLS security: TRUE
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_enable_nla]: Enabling NLA security: FALSE
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_enable_ext]: Enabling NLA extended security: FALSE
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_enable_rdstls]: Enabling RDSTLS security: FALSE
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_enable_aad]: Enabling RDS AAD security: FALSE
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_INITIAL --> CONNECTION_STATE_NEGO
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core] - [freerdp_tcp_is_hostname_resolvable]: resetting error state
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core] - [freerdp_tcp_default_connect]: resetting error state
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core] - [freerdp_tcp_default_connect]: connecting to peer 192.168.0.156
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_connect]: state: NEGO_STATE_TLS
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_attempt_tls]: Attempting TLS security
[07:21:31:438] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_send_negotiation_request]: RequestedProtocols: [SSL][0x00000001]
[07:21:31:441] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_process_negotiation_response]: RDP_NEG_RSP::flags = { [0x01] |EXTENDED_CLIENT_DATA_SUPPORTED }
[07:21:31:441] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_recv]: selected_protocol: [SSL][0x00000001]
[07:21:31:441] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_connect]: Negotiated [SSL][0x00000001] security
[07:21:31:441] [63352:0000f77b] [DEBUG][com.freerdp.core.nego] - [nego_try_connect]: nego_security_connect with PROTOCOL_SSL
[07:21:31:448] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_NEGO --> CONNECTION_STATE_MCS_CREATE_REQUEST
[07:21:31:433] [63352:0000f77b] [WARN][com.freerdp.core.gcc] - [filterAndLogEarlyServerCapabilityFlags]: TS_UD_SC_CORE::EarlyCapabilityFlags [0x00000fad & 0xfffffff0 --> 0x00000fa0] filtering RNS_UD_SC_UNKNOWN[0x00000fa0]|[0x00000fa0], feature not implemented
[07:21:31:435] [63352:0000f77b] [WARN][com.freerdp.core.connection] - [rdp_client_connect_auto_detect]: messageChannelId == 0
[07:21:31:435] [63352:0000f77b] [ERROR][com.freerdp.core] - [rdp_set_error_info]: ERRINFO_LOGOFF_BY_USER [0x0001000C]
[07:21:31:435] [63352:0000f77b] [WARN][com.freerdp.proxy.client] - [pf_client_on_error_info]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: received ErrorInfo PDU. code=0x00000012, message: The disconnection was initiated by the user logging off their session on the server.
[07:21:31:435] [63352:0000f77b] [ERROR][com.freerdp.core.peer] - [rdp_set_error_info]: ERRINFO_LOGOFF_BY_USER [0x0001000C]
[07:21:31:435] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [Stream_CheckAndLogRequiredLengthWLogExVa][0x7fe51c050fe0]: [rdp_read_security_header(/root/git/freerdp/libfreerdp/core/rdp.c:193)] invalid length, got 0, require at least 4 [element size=1]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 0: /root/git/freerdp-build/winpr/libwinpr/libwinpr3.so.3(winpr_backtrace+0x4a) [0x7fe53ef61c1a]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 1: /root/git/freerdp-build/winpr/libwinpr/libwinpr3.so.3(winpr_log_backtrace_ex+0x29) [0x7fe53ef670d9]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 2: /root/git/freerdp-build/winpr/libwinpr/libwinpr3.so.3(Stream_CheckAndLogRequiredLengthWLogExVa+0xc7) [0x7fe53ef68637]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 3: /root/git/freerdp-build/winpr/libwinpr/libwinpr3.so.3(Stream_CheckAndLogRequiredLengthWLogEx+0xe4) [0x7fe53ef68794]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 4: /root/git/freerdp-build/libfreerdp/libfreerdp3.so.3(+0x9ee6c) [0x7fe53f2aae6c]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 5: /root/git/freerdp-build/libfreerdp/libfreerdp3.so.3(+0x9b515) [0x7fe53f2a7515]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 6: /root/git/freerdp-build/libfreerdp/libfreerdp3.so.3(+0x9d852) [0x7fe53f2a9852]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 7: /root/git/freerdp-build/libfreerdp/libfreerdp3.so.3(+0x98865) [0x7fe53f2a4865]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 8: /root/git/freerdp-build/libfreerdp/libfreerdp3.so.3(+0xb14e1) [0x7fe53f2bd4e1]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 9: /root/git/freerdp-build/libfreerdp/libfreerdp3.so.3(freerdp_connect+0x778) [0x7fe53f2d3028]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 10: /root/git/freerdp-build/server/proxy/libfreerdp-server-proxy3.so.3(+0x16314) [0x7fe53f6a4314]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 11: /root/git/freerdp-build/server/proxy/libfreerdp-server-proxy3.so.3(+0x16b18) [0x7fe53f6a4b18]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 12: /root/git/freerdp-build/winpr/libwinpr/libwinpr3.so.3(+0x8d014) [0x7fe53ef50014]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 13: /lib64/libpthread.so.0(+0x817a) [0x7fe53e18317a]
[07:21:31:436] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 14: /lib64/libc.so.6(clone+0x43) [0x7fe53ebfadc3]
[07:21:31:436] [63352:0000f77b] [ERROR][com.freerdp.core.rdp] - [rdp_recv_callback_int][0x7fe51c050fe0]: CONNECTION_STATE_LICENSING status STATE_RUN_FAILED [-1]
[07:21:31:436] [63352:0000f77b] [ERROR][com.freerdp.core.transport] - [transport_check_fds]: transport_check_fds: transport->ReceiveCallback() - STATE_RUN_FAILED [-1]
[07:21:31:437] [63352:0000f77b] [ERROR][com.freerdp.proxy.client] - [pf_client_connect]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: failed to connect with NLA. retrying to connect without NLA
[07:21:31:450] [63352:0000f77b] [WARN][com.freerdp.core.gcc] - [filterAndLogEarlyServerCapabilityFlags]: TS_UD_SC_CORE::EarlyCapabilityFlags [0x00000fad & 0xfffffff0 --> 0x00000fa0] filtering RNS_UD_SC_UNKNOWN[0x00000fa0]|[0x00000fa0], feature not implemented
[07:21:31:451] [63352:0000f77b] [WARN][com.freerdp.core.connection] - [rdp_client_connect_auto_detect]: messageChannelId == 0
[07:21:31:451] [63352:0000f77b] [ERROR][com.freerdp.core] - [rdp_set_error_info]: ERRINFO_LOGOFF_BY_USER [0x0001000C]
[07:21:31:451] [63352:0000f77b] [WARN][com.freerdp.proxy.client] - [pf_client_on_error_info]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: received ErrorInfo PDU. code=0x00000012, message: The disconnection was initiated by the user logging off their session on the server.
[07:21:31:452] [63352:0000f77b] [ERROR][com.freerdp.core.peer] - [rdp_set_error_info]: ERRINFO_LOGOFF_BY_USER [0x0001000C]
[07:21:31:452] [63352:0000f77b] [ERROR][com.freerdp.core.peer] - [rdp_set_error_info]: TODO: Trying to set error code ERRINFO_LOGOFF_BY_USER, but ERRINFO_LOGOFF_BY_USER already set!
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [Stream_CheckAndLogRequiredLengthWLogExVa][0x7fe51c050fe0]: [rdp_read_security_header(/root/git/freerdp/libfreerdp/core/rdp.c:193)] invalid length, got 0, require at least 4 [element size=1]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 0: /root/git/freerdp-build/winpr/libwinpr/libwinpr3.so.3(winpr_backtrace+0x4a) [0x7fe53ef61c1a]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 1: /root/git/freerdp-build/winpr/libwinpr/libwinpr3.so.3(winpr_log_backtrace_ex+0x29) [0x7fe53ef670d9]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 2: /root/git/freerdp-build/winpr/libwinpr/libwinpr3.so.3(Stream_CheckAndLogRequiredLengthWLogExVa+0xc7) [0x7fe53ef68637]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 3: /root/git/freerdp-build/winpr/libwinpr/libwinpr3.so.3(Stream_CheckAndLogRequiredLengthWLogEx+0xe4) [0x7fe53ef68794]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 4: /root/git/freerdp-build/libfreerdp/libfreerdp3.so.3(+0x9ee6c) [0x7fe53f2aae6c]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 5: /root/git/freerdp-build/libfreerdp/libfreerdp3.so.3(+0x9b515) [0x7fe53f2a7515]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 6: /root/git/freerdp-build/libfreerdp/libfreerdp3.so.3(+0x9d852) [0x7fe53f2a9852]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 7: /root/git/freerdp-build/libfreerdp/libfreerdp3.so.3(+0x98865) [0x7fe53f2a4865]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 8: /root/git/freerdp-build/libfreerdp/libfreerdp3.so.3(+0xb14e1) [0x7fe53f2bd4e1]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 9: /root/git/freerdp-build/libfreerdp/libfreerdp3.so.3(freerdp_connect+0x778) [0x7fe53f2d3028]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 10: /root/git/freerdp-build/server/proxy/libfreerdp-server-proxy3.so.3(+0x16651) [0x7fe53f6a4651]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 11: /root/git/freerdp-build/server/proxy/libfreerdp-server-proxy3.so.3(+0x16b18) [0x7fe53f6a4b18]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 12: /root/git/freerdp-build/winpr/libwinpr/libwinpr3.so.3(+0x8d014) [0x7fe53ef50014]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 13: /lib64/libpthread.so.0(+0x817a) [0x7fe53e18317a]
[07:21:31:452] [63352:0000f77b] [WARN][com.freerdp.core.rdp] - [winpr_log_backtrace_ex][0x7fe51c050fe0]: 14: /lib64/libc.so.6(clone+0x43) [0x7fe53ebfadc3]
[07:21:31:452] [63352:0000f77b] [ERROR][com.freerdp.core.rdp] - [rdp_recv_callback_int][0x7fe51c050fe0]: CONNECTION_STATE_LICENSING status STATE_RUN_FAILED [-1]
[07:21:31:452] [63352:0000f77b] [ERROR][com.freerdp.core.transport] - [transport_check_fds]: transport_check_fds: transport->ReceiveCallback() - STATE_RUN_FAILED [-1]
[07:21:31:448] [63352:0000f77b] [DEBUG][com.freerdp.core.gcc] - [gcc_write_client_core_data]: Sending highColorDepth=HIGH_COLOR_24BPP, supportedColorDepths=RNS_UD_32BPP_SUPPORT|RNS_UD_24BPP_SUPPORT|RNS_UD_16BPP_SUPPORT|RNS_UD_15BPP_SUPPORT, earlyCapabilityFlags=RNS_UD_CS_SUPPORT_ERRINFO_PDU|RNS_UD_CS_SUPPORT_STATUSINFO_PDU|RNS_UD_CS_STRONG_ASYMMETRIC_KEYS|RNS_UD_CS_VALID_CONNECTION_TYPE|RNS_UD_CS_SUPPORT_NETCHAR_AUTODETECT|RNS_UD_CS_SUPPORT_DYNVC_GFX_PROTOCOL|RNS_UD_CS_SUPPORT_DYNAMIC_TIME_ZONE|RNS_UD_CS_SUPPORT_HEARTBEAT_PDU|RNS_UD_CS_SUPPORT_SKIP_CHANNELJOIN|[0x00000fad]
[07:21:31:448] [63352:0000f77b] [DEBUG][com.freerdp.core.gcc] - [gcc_write_client_monitor_data]: MonitorCount=0
[07:21:31:448] [63352:0000f77b] [DEBUG][com.freerdp.core.gcc] - [gcc_write_client_monitor_data]: FINISHED
[07:21:31:448] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_MCS_CREATE_REQUEST --> CONNECTION_STATE_MCS_CREATE_RESPONSE
[07:21:31:450] [63352:0000f77b] [DEBUG][com.freerdp.core.gcc] - [gcc_read_server_security_data]: Server rdp encryption method: NONE
[07:21:31:450] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_MCS_CREATE_RESPONSE --> CONNECTION_STATE_MCS_ERECT_DOMAIN
[07:21:31:450] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_MCS_ERECT_DOMAIN --> CONNECTION_STATE_MCS_ATTACH_USER
[07:21:31:450] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_MCS_ATTACH_USER --> CONNECTION_STATE_MCS_ATTACH_USER_CONFIRM
[07:21:31:450] [63352:0000f77b] [DEBUG][com.freerdp.core.connection] - [rdp_client_skip_mcs_channel_join]: rdpdr [1004]
[07:21:31:450] [63352:0000f77b] [DEBUG][com.freerdp.core.connection] - [rdp_client_skip_mcs_channel_join]: rdpsnd [1005]
[07:21:31:450] [63352:0000f77b] [DEBUG][com.freerdp.core.connection] - [rdp_client_skip_mcs_channel_join]: cliprdr [1006]
[07:21:31:450] [63352:0000f77b] [DEBUG][com.freerdp.core.connection] - [rdp_client_skip_mcs_channel_join]: drdynvc [1007]
[07:21:31:450] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_MCS_ATTACH_USER_CONFIRM --> CONNECTION_STATE_SECURE_SETTINGS_EXCHANGE
[07:21:31:450] [63352:0000f77b] [DEBUG][com.freerdp.core.info] - [rdp_write_info_packet]: Client Info Packet Flags = INFO_MOUSE|INFO_DISABLECTRLALTDEL|INFO_AUTOLOGON|INFO_UNICODE|INFO_MAXIMIZESHELL|INFO_COMPRESSION|INFO_ENABLEWINDOWSKEY|INFO_FORCE_ENCRYPTED_CS_PDU|INFO_LOGONERRORS|INFO_MOUSE_HAS_WHEEL|INFO_AUDIOCAPTURE
[07:21:31:450] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_SECURE_SETTINGS_EXCHANGE --> CONNECTION_STATE_CONNECT_TIME_AUTO_DETECT_REQUEST
[07:21:31:451] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_CONNECT_TIME_AUTO_DETECT_REQUEST --> CONNECTION_STATE_LICENSING
[07:21:31:451] [63352:0000f77b] [INFO][com.freerdp.core] - [rdp_print_errinfo]: ERRINFO_LOGOFF_BY_USER (0x0000000C):The disconnection was initiated by the user logging off their session on the server.
[07:21:31:452] [63352:0000f77b] [INFO][com.freerdp.core] - [rdp_print_errinfo]: ERRINFO_LOGOFF_BY_USER (0x0000000C):The disconnection was initiated by the user logging off their session on the server.
[07:21:31:452] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_send_data_pdu][0x7fe51c050fe0]: sending data (type=0x2f size=37 channelId=0)
[07:21:31:452] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_read_header][0x7fe51c050fe0]: DisconnectProviderUltimatum: reason: 3
[07:21:31:452] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_recv_callback_int][0x7fe51c050fe0]: CONNECTION_STATE_LICENSING - rdp_client_connect_license() - STATE_RUN_FAILED [-1]
[07:21:31:452] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_check_fds][0x7fe51c050fe0]: transport_check_fds() - -1
[07:21:31:453] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_finalize_reset_flags][0x7fe51c050fe0]: [CONNECTION_STATE_LICENSING] reset finalize_sc_pdus
[07:21:31:453] [63352:0000f77b] [DEBUG][com.freerdp.core.rdp] - [rdp_client_transition_to_state][0x7fe51c050fe0]: CONNECTION_STATE_LICENSING --> CONNECTION_STATE_INITIAL
[07:21:31:453] [63352:0000f77b] [DEBUG][com.freerdp.proxy.client] - [pf_client_client_stop]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: aborting client connection
[07:21:31:453] [63352:0000f77a] [INFO][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: abort event is set, closing connection with peer 192.168.0.231
[07:21:31:453] [63352:0000f77a] [INFO][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: starting shutdown of connection
[07:21:31:453] [63352:0000f77a] [INFO][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: stopping proxy's client
[07:21:31:453] [63352:0000f77a] [INFO][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: freeing server's channels
[07:21:31:453] [63352:0000f77a] [DEBUG][com.freerdp.core.rdp] - [rdp_send_data_pdu][0x7fe51c050fe0]: sending data (type=0x2f size=37 channelId=0)
[07:21:31:454] [63352:0000f77a] [INFO][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: freeing proxy data
[07:21:31:454] [63352:0000f77a] [DEBUG][com.winpr.thread] - [ThreadCloseHandle]: Thread running, setting to detached state!
[07:21:31:454] [63352:0000f77a] [DEBUG][com.freerdp.proxy.server] - [pf_server_handle_peer]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: Removed peer, 0 connected
[07:21:31:453] [63352:0000f77b] [ERROR][com.freerdp.proxy.client] - [pf_client_connect]: [SessionID=B67DC6F799BA034ABE44B13814DCA1FA]: pf_client_connect_without_nla failed!
matt335672 commented 1 month ago

Thanks - that's useful.

matt335672 commented 1 month ago

I see that @akallabeth has given you a workaround @StudyAndGrow using the xfreerdp client.

From my perspective I'm unable to reproduce this as described, which may be down to your Windows client configuration.

hardening commented 1 month ago

As @akallabeth remarked in FreeRDP/FreeRDP#10667 (which this is linked to), there's no configuration here. Can you add detail to both requests as to how you have configured the proxy, and any proxy logs please?

From the little I can see, there's a mismatch between the number of channels on the xrdp and proxy ends of the connection. This message :-

[2024-09-24T06:04:21.432+0000] [ERROR] Parsed [ITU-T T.125] DomainMCSPDU choice index expected 14, received 25

while admittedly rather cryptic tells us that xrdp is expecting a channel join request (14), but instead is getting a send data request.

Could it be that Xrdp doesn't support the "skip channel joins" flag ?

matt335672 commented 1 month ago

Thanks for that@hardening - I'd not come across that one before, and it's possible it's related to the issue.

You're referring to the RNS_UD_CS_SUPPORT_SKIP_CHANNELJOIN flag in the earlyCapabilityFlags field from the client. We don't parse that flag. We also don't send earlyCapabilities to the client at all, so we don't send RNS_UD_SC_SKIP_CHANNELJOIN_SUPPORTED.

The relevant section of [MS-RDPBCGR] is 3.2.5.3.8, and the relevant paragraph is this;-

If the client set the RNS_UD_CS_SUPPORT_SKIP_CHANNELJOIN flag in the earlyCapabilityFlags field of the Client Core Data (section 2.2.1.3.2), and the server set the RNS_UD_SC_SKIP_CHANNELJOIN_SUPPORTED flag in earlyCapabilityFlags field of the Server Core Data (section 2.2.1.4.2), then the MCS Channel Join Request PDUs (section 2.2.1.8) and the MCS Channel Join Confirm PDUs (section 2.2.1.9) SHOULD be skipped to reduce the connection time. Upon reception of the MCS Attach User Confirm PDU (section 2.2.1.7) all the MCS channels (the user channel, the I/O channel, the message channel, and all static virtual channels) SHOULD be considered as fully joined by the client. The client SHOULD NOT send any MCS Channel Join Request PDUs to server and SHOULD proceed to the RDP Security Commencement phase (section 1.3.1.1).

So a proper answer to your question would be that xrdp doesn't support the 'skip channel joins' flag, but it shouldn't need to.

Since there's a proxy involved here, it's possible that there's a mismatch in this area between xrdp and the eventual client. I'll need to reproduce this to be sure (which I'm happy to do), but I'll need more input from @StudyAndGrow.

I can see no reason however not to add support for this flag to xrdp.

akallabeth commented 1 month ago

@matt335672 most likely a configuration error on the submitter side. see my rationale for closing the https://github.com/FreeRDP/FreeRDP/issues/10667 without further details this can be closed as well as the setup described works if properly configured.

matt335672 commented 1 month ago

Thanks @akallabeth

If I get no more information from the OP within a few days I'll close this one too.