Issue: DHCP deassigns address

~400 dhcp clients, ROS 6.19, DHCP deassings addresess from clients after lease timeout.
Client asks for lease update, radius answers ok, acces-accept, but dhcp send nak:

12:53:45 dhcp,debug,packet DHCP received request with id 1459788688 from 10.195.5.149 
12:53:45 dhcp,debug,packet ciaddr = 10.195.5.149 
12:53:45 dhcp,debug,packet chaddr = 6C:71:D9:67:CF:E9 
12:53:45 dhcp,debug,packet Msg-Type = request 
12:53:45 dhcp,debug,packet Client-Id = 01-6C-71-D9-67-CF-E9 
12:53:45 dhcp,debug,packet Unknown(57) = 05-D4 
12:53:45 dhcp,debug,packet Parameter-List = Subnet-Mask,Router,Domain-Server,Host-Name,Domain-Name,Unknown(28),Static-Route,NTP-Server,MS-Classless-Route 
12:53:45 dhcp,debug,packet Class-Id = "udhcp 1.17.4" 
12:53:45 dhcp,debug,packet Relay-Agent-Info = 01-06-00-04-00-52-01-0D-02-08-00-06-FC-FB-FB-85-32-00 
12:53:45 dhcp,debug,packet Relay-Agent-Info = 01-06-00-04-00-52-04-0C-02-08-00-06-54-75-D0-BD-5B-40 
12:53:45 radius,debug new request 17:33da code=Access-Request service=dhcp called-id=DHCP 
12:53:45 radius,debug sending 17:33da to 10.192.7.132:1812 
12:53:45 radius,debug,packet sending Access-Request with id 112 to 10.192.7.132:1812 
12:53:45 radius,debug,packet Signature = 0x79fc455dad0b5963f2ac1f204289bf79 
12:53:45 radius,debug,packet NAS-Port-Type = 15 
12:53:45 radius,debug,packet NAS-Port = 2199348780 
12:53:45 radius,debug,packet Calling-Station-Id = "1:6c:71:d9:67:cf:e9" 
12:53:45 radius,debug,packet Framed-IP-Address = 10.195.5.142 
12:53:45 radius,debug,packet Called-Station-Id = "DHCP" 
12:53:45 radius,debug,packet User-Name = "6C:71:D9:67:CF:E9" 
12:53:45 radius,debug,packet User-Password = 0x 
12:53:45 radius,debug,packet Unknown-Attribute(vendor=Redback, type=96) = 0x0006fcfbfb853200 
12:53:45 radius,debug,packet Unknown-Attribute(vendor=Redback, type=97) = 0x00040052010d 
12:53:45 radius,debug,packet NAS-Identifier = "Router-PPPoE-01" 
12:53:45 radius,debug,packet MT-Realm = 0x31302e3139322e372e313332 
12:53:45 radius,debug,packet NAS-IP-Address = 10.192.32.92 
12:53:45 radius,debug,packet received Access-Accept with id 112 from 10.192.7.132:1812 
12:53:45 radius,debug,packet Signature = 0x1be294f8787795c4406520e87518f193 
12:53:45 radius,debug,packet Framed-Pool = "nat" 
12:53:45 radius,debug,packet MT-Address-List = "30M_class_client" 
12:53:45 radius,debug,packet Session-Timeout = 7200 
12:53:45 radius,debug received reply for 17:33da 
12:53:45 dhcp,error DHCP: failed to add address-list 30M_class_client for IP 10.195.5.142: already have such entry (6) 
12:53:45 dhcp,debug,packet DHCP sending nak with id 1459788688 to 255.255.255.255 
12:53:45 dhcp,debug,packet ciaddr = 0.0.0.0 
12:53:45 dhcp,debug,packet chaddr = 6C:71:D9:67:CF:E9 
12:53:45 dhcp,debug,packet Msg-Type = nak 
12:53:45 dhcp,debug,packet Server-Id = 10.170.4.1 
12:53:45 dhcp,debug,packet Relay-Agent-Info = 01-06-00-04-00-52-01-0D-02-08-00-06-FC-FB-FB-85-32-00-01-06-00-04-00-52-04-0C-02-08-00-06-54-75-D0-BD-5B-40 
12:53:45 dhcp,info DHCP deassigned 10.195.5.142 from 6C:71:D9:67:CF:E9

Every 2 hours(7200 sec) different clients loosing connection. Dhcp gives one address(10.195.5.149) but thinks about other(10.195.5.142), then deassign address, so clients losing all the connections.
[Ticket#2014090166000323] without answer from support.
Somebody else have this problem?

Check the entries in “/ip dhcp-server lease”.

/ip dhcp-server lease
print detail

Check the “expires-after” and “last-seen” entries. They should total the lease time. I had problems with this several versions ago when the “expires-after” time was not being updated after the lease renew. Maybe the same is happening to you.

Entries is ok:

372 R address=nat mac-address=EC:43:F6:08:66:61 client-id="1:ec:43:f6:8:66:61" server=DHCP lease-time=2h dhcp-option="" status=bound expires-after=1h1m9s last-seen=58m51s active-address=10.195.4.47 active-mac-address=EC:43:F6:08:66:61 
     active-client-id="1:ec:43:f6:8:66:61" active-server=DHCP host-name="Keenetic_Giga" agent-circuit-id="0:4:0:52:1:3" agent-remote-id="0:6:d0:c2:82:f5:bd:0" 

373 R address=nat mac-address=EC:43:F6:08:66:71 client-id="1:ec:43:f6:8:66:71" server=DHCP lease-time=2h dhcp-option="" status=bound expires-after=1h11m9s last-seen=48m51s active-address=10.195.4.177 active-mac-address=EC:43:F6:08:66:7>
     active-client-id="1:ec:43:f6:8:66:71" active-server=DHCP host-name="Keenetic_Giga" agent-circuit-id="0:4:0:52:1:12" agent-remote-id="0:6:64:d9:89:5a:9e:0" 

374 R address=nat mac-address=20:CF:30:D6:BD:0C client-id="1:20:cf:30:d6:bd:c" server=DHCP lease-time=2h dhcp-option="" status=bound expires-after=1h14m6s last-seen=45m54s active-address=10.195.4.130 active-mac-address=20:CF:30:D6:BD:0>
     active-client-id="1:20:cf:30:d6:bd:c" active-server=DHCP host-name="TL-WR841N" agent-circuit-id="0:4:0:52:1:10" agent-remote-id="0:6:1c:17:d3:47:83:80" 

375 R address=nat mac-address=58:6D:8F:50:F3:C7 server=DHCP lease-time=2h dhcp-option="" status=bound expires-after=1h24m58s last-seen=35m2s active-address=10.195.4.213 active-mac-address=58:6D:8F:50:F3:C7 active-server=DHCP 
     agent-circuit-id="0:4:0:52:1:7" agent-remote-id="0:6:ec:44:76:c5:4b:80" 

376 R address=nat mac-address=F8:D1:11:A7:08:4B client-id="1:f8:d1:11:a7:8:4b" server=DHCP lease-time=5m dhcp-option="" status=bound expires-after=3m53s last-seen=1m7s active-address=10.195.5.61 active-mac-address=F8:D1:11:A7:08:4B 
     active-client-id="1:f8:d1:11:a7:8:4b" active-server=DHCP agent-circuit-id="0:4:0:52:1:a" agent-remote-id="0:6:8:17:35:78:c:80" 

377 R address=nat mac-address=F4:F1:5A:4B:B9:63 client-id="1:f4:f1:5a:4b:b9:63" server=DHCP lease-time=5m dhcp-option="" status=bound expires-after=3m39s last-seen=1m21s active-address=10.195.4.156 active-mac-address=F4:F1:5A:4B:B9:63 
     active-client-id="1:f4:f1:5a:4b:b9:63" active-server=DHCP agent-circuit-id="0:4:0:52:1:d" agent-remote-id="0:6:64:d9:89:80:d3:80" 

378 R address=nat mac-address=E0:3F:49:75:C0:68 client-id="1:e0:3f:49:75:c0:68" server=DHCP lease-time=2h dhcp-option="" status=bound expires-after=1h52m28s last-seen=7m32s active-address=10.195.5.60 active-mac-address=E0:3F:49:75:C0:6>
     active-client-id="1:e0:3f:49:75:c0:68" active-server=DHCP agent-circuit-id="0:4:0:52:1:3" agent-remote-id="0:6:1c:17:d3:d0:97:80"

Why are some lease times 2 hours and others 5 minutes? Both were issued by the same dhcp server.

374 R address=nat mac-address=20:CF:30:D6:BD:0C client-id=“1:20:cf:30:d6:bd:c” > server=DHCP lease-time=2h > dhcp-option=“” status=bound expires-after=1h14m6s last-seen=45m54s active-address=10.195.4.130 active-mac-address=20:CF:30:D6:BD:0>
active-client-id=“1:20:cf:30:d6:bd:c” active-server=DHCP host-name=“TL-WR841N” agent-circuit-id=“0:4:0:52:1:10” agent-remote-id=“0:6:1c:17:d3:47:83:80”



376 R address=nat mac-address=F8:D1:11:A7:08:4B client-id=“1:f8:d1:11:a7:8:4b” > server=DHCP lease-time=5m > dhcp-option=“” status=bound expires-after=3m53s last-seen=1m7s active-address=10.195.5.61 active-mac-address=F8:D1:11:A7:08:4B
active-client-id=“1:f8:d1:11:a7:8:4b” active-server=DHCP agent-circuit-id=“0:4:0:52:1:a” agent-remote-id=“0:6:8:17:35:78:c:80”

One for “blocked” address-list, so client pay for internet, 5 min expires → new request to radius → mikrotik changes the address list
Second for others, client refreshes ip-address every 2 hours or get blocked on expire.

Heh, another one issue with 6.19, mikrotik not changing address list of client, but adds another one, because of:

*) dhcpv4 server - support multiple radius address lists;

I have now:

  1. error in the log:

11:01:34 dhcp,error DHCP: failed to add address-list blocked for IP 10.195.4.236: already have such entry (6)

  1. multiple address lists like:
> ip firewall address-list print
Flags: X - disabled, D - dynamic 
 #   LIST                          
...
33 D blocked    10.195.4.236                   
34 D 50M_class_client    10.195.4.236                   
35 D 30M_class_client    10.195.4.236
...

Because my DHCP server get parameters from radius:

  • Framed-Pool
    Mikrotik-Address-List
    Session-Timeout

So dhcp server adds new address list instead of updating old one.
Don’t know what to do now. Revert back to 6.18?