AnyConnect Client Fails To Get IP From Windows DHCP Server
KB ID 0001053 Dtd 16/04/15
Problem
A few days ago I did an article on AnyConnect and Windows DHCP. I ran it up on the test bench for a client, and everything worked fine. Doing the install my test 'remote' client failed to get an IP address.
As you can see the DHCP Server (Windows Server 2012 R2) is on a different network segment to the inside of the ASA.
Solution
1. First this to do was debug the connection, 'debug webvpn anyconnect 255' gives me this.
----Output Removed for the sake of Brevity----
Processing CSTP header line: 'X-CSTP-Protocol: Copyright (c) 2004 Cisco Systems, Inc.'
Validating address: 0.0.0.0
CSTP state = WAIT_FOR_ADDRESS
webvpn_cstp_accept_ipv6_address: No IPv6 Address
webvpn_cstp_accept_address: 0.0.0.0/0.0.0.0
webvpn_cstp_accept_address: no address?!?
CSTP state = HAVE_ADDRESS
No assigned address
webvpn_cstp_send_error: 503 Service Unavailable
CSTP state = ERROR
Not calling vpn_remove_uauth: not IPv4!
webvpn_svc_np_tear_down: no IPv6 ACL
----Output Removed for the sake of Brevity----
Processing CSTP header line: 'X-CSTP-Protocol: Copyright (c) 2004 Cisco Systems, Inc.'
Validating address: 0.0.0.0
CSTP state = WAIT_FOR_ADDRESS
webvpn_cstp_accept_ipv6_address: No IPv6 Address
webvpn_cstp_accept_address: 0.0.0.0/0.0.0.0
webvpn_cstp_accept_address: no address?!?
CSTP state = HAVE_ADDRESS
No assigned address
webvpn_cstp_send_error: 503 Service Unavailable
CSTP state = ERROR
Not calling vpn_remove_uauth: not IPv4!
webvpn_svc_np_tear_down: no IPv6 ACL
----Output Removed for the sake of Brevity----
OK so the remote client is not getting an IP address. Let's see what the ASA is doing by a packet capture, capturing any traffic to the DHCP server when I try to connect.
16 packets captured
1: 07:59:28.201573 10.1.1.1 > 10.2.2.10: udp 548
2: 07:59:31.198613 10.1.1.1 > 10.2.2.10: udp 548
3: 07:59:35.198399 10.1.1.1 > 10.2.2.10: udp 548
4: 07:59:40.198109 10.1.1.1 > 10.2.2.10: udp 548
5: 07:59:40.679392 10.1.1.1 > 10.2.2.10: udp 548
6: 07:59:43.677882 10.1.1.1 > 10.2.2.10: udp 548
7: 07:59:47.678706 10.1.1.1 > 10.2.2.10: udp 548
8: 07:59:52.678492 10.1.1.1 > 10.2.2.10: udp 548
9: 07:59:53.158713 10.1.1.1 > 10.2.2.10: udp 548<
10: 07:59:56.157218 10.1.1.1 > 10.2.2.10: udp 548
11: 08:00:00.156974 10.1.1.1 > 10.2.2.10: udp 548
12: 08:00:05.156684 10.1.1.1 > 10.2.2.10: udp 548
13: 08:00:05.637998 10.1.1.1 > 10.2.2.10: udp 548
14: 08:00:08.636456 10.1.1.1 > 10.2.2.10: udp 548
15: 08:00:12.636228 10.1.1.1 > 10.2.2.10: udp 548
16: 08:00:17.635938 10.1.1.1 > 10.2.2.10: udp 548
1: 07:59:28.201573 10.1.1.1 > 10.2.2.10: udp 548
2: 07:59:31.198613 10.1.1.1 > 10.2.2.10: udp 548
3: 07:59:35.198399 10.1.1.1 > 10.2.2.10: udp 548
4: 07:59:40.198109 10.1.1.1 > 10.2.2.10: udp 548
5: 07:59:40.679392 10.1.1.1 > 10.2.2.10: udp 548
6: 07:59:43.677882 10.1.1.1 > 10.2.2.10: udp 548
7: 07:59:47.678706 10.1.1.1 > 10.2.2.10: udp 548
8: 07:59:52.678492 10.1.1.1 > 10.2.2.10: udp 548
9: 07:59:53.158713 10.1.1.1 > 10.2.2.10: udp 548<
10: 07:59:56.157218 10.1.1.1 > 10.2.2.10: udp 548
11: 08:00:00.156974 10.1.1.1 > 10.2.2.10: udp 548
12: 08:00:05.156684 10.1.1.1 > 10.2.2.10: udp 548
13: 08:00:05.637998 10.1.1.1 > 10.2.2.10: udp 548
14: 08:00:08.636456 10.1.1.1 > 10.2.2.10: udp 548
15: 08:00:12.636228 10.1.1.1 > 10.2.2.10: udp 548
16: 08:00:17.635938 10.1.1.1 > 10.2.2.10: udp 548
Well this tells me I'm sending the traffic to the DHCP server but I'm not getting anything back. The DHCP server and the firewall can ping each other so whats wrong! I'd like to be able to say that the windows server event logs of the DHCP log would give me some good information, but it did not.
As a troubleshooting move, I moved the DHCP onto Switch A (Cisco 6880-X), then my colleague could watch the logs as I tried to connect.
----Output Removed for the sake of Brevity----
1626550: Apr 16 09:43:34.520 BST: DHCPD: DHCPDISCOVER received from client {VERY-LONG-Client-ID-1} through relay 192.168.50.0.
1626551: Apr 16 09:43:36.549 BST: DHCPD: assigned IP address 192.168.50.5 to client {VERY-LONG-Client-ID-1}.
1626552: Apr 16 09:43:36.549 BST: DHCPD: Sending DHCPOFFER to client {VERY-LONG-Client-ID-1} (192.168.50.5).
1626553: Apr 16 09:43:36.553 BST: DHCPD: no option 125
----Output Removed for the sake of Brevity----
1626550: Apr 16 09:43:34.520 BST: DHCPD: DHCPDISCOVER received from client {VERY-LONG-Client-ID-1} through relay 192.168.50.0.
1626551: Apr 16 09:43:36.549 BST: DHCPD: assigned IP address 192.168.50.5 to client {VERY-LONG-Client-ID-1}.
1626552: Apr 16 09:43:36.549 BST: DHCPD: Sending DHCPOFFER to client {VERY-LONG-Client-ID-1} (192.168.50.5).
1626553: Apr 16 09:43:36.553 BST: DHCPD: no option 125
----Output Removed for the sake of Brevity----
My DHCP server is getting the discover request form the ASA firewall but at the IP address that the ASA is presenting (192.168.50.0) it is not it's inside IP address!
It's the address that you put in the group-policy to set the dhcp-network-scope, that the firewall presents to the DHCP server.
Neither the Switch (or the original Windows DHCP server) had a route to that network. Once the local routing Ninja was dispatched to redistribute that network into the routing tables, everything started to work.
No comments:
Post a Comment