Slow getting IP address from DHCP server on Apple Macs

  • 2
  • Question
  • Updated 3 years ago
DHCP Server (AD1) - Windows Server 2012 R2
Aerohive AP230
Subnet 10.0.0.0/24

AD1 is connected to Cisco 2960X (S1) switch.
Using RADIUS authentication on AD1.
Aerohives are attached to a second Cisco 2960X (S2).
S1 and S2 are connected via ethernet cable.


Our Apple Mac computers can take a long time to get an IP address from our DHCP server.  Sometimes they'll have an Internet connection but then they drop and won't get assigned another IP.  If I disable the wifi interface and re-enable it'll either connect back right away or just spin and wait for an IP address to be assigned.

Is there a setting that I need to enable for Macs or any suggestions on how to handle this?

Thanks.
Photo of Michael

Michael

  • 8 Posts
  • 0 Reply Likes

Posted 3 years ago

  • 2
Photo of Nick Lowe

Nick Lowe, Official Rep

  • 2491 Posts
  • 451 Reply Likes
Have you updated the Macs to OS X 10.10.4?
(Edited)
Photo of Michael

Michael

  • 8 Posts
  • 0 Reply Likes
Yes
Photo of Nick Lowe

Nick Lowe, Official Rep

  • 2491 Posts
  • 451 Reply Likes
Cool. Having got that out of the way. What's the output of Client Monitor when this occurs?

http://blogs.aerohive.com/blog/the-wireless-lan-training-blog/troubleshooting-wi-fi-connectivity-wit...
Photo of Michael

Michael

  • 8 Posts
  • 0 Reply Likes
06/30/2015 03:05:33 PM 60F81DB7C5A6 9C5D12830554 AH-830540 INFO (24581)DHCP server sent out DHCP ACKNOWLEDGE message to station06/30/2015 03:05:33 PM 60F81DB7C5A6 9C5D12830554 AH-830540 BASIC (24582)DHCP session completed for station
06/30/2015 03:05:33 PM 60F81DB7C5A6 9C5D12830554 AH-830540 BASIC (24583)IP 10.0.2.162 assigned for station
06/30/2015 03:05:34 PM 60F81DB7C5A6 9C5D12830554 AH-830540 INFO (24584)station sent out DHCP REQUEST message
06/30/2015 03:05:34 PM 60F81DB7C5A6 9C5D12830554 AH-830540 INFO (24585)DHCP server sent out DHCP ACKNOWLEDGE message to station
06/30/2015 03:05:34 PM 60F81DB7C5A6 9C5D12830554 AH-830540 BASIC (24586)DHCP session completed for station
06/30/2015 03
:05:34 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24587)IP 10.0.2.162 assigned for station
06/30/2015 03:05:34 PM  60F81DB7C5A6  9C5D12830554  AH-830540    INFO    (24588)Rx disassoc (reason 8 <assoc-leave>, rssi -69dB)
06/30/2015 03:05:34 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24589)Sta(at if=wifi0.1) is de-authenticated because of notification of driver
06/30/2015 03:05:38 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24590)Rx <specific> probe req (rssi -67dB)
06/30/2015 03:05:38 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24591)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:38 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24592)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:38 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24593)Rx <broadcast> probe req (rssi -67dB)
06/30/2015 03:05:38 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24594)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:38 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24595)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:38 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24596)Rx <specific> probe req (rssi -68dB)
06/30/2015 03:05:38 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24597)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:38 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24598)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:38 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24599)Rx <broadcast> probe req (rssi -67dB)
06/30/2015 03:05:38 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24600)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:38 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24601)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24602)Rx <specific> probe req (rssi -56dB)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24603)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24604)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24605)Rx <broadcast> probe req (rssi -55dB)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24606)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24607)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24608)Rx <specific> probe req (rssi -54dB)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24609)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24610)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24611)Rx <broadcast> probe req (rssi -55dB)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24612)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24613)Tx probe resp (pwr 19dBm)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830564  AH-830540    DETAIL  (24614)Rx <specific> probe req (rssi -62dB)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830564  AH-830540    BASIC   (24615)Tx probe resp (pwr 14dBm)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830564  AH-830540    BASIC   (24616)Tx probe resp (pwr 14dBm)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830564  AH-830540    DETAIL  (24617)Rx <broadcast> probe req (rssi -62dB)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830564  AH-830540    BASIC   (24618)Tx probe resp (pwr 14dBm)
06/30/2015 03:05:58 PM  60F81DB7C5A6  9C5D12830564  AH-830540    BASIC   (24619)Tx probe resp (pwr 14dBm)


06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24743)Rx assoc req (rssi -66dB)
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24744)Tx assoc resp <accept> (status 0, pwr 19dBm)
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    INFO    (24745)IEEE802.1X auth is starting (at if=wifi0.1)
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24746)Send message to RADIUS Server(10.0.0.1): code=1 (Access-Request) identifier=162 length=153,  User-Name=tiffany.guo NAS-IP-Address=10.0.0.40 Called-Station-Id=9C-5D-12-83-05-54:FFHQ Calling-Station-Id=60-F8-1D-B7-C5-A6
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24747)Receive message from RADIUS Server: code=11 (Access-Challenge) identifier=162 length=90
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24748)Send message to RADIUS Server(10.0.0.1): code=1 (Access-Request) identifier=163 length=359,  User-Name=tiffany.guo NAS-IP-Address=10.0.0.40 Called-Station-Id=9C-5D-12-83-05-54:FFHQ Calling-Station-Id=60-F8-1D-B7-C5-A6
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24749)Receive message from RADIUS Server: code=11 (Access-Challenge) identifier=163 length=239
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24750)Send message to RADIUS Server(10.0.0.1): code=1 (Access-Request) identifier=164 length=244,  User-Name=tiffany.guo NAS-IP-Address=10.0.0.40 Called-Station-Id=9C-5D-12-83-05-54:FFHQ Calling-Station-Id=60-F8-1D-B7-C5-A6
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24751)Receive message from RADIUS Server: code=11 (Access-Challenge) identifier=164 length=191
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24752)Send message to RADIUS Server(10.0.0.1): code=1 (Access-Request) identifier=165 length=218,  User-Name=tiffany.guo NAS-IP-Address=10.0.0.40 Called-Station-Id=9C-5D-12-83-05-54:FFHQ Calling-Station-Id=60-F8-1D-B7-C5-A6
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    DETAIL  (24753)Receive message from RADIUS Server: code=2 (Access-Accept) identifier=165 length=291 
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    INFO    (24754)Sending 1/4 msg of 4-Way Handshake (at if=wifi0.1)
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    INFO    (24755)Received 2/4 msg of 4-Way Handshake (at if=wifi0.1)
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    INFO    (24756)Sending 3/4 msg of 4-Way Handshake (at if=wifi0.1)
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    INFO    (24757)Received 4/4 msg of 4-Way Handshake (at if=wifi0.1)
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    INFO    (24758)PTK is set (at if=wifi0.1)
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830554  AH-830540    BASIC   (24759)Authentication is successfully finished (at if=wifi0.1)
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830564  AH-830540    BASIC   (24760)Sta(at if=wifi1.1) is de-authenticated because of roaming away
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830564  AH-830540    INFO    (24761)Tx deauth (reason 4 <assoc-leave>, pwr 14dBm)
06/30/2015 03:06:55 PM  60F81DB7C5A6  9C5D12830564  AH-830540    BASIC   (24762)Sta(at if=wifi1.1) is de-authenticated because of notification of driver
Photo of Nick Lowe

Nick Lowe, Official Rep

  • 2491 Posts
  • 451 Reply Likes
I think to diagnose this further, we're going to need a packet capture from the client.
Photo of Michael

Michael

  • 8 Posts
  • 0 Reply Likes
Could it be anything to do with slow RADIUS response time?  I've noticed it usually lags on authentication.  Our RADIUS server is Windows Server.  I have 3 APs and noticed it's only with this one AP so I'm going to swap it with another and see if it fixes the issue.
Photo of Nick Lowe

Nick Lowe, Official Rep

  • 2491 Posts
  • 451 Reply Likes
Are you running NPS on domain controllers or independent servers? NPS is significantly more responsive when it's running on a domain controller. (This can be a RODC if needed for security.)

One issue I've had historically with NPS has been it locking all its processing threads up performing lookups for non existent domain names supplied by misconfigured clients in the identity. Yes, a lookup timeout does occur but this happens when you have enough bad acting clients, they collectively perform a pretty good DoS on your server(s).

An effective workaround to this is to use a regular expression on the Connection Request Policy (CRP).

I can supply a regular expression to do this if interested.

Another thing to do is to ensure that you have dialled back the per-session RADIUS accounting interval to something sensible if you have accounting enabled. It used to be 20 seconds in HiveOS but it now defaults to 600 seconds for new configurations.

Finally, check what logging you are performing in NPS - where to, what exactly is being logged. This is a blocking process that can delay authentication, especially with slow backing I/O.

---

EDIT: Also, check for packet loss. RADIUS won't thank you if packet loss is occurring.
(Edited)
Photo of Michael

Michael

  • 8 Posts
  • 0 Reply Likes
NPS is running on a domain controller.  I will check the other suggestions and report back.
Photo of Nick Lowe

Nick Lowe, Official Rep

  • 2491 Posts
  • 451 Reply Likes
That client monitor log doesn't show anything going wrong with DHCP:

06/30/2015 03:05:34 PM 60F81DB7C5A6 9C5D12830554 AH-830540 INFO (24584)station sent out DHCP REQUEST message
06/30/2015 03:05:34 PM 60F81DB7C5A6 9C5D12830554 AH-830540 INFO (24585)DHCP server sent out DHCP ACKNOWLEDGE message to station
06/30/2015 03:05:34 PM 60F81DB7C5A6 9C5D12830554 AH-830540 BASIC (24586)DHCP session completed for station
(Edited)
Photo of Kyle Heading

Kyle Heading

  • 9 Posts
  • 1 Reply Like
we had a similar issue a while back, we fixed it by putting our DHCP server on the same subnet as the clients, originally I was thinking it was a pre 10.10.4 issue but having the DHCP server on the same subnet definitely resolved it for us.

let me know if you want more details :)
Photo of Nick Lowe

Nick Lowe, Official Rep

  • 2491 Posts
  • 451 Reply Likes
DHCP relay doesn't usually and shouldn't impose a user perceptible delay on DHCP completing on a client.

That doesn't appear to be the case here in any case due to the timings seen via Client Monitor.
Photo of Michael

Michael

  • 8 Posts
  • 0 Reply Likes
The DHCP server is on the same subnet.