[Kea-users] kea-dhcp4 version1.8 , unable to send response packet

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

[Kea-users] kea-dhcp4 version1.8 , unable to send response packet

Stefan Berger
Hi all,

i have upgraded a kea-dhcp4 setup from version 1.6 to 1.8
it's a simple setup with a shared subnet and two normal subnets.
I'm using the premium hooks.

The Server is receiving requests from multiple cisco routers which are
accting as forwarders (ip helper - convert request to unicast and send it to server)
The client requests are transmitted over a GRE tunnel which terminates directly on the Server

KEA DHCP4 itself is listening on Loopbackdevice (172.16.160.248)

Server Information
-------------------------
OEL 7
Kernel 3.10.0-862.11.6.el7.x86_64
Kea 1.8 with premium hooks


INTERFACE-CONFIG
--------------------------
"interfaces-config": {
        "interfaces": [ "lo/172.16.160.248" ],
        "dhcp-socket-type": "udp"
    },

This Setup was working fne under version 1.6 but with 1.8 the server isn't able to send packets back
to client.

The log shows that everything is working fine until a response should be sent to client
": failed to send DHCPv4 packet: Interface tun1/8 does not have any suitable IPv4 sockets open."

2021-03-25 14:09:58.577 DEBUG [kea-dhcp4.packets/4784.139911471499392] DHCP4_PACKET_SEND [hwtype=1 f4:cf:e2:98:75:e1],
cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0xb4b: try
ing to send packet DHCPOFFER (type 2) from 172.16.160.248:67 to 192.168.200.254:67 on interface lo

2021-03-25 14:09:58.577 ERROR [kea-dhcp4.packets/4784.139911471499392] DHCP4_PACKET_SEND_FAIL
 [hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0xb4b
: failed to send DHCPv4 packet: Interface tun1/8 does not have any suitable IPv4 sockets open.

Any hints what could be wrong ?


FULL-LOG
------------------
2021-03-25 14:09:58.573 DEBUG [kea-dhcp4.packets/4784.139911471499392] DHCP4_BUFFER_RECEIVED
received buffer from 192.168.200.254:67 to 172.16.160.248:67 over interface lo
2021-03-25 14:09:58.573 DEBUG [kea-dhcp4.packets/4784.139911471499392] DHCP4_PACKET_RECEIVED
 [hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0xb4b:
DHCPDISCOVER (type 1) received from 192.168.200.254 to 172.16.160.248 on interface lo
2021-03-25 14:09:58.573 DEBUG [kea-dhcp4.callouts/4784.139911471499392] HOOKS_CALLOUTS_BEGIN
 begin all callouts for hook pkt4_receive
2021-03-25 14:09:58.573 DEBUG [kea-dhcp4.callouts/4784.139911471499392] HOOKS_CALLOUTS_COMPLETE
 completed callouts for hook pkt4_receive (total callouts duration: 0.027 ms)
2021-03-25 14:09:58.573 DEBUG [kea-dhcp4.packets/4784.139911471499392] DHCP4_SUBNET_SELECTED
 [hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0xb4b:
 the subnet with ID 391001 was selected for client assignments
2021-03-25 14:09:58.573 DEBUG [kea-dhcp4.callouts/4784.139911471499392] HOOKS_CALLOUTS_BEGIN
 begin all callouts for hook host4_identifier
2021-03-25 14:09:58.574 DEBUG [kea-dhcp4.flex-id-hooks/4784.139911471499392] FLEX_ID_EXPRESSION_EVALUATED
Expression evaluated for packet to "" (size: 0)
2021-03-25 14:09:58.574 DEBUG [kea-dhcp4.callouts/4784.139911471499392] HOOKS_CALLOUTS_COMPLETE
 completed callouts for hook host4_identifier (total callouts duration: 0.239 ms)
2021-03-25 14:09:58.575 DEBUG [kea-dhcp4.dhcp4/4784.139911471499392] DHCP4_CLASS_ASSIGNED
[hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0xb4b: cl
ient packet has been assigned to the following class(es): UNKNOWN
2021-03-25 14:09:58.575 DEBUG [kea-dhcp4.dhcp4/4784.139911471499392] DHCP4_CLASS_ASSIGNED
 [hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0xb4b: cl
ient packet has been assigned to the following class(es): ALL, VENDOR_CLASS_ciscopnp, UNKNOWN
2021-03-25 14:09:58.575 DEBUG [kea-dhcp4.alloc-engine/4784.139911471499392] ALLOC_ENGINE_V4_OFFER_NEW_LEASE
allocation engine will try to offer new lease to the client [hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:
66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0xb4b
2021-03-25 14:09:58.576 DEBUG [kea-dhcp4.callouts/4784.139911471499392] HOOKS_CALLOUTS_BEGIN
 begin all callouts for hook lease4_select
2021-03-25 14:09:58.576 DEBUG [kea-dhcp4.callouts/4784.139911471499392] HOOKS_CALLOUTS_COMPLETE
 completed callouts for hook lease4_select (total callouts duration: 0.060 ms)
2021-03-25 14:09:58.577 INFO  [kea-dhcp4.leases/4784.139911471499392] DHCP4_LEASE_ADVERT
 [hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0xb4b: lea
se 192.168.200.1 will be advertised
2021-03-25 14:09:58.577 DEBUG [kea-dhcp4.callouts/4784.139911471499392] HOOKS_CALLOUTS_BEGIN
begin all callouts for hook pkt4_send
2021-03-25 14:09:58.577 DEBUG [kea-dhcp4.callouts/4784.139911471499392] HOOKS_CALLOUTS_COMPLETE
 completed callouts for hook pkt4_send (total callouts duration: 0.024 ms)
2021-03-25 14:09:58.577 DEBUG [kea-dhcp4.packets/4784.139911471499392] DHCP4_PACKET_SEND
 [hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0xb4b: try
ing to send packet DHCPOFFER (type 2) from 172.16.160.248:67 to 192.168.200.254:67 on interface lo
2021-03-25 14:09:58.577 ERROR [kea-dhcp4.packets/4784.139911471499392] DHCP4_PACKET_SEND_FAIL
 [hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0xb4b
: failed to send DHCPv4 packet: Interface tun1/8 does not have any suitable IPv4 sockets open.


SUBNET-CONFIG
---------------------

"shared-networks": [
            {
                        "name": "TEST-NET-1",
                        "subnet4": [
                            {
                                "subnet": "192.168.202.0/24",
                                "id": 391002,
                                "match-client-id": false,
                                "pools": [
                                            { "pool": "192.168.202.1 - 192.168.202.100" },
                                            { "pool": "192.168.202.200 - 192.168.202.220" }
                                ],
           
                                "option-data": [
                                    {
                                        "name": "routers",
                                        "data": "192.168.202.254"
                                    }
                                ],
           
                                "relay": {
                                            "ip-address": "192.168.202.254"
                                }
                            },
   
                            {
                                "subnet": "192.168.203.0/24",
                                "id": 391003,
                                "match-client-id": false,
                                "pools": [
                                            { "pool": "192.168.203.1 - 192.168.203.100" },
                                            { "pool": "192.168.203.200 - 192.168.203.220" }
                                ],
           
                                "option-data": [
                                    {
                                        "name": "routers",
                                        "data": "192.168.203.254"
                                    }
                                ],
           
                                "relay": {
                                            "ip-address": "192.168.203.254"
                                }
                            }
                        ]    
            }
           
    ],

    "subnet4": [
        {
            "subnet": "192.168.201.0/24",
            "id": 391000,
            "match-client-id": false,
            "pools": [
                        { "pool": "192.168.201.1 - 192.168.201.100" }
            ],
           
            "option-data": [
                {
                    "name": "routers",
                    "data": "192.168.201.254"
                },
                {
                    "name": "ntp-servers",
                    "data": "10.220.1.253"
                }
            ],
           
            "relay": {
                        "ip-address": "192.168.201.254"
            }
        },
       
        {
            "subnet": "192.168.200.0/24",
            "id": 391001,
            "match-client-id": false,
            "pools": [
                        { "pool": "192.168.200.1 - 192.168.200.100" }
            ],
           
            "option-data": [
                {
                    "name": "routers",
                    "data": "192.168.200.254"
                },
                {
                    "name": "ntp-servers",
                    "data": "10.220.1.253"
                }
            ],
           
            "relay": {
                        "ip-address": "192.168.200.254"
            }
        }
       
    ],

BR
Stefan
_______________________________________________
ISC funds the development of this software with paid support subscriptions. Contact us at https://www.isc.org/contact/ for more information.

To unsubscribe visit https://lists.isc.org/mailman/listinfo/kea-users.

Kea-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/kea-users
Reply | Threaded
Open this post in threaded view
|

Re: [Kea-users] kea-dhcp4 version1.8 , unable to send response packet

Stefan Berger
>This Setup was working fne under version 1.6 but with 1.8 the server isn't able to send packets back to client.
>
>The log shows that everything is working fine until a response should be sent to client
>": failed to send DHCPv4 packet: Interface tun1/8 does not have any suitable IPv4 sockets open."

Replay to my own message

I have done some strace and it seems the tunnel interface is the problem.

In DHCP4_PACKET_SEND everything looks ok - 172.16.160.248 is the loopback IP on which the request was received and 192.168.168.200.254
is the Interface on the router with the Cisco IP Helper.

DHCP4_RESPONSE_DATA shows the right DHCPOFFER

Then the DHCP4_PACKET_SEND_FAIL Message - tun1 is the interface on which the packet was received.
I think the right way should be sending the packet through the loopback and the linux stack should do the rest.

16:46:02 write(5, "2021-03-26 16:46:02.116 DEBUG [kea-dhcp4.options/13945.140485403977856] DHCP4_PACKET_PACK [hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0x14ea: preparing on-wire format of the packet to be sent\n", 282) = 282 <0.000011>
16:46:02 lseek(5, 0, SEEK_CUR)          = 9600239 <0.000009>
16:46:02 fcntl(4, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0 <0.000010>
16:46:02 fcntl(26, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=1}) = 0 <0.000010>
16:46:02 fcntl(25, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=1}) = 0 <0.000011>
16:46:02 fcntl(4, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0 <0.000010>
16:46:02 lseek(5, 0, SEEK_END)          = 9600239 <0.000010>
16:46:02 lseek(5, 0, SEEK_CUR)          = 9600239 <0.000009>
16:46:02 lseek(5, 0, SEEK_END)          = 9600239 <0.000010>
16:46:02 write(5, "2021-03-26 16:46:02.117 DEBUG [kea-dhcp4.packets/13945.140485403977856] DHCP4_PACKET_SEND [hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0x14ea: trying to send packet DHCPOFFER (type 2) from 172.16.160.248:67 to 192.168.200.254:67 on interface lo\n", 334) = 334 <0.000016>
16:46:02 lseek(5, 0, SEEK_CUR)          = 9600573 <0.000010>
16:46:02 fcntl(4, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0 <0.000010>
16:46:02 fcntl(25, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=1}) = 0 <0.000010>
16:46:02 fcntl(25, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=1}) = 0 <0.000011>
16:46:02 fcntl(4, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0 <0.000010>
16:46:02 lseek(5, 0, SEEK_END)          = 9600573 <0.000010>
16:46:02 lseek(5, 0, SEEK_CUR)          = 9600573 <0.000010>
16:46:02 lseek(5, 0, SEEK_END)          = 9600573 <0.000010>
16:46:02 write(5, "2021-03-26 16:46:02.117 DEBUG [kea-dhcp4.packets/13945.140485403977856] DHCP4_RESPONSE_DATA [hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0x14ea: responding with packet DHCPOFFER (type 2), packet details: local_address=172.16.160.248:67, remote_address=192.168.200.254:67, msg_type=DHCPOFFER (2), transid=0x14ea,\noptions:\n  type=001, len=004: 4294967040 (uint32)\n  type=003, len=004: 192.168.200.254\n  type=006, len=008: 8.8.8.8 9.9.9.9\n  type=012, len=014: \"config-station\" (string)\n  type=051, len=004: 28800 (uint32)\n  type=053, len=001: 2 (uint8)\n  type=054, len=004: 172.16.160.248\n  type=061, len=031: 00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30\n", 802) = 802 <0.000018>
16:46:02 lseek(5, 0, SEEK_CUR)          = 9601375 <0.000010>
16:46:02 fcntl(4, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0 <0.000010>
16:46:02 fcntl(25, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=1}) = 0 <0.000010>
16:46:02 fcntl(25, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=1}) = 0 <0.000010>
16:46:02 fcntl(4, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0 <0.000009>
16:46:02 lseek(5, 0, SEEK_END)          = 9601375 <0.000008>
16:46:02 lseek(5, 0, SEEK_CUR)          = 9601375 <0.000009>
16:46:02 lseek(5, 0, SEEK_END)          = 9601375 <0.000009>
16:46:02 write(5, "2021-03-26 16:46:02.118 ERROR [kea-dhcp4.packets/13945.140485403977856] DHCP4_PACKET_SEND_FAIL [hwtype=1 f4:cf:e2:98:75:e1], cid=[00:63:69:73:63:6f:2d:66:34:63:66:2e:65:32:39:38:2e:37:35:65:31:2d:47:69:30:2f:31:2e:39:30:30], tid=0x14ea: failed to send DHCPv4 packet: Interface tun1/8 does not have any suitable IPv4 sockets open.\n", 330) = 330 <0.000016>
16:46:02 lseek(5, 0, SEEK_CUR)          = 9601705 <0.000009>
16:46:02 fcntl(4, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0 <0.000009>
16:46:02 fcntl(25, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=1}) = 0 <0.000008>

If we change the interface config to
"outbound-interface": "use-routing"
 it's working !

    "interfaces-config": {
        "interfaces": [ "lo/172.16.160.248" ],
        "dhcp-socket-type": "udp",
          "outbound-interface": "use-routing"
        // "outbound-interface": "same-as-inbound"
       // same as inbound is default
    },

This is a work around but it's not so easy for debugging - tracing packets over different interfaces needs much more effort.
We also have to modify the firewalls rules to leave this traffic out which wasn't seen by firewall (was arrived through the gre tunnel)


I have also tried to bind kea-dchp4 directly to the gre tunnel which failed too.
It seems that kea-dhcp4 select the wrong IP address for binding .
It is using the Tunnel PEER_INNER address.
Maybe this is also the reason for the message above (tun1/8 does not have any suitable IPv4 sockets open)

#GRE Tunnel Config
#cat ifcfg-tun1
DEVICE=tun1
BOOTPROTO=none
ONBOOT=yes
TYPE=GRE
PEER_OUTER_IPADDR=172.16.213.253
PEER_INNER_IPADDR=172.16.200.254/24
MY_OUTER_IPADDR=10.214.200.4
MY_INNER_IPADDR=172.16.200.4/24

17:23:15 socket(AF_INET, SOCK_DGRAM, IPPROTO_IP) = 24 <0.000015>
17:23:15 fcntl(24, F_SETFD, FD_CLOEXEC) = 0 <0.000008>
17:23:15 bind(24, {sa_family=AF_INET, sin_port=htons(67), sin_addr=inet_addr("172.16.160.248")}, 16) = 0 <0.000013>
17:23:15 setsockopt(24, SOL_IP, IP_PKTINFO, [1], 4) = 0 <0.000009>
17:23:15 socket(AF_INET, SOCK_DGRAM, IPPROTO_IP) = 25 <0.000011>
17:23:15 fcntl(25, F_SETFD, FD_CLOEXEC) = 0 <0.000008>
17:23:15 bind(25, {sa_family=AF_INET, sin_port=htons(67), sin_addr=inet_addr("172.16.200.254")}, 16) = -1 EADDRNOTAVAIL (Die angeforderte Adresse kann nicht zugewiesen werden) <0.000009>
17:23:15 close(25)                      = 0 <0.000015>
17:23:15 fcntl(8, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=1}) = 0 <0.000012>
17:23:15 fcntl(4, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0 <0.000010>
17:23:15 lseek(5, 0, SEEK_END)          = 9296497 <0.000008>
17:23:15 lseek(5, 0, SEEK_CUR)          = 9296497 <0.000008>
17:23:15 lseek(5, 0, SEEK_END)          = 9296497 <0.000008>
17:23:15 write(5, "2021-03-25 17:23:15.918 WARN  [kea-dhcp4.dhcpsrv/18423.139928109389952] DHCPSRV_OPEN_SOCKET_FAIL failed to open socket: failed to open socket on interface tun1, reason: Failed to bind socket 25 to 172.16.200.254/port=67\n", 220) = 220 <0.000015>
17:23:15 lseek(5, 0, SEEK_CUR)          = 9296717 <0.000008>
17:23:15 fcntl(4, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0 <0.000009>
17:23:15 fcntl(8, F_SETLKW, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=1}) = 0 <0.000009>
17:23:15 fcntl(8, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=1}) = 0 <0.000010>
17:23:15 fcntl(4, F_SETLKW, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0 <0.000009>


_______________________________________________
ISC funds the development of this software with paid support subscriptions. Contact us at https://www.isc.org/contact/ for more information.

To unsubscribe visit https://lists.isc.org/mailman/listinfo/kea-users.

Kea-users mailing list
[hidden email]
https://lists.isc.org/mailman/listinfo/kea-users