RDP connections might fail due to a problem with KB2621440 - MS12-020

Artigo
01/18/2013

I was helping a colleague who was dealing with a Remote desktop connection problem where Windows 8 client was failing to access a certain Windows 2008 R2 SP1 Terminal server. We first collected some logs while reproducing the problem to better understand why the RDP connection was failing:

1) Please start TCPIP/Winsock ETL tracing on the client and on the Windows 2008 R2 TS from an elevated command prompt:

netsh trace start provider=Microsoft-Windows-TCPIP provider=Microsoft-Windows-Winsock-AFD tracefile=Terminalserver_tcpip_winsock.etl maxsize=500 capture=yes

Note: This command generates a lot of activity so we have to do the testing as fast as possible.

2) Please immediately reproduce the problem from the client by trying RDP connection. Right after the problem is reproduced please immediately stop netsh on the Windows 2008 R2 server first with the below command:

netsh trace stop

ANALYSIS:

========

After the logs were collected, I followed the below steps to further troubleshoot the issue:

=> The problem RDP session in the RDP server side ETL trace including network activity trace:

(ip.addr eq 10.0.107.58 and ip.addr eq 10.7.3.187) and (tcp.port eq 59193 and tcp.port eq 3389)

No. Time Delta Source Destination Protocol Length Info

5781 2013-01-06 09:52:15.407 0.000 10.0.107.58 10.7.3.187 TCP 66 59193 > 3389 [SYN] Seq=3976196062 Win=8192 Len=0 MSS=1380 WS=256

5782 2013-01-06 09:52:15.407 0.000 10.7.3.187 10.0.107.58 TCP 62 3389 > 59193 [SYN, ACK] Seq=3028123794 Ack=3976196063 Win=8192 Len=0 MSS=1460 WS=256

5783 2013-01-06 09:52:15.447 0.039 10.0.107.58 10.7.3.187 TCP 60 59193 > 3389 [ACK] Seq=3976196063 Ack=3028123795 Win=66048 Len=0

5784 2013-01-06 09:52:15.448 0.000 10.0.107.58 10.7.3.187 TPKT 73 CR TPDU src-ref: 0x0000 dst-ref: 0x0000[Unreassembled Packet]

5785 2013-01-06 09:52:15.451 0.003 10.7.3.187 10.0.107.58 TCP 54 3389 > 59193 [ACK] Seq=3028123795 Ack=3976196082 Win=66048 Len=0

5786 2013-01-06 09:52:15.458 0.007 10.7.3.187 10.0.107.58 TPKT 73 CC TPDU src-ref: 0x1234 dst-ref: 0x0000[Unreassembled Packet]

5787 2013-01-06 09:52:15.520 0.062 10.0.107.58 10.7.3.187 TCP 60 59193 > 3389 [ACK] Seq=3976196082 Ack=3028123814 Win=66048 Len=0

5958 2013-01-06 09:52:22.632 7.111 10.0.107.58 10.7.3.187 TPKT 218 Continuation

5959 2013-01-06 09:52:22.632 0.000 10.7.3.187 10.0.107.58 TPKT 912 Continuation

5971 2013-01-06 09:52:22.678 0.045 10.0.107.58 10.7.3.187 TPKT 380 Continuation

5972 2013-01-06 09:52:22.696 0.018 10.7.3.187 10.0.107.58 TPKT 113 Continuation

5975 2013-01-06 09:52:22.752 0.055 10.0.107.58 10.7.3.187 TPKT 235 Continuation

5976 2013-01-06 09:52:22.753 0.000 10.7.3.187 10.0.107.58 TPKT 1211 Continuation

5977 2013-01-06 09:52:22.809 0.055 10.0.107.58 10.7.3.187 TPKT 1434 Continuation

5978 2013-01-06 09:52:22.809 0.000 10.7.3.187 10.0.107.58 TCP 54 3389 > 59193 [ACK] Seq=3028125888 Ack=3976198133 Win=65792 Len=0

5979 2013-01-06 09:52:22.809 0.000 10.0.107.58 10.7.3.187 TPKT 263 Continuation

5980 2013-01-06 09:52:22.810 0.001 10.7.3.187 10.0.107.58 TPKT 315 Continuation

...

8129 2013-01-06 09:52:49.090 0.094 10.0.107.58 10.7.3.187 TCP 60 59193 > 3389 [ACK] Seq=3976208206 Ack=3028242245 Win=64768 Len=0

8154 2013-01-06 09:52:49.526 0.436 10.7.3.187 10.0.107.58 TPKT 139 Continuation

8164 2013-01-06 09:52:49.620 0.093 10.0.107.58 10.7.3.187 TCP 60 59193 > 3389 [ACK] Seq=3976208206 Ack=3028242330 Win=64768 Len=0

8170 2013-01-06 09:52:49.673 0.052 10.0.107.58 10.7.3.187 TPKT 123 Continuation

8180 2013-01-06 09:52:49.776 0.102 10.7.3.187 10.0.107.58 TPKT 683 Continuation

8186 2013-01-06 09:52:49.874 0.097 10.0.107.58 10.7.3.187 TCP 60 59193 > 3389 [ACK] Seq=3976208275 Ack=3028242959 Win=66048 Len=0

8254 2013-01-06 09:52:52.475 2.600 10.7.3.187 10.0.107.58 TPKT 91 Continuation

8257 2013-01-06 09:52:52.567 0.092 10.0.107.58 10.7.3.187 TCP 60 59193 > 3389 [ACK] Seq=3976208275 Ack=3028242996 Win=66048 Len=0

10717 2013-01-06 09:53:40.765 48.198 10.7.3.187 10.0.107.58 TCP 54 3389 > 59193 [RST, ACK] Seq=3028242996 Ack=3976208275 Win=0 Len=0

The RDP server resets the existing RDP session. Interestingly all following RDP session attempts are immediately RESET:

I decided to check why TCPIP driver was reseting all incoming connection attempts from the ETL trace:

61714 8:53:53 AM 1/6/2013 111.1142353 Idle (0) 10.0.107.58 10.7.3.187 TCP TCP:Flags=......S., SrcPort=59210, DstPort=MS WBT Server(3389), PayloadLen=0, Seq=2885139468, Ack=0, Win=8192 ( Negotiating scale factor 0x8 ) = 8192

61715 8:53:53 AM 1/6/2013 111.1142441 Idle (0) TCPIP_MicrosoftWindowsTCPIP TCPIP_MicrosoftWindowsTCPIP:TCPIP: NBL 0x0000000039EE1B40 fell off the receive fast path, Reason: Session state is not compatible. Protocol = TCP, Family = IPV4, Number of NBLs = 1 (0x1). SourceAddress = 10.0.107.58 Null. DestAddress = 10.7.3.187 Null.

61716 8:53:53 AM 1/6/2013 111.1142562 Idle (0) TCPIP_MicrosoftWindowsTCPIP TCPIP_MicrosoftWindowsTCPIP:TCPIP: Transport (Protocol TCP, AddressFamily = IPV4) dropped 1 (0x1) packet(s) with Source = 10.7.3.187:3389, Destination = 10.0.107.58:59210. Reason = Transport endpoint was not found.

61717 8:53:53 AM 1/6/2013 111.1142853 Idle (0) 10.7.3.187 10.0.107.58 TCP TCP: [Bad CheckSum]Flags=...A.R.., SrcPort=MS WBT Server(3389), DstPort=59210, PayloadLen=0, Seq=0, Ack=2885139469, Win=0

that means there’s no process listening on TCP 3389. When we check the netstat output collected from RDP server, we really don’t see a process listening on that port:

TCP 0.0.0.0:80 0.0.0.0:0 LISTENING 4 InHost

TCP 0.0.0.0:135 0.0.0.0:0 LISTENING 920 InHost

TCP 0.0.0.0:443 0.0.0.0:0 LISTENING 4 InHost

TCP 0.0.0.0:445 0.0.0.0:0 LISTENING 4 InHost

TCP 0.0.0.0:4279 0.0.0.0:0 LISTENING 5796 InHost

TCP 0.0.0.0:5279 0.0.0.0:0 LISTENING 5796 InHost

TCP 0.0.0.0:8530 0.0.0.0:0 LISTENING 4 InHost

TCP 0.0.0.0:8531 0.0.0.0:0 LISTENING 4 InHost

TCP 0.0.0.0:47001 0.0.0.0:0 LISTENING 4 InHost

TCP 0.0.0.0:49152 0.0.0.0:0 LISTENING 636 InHost

TCP 0.0.0.0:49153 0.0.0.0:0 LISTENING 232 InHost

TCP 0.0.0.0:49154 0.0.0.0:0 LISTENING 240 InHost

TCP 0.0.0.0:49155 0.0.0.0:0 LISTENING 740 InHost

TCP 0.0.0.0:49156 0.0.0.0:0 LISTENING 724 InHost

TCP 0.0.0.0:49161 0.0.0.0:0 LISTENING 3048 InHost

TCP 10.7.3.187:80 10.193.10.7:49684 ESTABLISHED 4 InHost

=> Also at the exact time which matches the time of initial RDP connection being reset, we see the following event on RDP server which explains why the current connection is reset and the new ones are reset as well:

Error 1/6/2013 8:54:40 AM Service Control Manager 7034 None

The Remote Desktop Services service terminated unexpectedly. It has done this 3 time(s).

My colleague kept troubleshooting the problem from Terminal server perspective and they found out that https://support.microsoft.com/kb/2621440/en-us was re-published due to an initial problem with the security update. After reinstalling the security update, the issue was resolved.

Hope this helps you when dealing with similar problems.

Thanks,

Murat

Comments

Anonymous
September 09, 2015
Murat thank you! Very helpful indeed. For those with unresolved issue of random disconnects, check your GPO closely because we chased this down for months until this solved the issue:https://support.microsoft.com/en-us/kb/2083411
Anonymous
December 18, 2015
Nile - setting the registry key solved our problem as well.

Partilhar via

RDP connections might fail due to a problem with KB2621440 - MS12-020

Comments

Recursos adicionais