HenriWahl / dhcpy6d

MAC address aware DHCPv6 server written in Python
https://dhcpy6d.de
GNU General Public License v2.0
94 stars 27 forks source link

Recent dhcpy6d version causes problems with ISC DHCP client on Debian Bullseye #48

Closed FelixJacobi closed 2 years ago

FelixJacobi commented 2 years ago

I noticed that the ISC DHCP client seems to no longer working since upgrading to the dhcpy6d version from Debian Bullseye. The client uses the ISC DHCP client and is also on a Debian Bullseye. A Debian Buster system is also affected.

The ISC DHCP client is hanging in an infinity loop when tryring to receive an IP address:

backup2.stsbl.de ~ # ifdown eth0; ifup eth0
Internet Systems Consortium DHCP Client 4.4.1
Copyright 2004-2018 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/

no link-local IPv6 address for eth0

If you think you have received this message due to a bug rather
than a configuration issue please read the section on submitting
bugs on either our web page at www.isc.org or in the README file
before submitting a bug.  These pages explain the proper
process and the information we find helpful for debugging.

exiting.
Internet Systems Consortium DHCP Client 4.4.1
Copyright 2004-2018 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/

Listening on Socket/eth0
Sending on   Socket/eth0
PRC: Previous lease is devoid of active addresses.
PRC: Soliciting for leases (INIT).
XMT: Forming Solicit, 0 ms elapsed.
XMT:  X-- IA_NA 5d:eb:87:04
XMT:  | X-- Request renew in  +3600
XMT:  | X-- Request rebind in +5400
XMT: Solicit on eth0, interval 1050ms.
RCV: Advertise message on eth0 from fe80::1.
RCV:  X-- Preference 255.
RCV:  X-- IA_NA 5d:eb:87:04
RCV:  | X-- starts 1633047764
RCV:  | X-- t1 - renew  +2700
RCV:  | X-- t2 - rebind +4050
RCV:  | X-- [Options]
RCV:  | | X-- IAADDR fda9:b38a:2445:1001::3
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR 2001:470:539f:1001::3
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR fda9:b38a:2445:1001:215:5dff:feeb:8704
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR 2001:470:539f:1001:215:5dff:feeb:8704
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR fe80::3
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR fe80::215:5dff:feeb:8704
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR 2001:470:539f:1001:215:5dff:feeb:8704
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR fda9:b38a:2445:1001:215:5dff:feeb:8704
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  X-- Server ID: 00:01:00:01:5c:00:99:36:60:a4:4c:25:e3:e6
RCV:  Advertisement immediately selected.
PRC: Selecting best advertised lease.
PRC: Considering best lease.
PRC:  X-- Initial candidate 00:01:00:01:5c:00:99:36:60:a4:4c:25:e3:e6 (s: 10805, p: 255).
XMT: Forming Request, 0 ms elapsed.
XMT:  X-- IA_NA 5d:eb:87:04
XMT:  | X-- Requested renew  +3600
XMT:  | X-- Requested rebind +5400
XMT:  | | X-- IAADDR fda9:b38a:2445:1001::3
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR 2001:470:539f:1001::3
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR fda9:b38a:2445:1001:215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR 2001:470:539f:1001:215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR fe80::3
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR fe80::215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR 2001:470:539f:1001:215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR fda9:b38a:2445:1001:215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR 2001:470:539f:1001:215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR fe80::3
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR fe80::215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR 2001:470:539f:1001:215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR fda9:b38a:2445:1001:215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  V IA_NA appended.
XMT: Request on eth0, interval 1040ms.
RCV: Reply message on eth0 from fe80::1.
RCV:  X-- Preference 255.
RCV:  X-- Server ID: 00:01:00:01:5c:00:99:36:60:a4:4c:25:e3:e6
PRC: Soliciting for leases (INIT).
XMT: Forming Solicit, 0 ms elapsed.
XMT:  X-- IA_NA 5d:eb:87:04
XMT:  | X-- Request renew in  +3600
XMT:  | X-- Request rebind in +5400
XMT: Solicit on eth0, interval 1040ms.
RCV: Advertise message on eth0 from fe80::1.
RCV:  X-- Preference 255.
RCV:  X-- IA_NA 5d:eb:87:04
RCV:  | X-- starts 1633047765
RCV:  | X-- t1 - renew  +2700
RCV:  | X-- t2 - rebind +4050
RCV:  | X-- [Options]
RCV:  | | X-- IAADDR fda9:b38a:2445:1001::3
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR 2001:470:539f:1001::3
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR fda9:b38a:2445:1001:215:5dff:feeb:8704
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR 2001:470:539f:1001:215:5dff:feeb:8704
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR fe80::3
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR fe80::215:5dff:feeb:8704
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR 2001:470:539f:1001:215:5dff:feeb:8704
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  | | X-- IAADDR fda9:b38a:2445:1001:215:5dff:feeb:8704
RCV:  | | | X-- Preferred lifetime 5400.
RCV:  | | | X-- Max lifetime 7200.
RCV:  X-- Server ID: 00:01:00:01:5c:00:99:36:60:a4:4c:25:e3:e6
RCV:  Advertisement immediately selected.
PRC: Selecting best advertised lease.
PRC: Considering best lease.
PRC:  X-- Initial candidate 00:01:00:01:5c:00:99:36:60:a4:4c:25:e3:e6 (s: 10805, p: 255).
XMT: Forming Request, 0 ms elapsed.
XMT:  X-- IA_NA 5d:eb:87:04
XMT:  | X-- Requested renew  +3600
XMT:  | X-- Requested rebind +5400
XMT:  | | X-- IAADDR fda9:b38a:2445:1001::3
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR 2001:470:539f:1001::3
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR fda9:b38a:2445:1001:215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR 2001:470:539f:1001:215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR fe80::3
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR fe80::215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR 2001:470:539f:1001:215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  | | X-- IAADDR fda9:b38a:2445:1001:215:5dff:feeb:8704
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  V IA_NA appended.
XMT: Request on eth0, interval 1000ms.
RCV: Reply message on eth0 from fe80::1.
RCV:  X-- Preference 255.
RCV:  X-- Server ID: 00:01:00:01:5c:00:99:36:60:a4:4c:25:e3:e6
PRC: Soliciting for leases (INIT).
XMT: Forming Solicit, 0 ms elapsed.
XMT:  X-- IA_NA 5d:eb:87:04
XMT:  | X-- Request renew in  +3600
XMT:  | X-- Request rebind in +5400
XMT: Solicit on eth0, interval 1010ms.

The interface was configured using ifupdown in /etc/network/interfaces:

auto eth0
iface eth0 inet6 auto

In the log of dhcpy6d you can see that client is sending SOLICTs and dhcpy6d replies as expected:

2021-10-01 02:22:55,699 dhcpy6d INFO REQUEST | transaction: 3e817e | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 False | answer: normal | client_llip: fe80:0000:0000:0000:0215:5dff:feeb:8704 | counter: 1 | duid: 00010001252ba33000155deb8704 | ia_options: [3] | iaid: 5deb8704 | interface: br_server | last_message_received_type: 3 | mac: 00:15:5d:eb:87:04 | options_request: [23, 24, 39, 31]
2021-10-01 02:22:55,701 dhcpy6d INFO REPLY | transaction: 3e817e | options: [7, 13, 23, 24, 31, 39]  | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 False 2001:0470:539f:1001:0215:5dff:feeb:8704 fda9:b38a:2445:1001:0215:5dff:feeb:8704 | client_class: default_br_server | hostname: backup2
2021-10-01 02:22:56,147 dhcpy6d INFO SOLICIT | transaction: 5fbb4a | answer: normal | client_llip: fe80:0000:0000:0000:0215:5dff:feeb:8704 | counter: 1 | duid: 00010001252ba33000155deb8704 | ia_options: [3] | iaid: 5deb8704 | interface: br_server | last_message_received_type: 1 | mac: 00:15:5d:eb:87:04 | options_request: [23, 24, 39, 31]
2021-10-01 02:22:56,148 dhcpy6d INFO ADVERTISE | transaction: 5fbb4a | options: [3, 7, 23, 24, 31, 39]  | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:ed21:0972:6ed2:09d7 fda9:b38a:2445:1001:a91d:b547:c09f:06b0 | client_class: default_br_server | hostname: backup2
2021-10-01 02:22:56,161 dhcpy6d INFO REQUEST | transaction: b81330 | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 False | answer: normal | client_llip: fe80:0000:0000:0000:0215:5dff:feeb:8704 | counter: 1 | duid: 00010001252ba33000155deb8704 | ia_options: [3] | iaid: 5deb8704 | interface: br_server | last_message_received_type: 3 | mac: 00:15:5d:eb:87:04 | options_request: [23, 24, 39, 31]
2021-10-01 02:22:56,162 dhcpy6d INFO REPLY | transaction: b81330 | options: [7, 13, 23, 24, 31, 39]  | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 False 2001:0470:539f:1001:0215:5dff:feeb:8704 fda9:b38a:2445:1001:0215:5dff:feeb:8704 | client_class: default_br_server | hostname: backup2
2021-10-01 02:22:56,489 dhcpy6d INFO SOLICIT | transaction: 9a2b2a | answer: normal | client_llip: fe80:0000:0000:0000:0215:5dff:feeb:8704 | counter: 1 | duid: 00010001252ba33000155deb8704 | ia_options: [3] | iaid: 5deb8704 | interface: br_server | last_message_received_type: 1 | mac: 00:15:5d:eb:87:04 | options_request: [23, 24, 39, 31]
2021-10-01 02:22:56,490 dhcpy6d INFO ADVERTISE | transaction: 9a2b2a | options: [3, 7, 23, 24, 31, 39]  | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:ed21:0972:6ed2:09d7 fda9:b38a:2445:1001:a91d:b547:c09f:06b0 | client_class: default_br_server | hostname: backup2
2021-10-01 02:22:56,504 dhcpy6d INFO REQUEST | transaction: c5e9f1 | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 False | answer: normal | client_llip: fe80:0000:0000:0000:0215:5dff:feeb:8704 | counter: 1 | duid: 00010001252ba33000155deb8704 | ia_options: [3] | iaid: 5deb8704 | interface: br_server | last_message_received_type: 3 | mac: 00:15:5d:eb:87:04 | options_request: [23, 24, 39, 31]
2021-10-01 02:22:56,505 dhcpy6d INFO REPLY | transaction: c5e9f1 | options: [7, 13, 23, 24, 31, 39]  | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 False 2001:0470:539f:1001:0215:5dff:feeb:8704 fda9:b38a:2445:1001:0215:5dff:feeb:8704 | client_class: default_br_server | hostname: backup2
--
2021-10-01 02:22:57,291 dhcpy6d INFO SOLICIT | transaction: 6358a0 | answer: normal | client_llip: fe80:0000:0000:0000:0215:5dff:feeb:8704 | counter: 1 | duid: 00010001252ba33000155deb8704 | ia_options: [3] | iaid: 5deb8704 | interface: br_server | last_message_received_type: 1 | mac: 00:15:5d:eb:87:04 | options_request: [23, 24, 39, 31]
2021-10-01 02:22:57,292 dhcpy6d INFO ADVERTISE | transaction: 6358a0 | options: [3, 7, 23, 24, 31, 39]  | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:ed21:0972:6ed2:09d7 fda9:b38a:2445:1001:a91d:b547:c09f:06b0 | client_class: default_br_server | hostname: backup2
2021-10-01 02:22:57,305 dhcpy6d INFO REQUEST | transaction: 57cea1 | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 False | answer: normal | client_llip: fe80:0000:0000:0000:0215:5dff:feeb:8704 | counter: 1 | duid: 00010001252ba33000155deb8704 | ia_options: [3] | iaid: 5deb8704 | interface: br_server | last_message_received_type: 3 | mac: 00:15:5d:eb:87:04 | options_request: [23, 24, 39, 31]
2021-10-01 02:22:57,306 dhcpy6d INFO REPLY | transaction: 57cea1 | options: [7, 13, 23, 24, 31, 39]  | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 False 2001:0470:539f:1001:0215:5dff:feeb:8704 fda9:b38a:2445:1001:0215:5dff:feeb:8704 | client_class: default_br_server | hostname: backup2
2021-10-01 02:22:58,003 dhcpy6d INFO SOLICIT | transaction: 8cdf40 | answer: normal | client_llip: fe80:0000:0000:0000:0215:5dff:feeb:8704 | counter: 1 | duid: 00010001252ba33000155deb8704 | ia_options: [3] | iaid: 5deb8704 | interface: br_server | last_message_received_type: 1 | mac: 00:15:5d:eb:87:04 | options_request: [23, 24, 39, 31]
2021-10-01 02:22:58,004 dhcpy6d INFO ADVERTISE | transaction: 8cdf40 | options: [3, 7, 23, 24, 31, 39]  | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:ed21:0972:6ed2:09d7 fda9:b38a:2445:1001:a91d:b547:c09f:06b0 | client_class: default_br_server | hostname: backup2
2021-10-01 02:22:58,017 dhcpy6d INFO REQUEST | transaction: 4606c8 | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 False | answer: normal | client_llip: fe80:0000:0000:0000:0215:5dff:feeb:8704 | counter: 1 | duid: 00010001252ba33000155deb8704 | ia_options: [3] | iaid: 5deb8704 | interface: br_server | last_message_received_type: 3 | mac: 00:15:5d:eb:87:04 | options_request: [23, 24, 39, 31]
2021-10-01 02:22:58,018 dhcpy6d INFO REPLY | transaction: 4606c8 | options: [7, 13, 23, 24, 31, 39]  | addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 False 2001:0470:539f:1001:0215:5dff:feeb:8704 fda9:b38a:2445:1001:0215:5dff:feeb:8704 | client_class: default_br_server | hostname: backup2

From time to times also the following message is printed repeatly in the log:

Okt 01 02:38:11 iserv.stsbl.de dhcpy6d[28818]: Uncolonifyable address:
Okt 01 02:38:11 iserv.stsbl.de dhcpy6d[28818]: Uncolonifyable address:
Okt 01 02:38:11 iserv.stsbl.de dhcpy6d[28818]: Uncolonifyable address:

I am not really sure where to start debugging.

HenriWahl commented 2 years ago

Is the bunch of addresses intended or already part of the problem?

FelixJacobi commented 2 years ago

Is the bunch of addresses intended or already part of the problem?

If you mean the link-local addresses: There were contained in the address list by accident, yes (bug in my script generating the configuration file). I also was start to suspecting them being the cause, but removing them from the address list does not change anything. The rest of the addresses should be assigned to the client, that's correct.

The dhcpy6d.conf:

# dhcpy6d configuration for IServ
#
# This file is generated automatically by iservchk.
# It is not recommended to make any changes to this file.
# If really necessary you can save changes permanently using:
#   iconf save /etc/dhcpy6d.conf

# dhcpy6d default configuration
#
# Please see the examples in /usr/share/doc/dhcpy6d and 
# https://dhcpy6d.ifw-dresden.de/documentation for more information.

[dhcpy6d]
# Interface to listen to multicast ff02::1:2.
interface = br_admin br_beamer br_byod_student br_byod_teacher br_dmz br_fallback br_lan br_printer br_server 
# Identify and configure clients via clients.conf.
store_config = file
# SQLite DB for leases and LLIP-MAC-mapping.
store_volatile = sqlite
store_sqlite_volatile = /var/lib/dhcpy6d/volatile.sqlite
log = on
log_file = /var/log/dhcpy6d.log
domain = i.local
domain_search_list = stsbl.de
log_console = yes
identification = mac
# set to yes to really answer to clients
# not necessary in Debian where it comes from /etc/default/dhcpy6d and /etc/init.d/dhcpy6
#really_do_it = no

store_file_config = /var/lib/iserv/ipv6-support/dhcpy6d/clients.conf

[class_default_br_admin]
bootfiles = br_admin_ipxe br_admin_efi64 br_admin_efi32 br_admin_efibc
addresses = br_admin_0 br_admin_1 temp_br_admin_0 temp_br_admin_1
interface = br_admin
nameserver = fd00::53
ntp_server = 2001:470:539f:1004::1 2001:470:539f:1004:d65d:64ff:febc:ba1f fda9:b38a:2445:1004::1 fda9:b38a:2445:1004:d65d:64ff:febc:ba1f
filter_mac = .*

[address_br_admin_0]
# Choosing EUI-64-based addresses.
category = eui64
pattern = 2001:470:539f:1004::$eui64$
ia_type = na

[address_temp_br_admin_0]
# Choosing random addresses.
category = random
pattern = 2001:470:539f:1004::$random64$
ia_type = ta

[address_br_admin_1]
# Choosing EUI-64-based addresses.
category = eui64
pattern = fda9:b38a:2445:1004::$eui64$
ia_type = na

[address_temp_br_admin_1]
# Choosing random addresses.
category = random
pattern = fda9:b38a:2445:1004::$random64$
ia_type = ta

[class_default_br_beamer]
bootfiles = br_beamer_ipxe br_beamer_efi64 br_beamer_efi32 br_beamer_efibc
addresses = br_beamer_0 br_beamer_1 temp_br_beamer_0 temp_br_beamer_1
interface = br_beamer
nameserver = fd00::53
ntp_server = 2001:470:539f:1002::1 2001:470:539f:1002:d65d:64ff:febc:ba1f fda9:b38a:2445:1002::1 fda9:b38a:2445:1002:d65d:64ff:febc:ba1f
filter_mac = .*

[address_br_beamer_0]
# Choosing EUI-64-based addresses.
category = eui64
pattern = 2001:470:539f:1002::$eui64$
ia_type = na

[address_temp_br_beamer_0]
# Choosing random addresses.
category = random
pattern = 2001:470:539f:1002::$random64$
ia_type = ta

[address_br_beamer_1]
# Choosing EUI-64-based addresses.
category = eui64
pattern = fda9:b38a:2445:1002::$eui64$
ia_type = na

[address_temp_br_beamer_1]
# Choosing random addresses.
category = random
pattern = fda9:b38a:2445:1002::$random64$
ia_type = ta

[class_default_br_byod_student]
bootfiles = br_byod_student_ipxe br_byod_student_efi64 br_byod_student_efi32 br_byod_student_efibc
addresses = br_byod_student_0 br_byod_student_1 temp_br_byod_student_0 temp_br_byod_student_1
interface = br_byod_student
nameserver = fd00::53
ntp_server = 2001:470:539f:1011::1 2001:470:539f:1011:d65d:64ff:febc:ba1f fda9:b38a:2445:1011::1 fda9:b38a:2445:1011:d65d:64ff:febc:ba1f
filter_mac = .*

[address_br_byod_student_0]
# Choosing EUI-64-based addresses.
category = eui64
pattern = 2001:470:539f:1011::$eui64$
ia_type = na

[address_temp_br_byod_student_0]
# Choosing random addresses.
category = random
pattern = 2001:470:539f:1011::$random64$
ia_type = ta

[address_br_byod_student_1]
# Choosing EUI-64-based addresses.
category = eui64
pattern = fda9:b38a:2445:1011::$eui64$
ia_type = na

[address_temp_br_byod_student_1]
# Choosing random addresses.
category = random
pattern = fda9:b38a:2445:1011::$random64$
ia_type = ta

[class_default_br_byod_teacher]
bootfiles = br_byod_teacher_ipxe br_byod_teacher_efi64 br_byod_teacher_efi32 br_byod_teacher_efibc
addresses = br_byod_teacher_0 br_byod_teacher_1 temp_br_byod_teacher_0 temp_br_byod_teacher_1
interface = br_byod_teacher
nameserver = fd00::53
ntp_server = 2001:470:539f:1010::1 2001:470:539f:1010:d65d:64ff:febc:ba1f fda9:b38a:2445:1010::1 fda9:b38a:2445:1010:d65d:64ff:febc:ba1f
filter_mac = .*

[address_br_byod_teacher_0]
# Choosing EUI-64-based addresses.
category = eui64
pattern = 2001:470:539f:1010::$eui64$
ia_type = na

[address_temp_br_byod_teacher_0]
# Choosing random addresses.
category = random
pattern = 2001:470:539f:1010::$random64$
ia_type = ta

[address_br_byod_teacher_1]
# Choosing EUI-64-based addresses.
category = eui64
pattern = fda9:b38a:2445:1010::$eui64$
ia_type = na

[address_temp_br_byod_teacher_1]
# Choosing random addresses.
category = random
pattern = fda9:b38a:2445:1010::$random64$
ia_type = ta

[class_default_br_dmz]
bootfiles = br_dmz_ipxe br_dmz_efi64 br_dmz_efi32 br_dmz_efibc
addresses = br_dmz_0 br_dmz_1 temp_br_dmz_0 temp_br_dmz_1
interface = br_dmz
ntp_server = 2001:470:539f:0:d65d:64ff:febc:ba20 fda9:b38a:2445:0:d65d:64ff:febc:ba20
filter_mac = .*

[address_br_dmz_0]
# Choosing EUI-64-based addresses.
category = eui64
pattern = 2001:470:539f::$eui64$
ia_type = na

[address_temp_br_dmz_0]
# Choosing random addresses.
category = random
pattern = 2001:470:539f::$random64$
ia_type = ta

[address_br_dmz_1]
# Choosing EUI-64-based addresses.
category = eui64
pattern = fda9:b38a:2445::$eui64$
ia_type = na

[address_temp_br_dmz_1]
# Choosing random addresses.
category = random
pattern = fda9:b38a:2445::$random64$
ia_type = ta

[class_default_br_fallback]
bootfiles = br_fallback_ipxe br_fallback_efi64 br_fallback_efi32 br_fallback_efibc
addresses = br_fallback_0 br_fallback_1 temp_br_fallback_0 temp_br_fallback_1
interface = br_fallback
nameserver = fd00::53
ntp_server = 2001:470:539f:1020::1 2001:470:539f:1020:d65d:64ff:febc:ba1f fda9:b38a:2445:1020::1 fda9:b38a:2445:1020:d65d:64ff:febc:ba1f
filter_mac = .*

[address_br_fallback_0]
# Choosing EUI-64-based addresses.
category = eui64
pattern = 2001:470:539f:1020::$eui64$
ia_type = na

[address_temp_br_fallback_0]
# Choosing random addresses.
category = random
pattern = 2001:470:539f:1020::$random64$
ia_type = ta

[address_br_fallback_1]
# Choosing EUI-64-based addresses.
category = eui64
pattern = fda9:b38a:2445:1020::$eui64$
ia_type = na

[address_temp_br_fallback_1]
# Choosing random addresses.
category = random
pattern = fda9:b38a:2445:1020::$random64$
ia_type = ta

[class_default_br_lan]
bootfiles = br_lan_ipxe br_lan_efi64 br_lan_efi32 br_lan_efibc
addresses = br_lan_0 br_lan_1 temp_br_lan_0 temp_br_lan_1
interface = br_lan
nameserver = fd00::53
ntp_server = 2001:470:539f:1000::1 2001:470:539f:1000:d65d:64ff:febc:ba1f fda9:b38a:2445:1000::1 fda9:b38a:2445:1000:d65d:64ff:febc:ba1f
filter_mac = .*

[address_br_lan_0]
# Choosing EUI-64-based addresses.
category = eui64
pattern = 2001:470:539f:1000::$eui64$
ia_type = na

[address_temp_br_lan_0]
# Choosing random addresses.
category = random
pattern = 2001:470:539f:1000::$random64$
ia_type = ta

[address_br_lan_1]
# Choosing EUI-64-based addresses.
category = eui64
pattern = fda9:b38a:2445:1000::$eui64$
ia_type = na

[address_temp_br_lan_1]
# Choosing random addresses.
category = random
pattern = fda9:b38a:2445:1000::$random64$
ia_type = ta

[class_default_br_printer]
bootfiles = br_printer_ipxe br_printer_efi64 br_printer_efi32 br_printer_efibc
addresses = br_printer_0 br_printer_1 temp_br_printer_0 temp_br_printer_1
interface = br_printer
nameserver = fd00::53
ntp_server = 2001:470:539f:1003::1 2001:470:539f:1003:d65d:64ff:febc:ba1f fda9:b38a:2445:1003::1 fda9:b38a:2445:1003:d65d:64ff:febc:ba1f
filter_mac = .*

[address_br_printer_0]
# Choosing EUI-64-based addresses.
category = eui64
pattern = 2001:470:539f:1003::$eui64$
ia_type = na

[address_temp_br_printer_0]
# Choosing random addresses.
category = random
pattern = 2001:470:539f:1003::$random64$
ia_type = ta

[address_br_printer_1]
# Choosing EUI-64-based addresses.
category = eui64
pattern = fda9:b38a:2445:1003::$eui64$
ia_type = na

[address_temp_br_printer_1]
# Choosing random addresses.
category = random
pattern = fda9:b38a:2445:1003::$random64$
ia_type = ta

[class_default_br_server]
bootfiles = br_server_ipxe br_server_efi64 br_server_efi32 br_server_efibc
addresses = br_server_0 br_server_1 temp_br_server_0 temp_br_server_1
interface = br_server
nameserver = fd00::53
ntp_server = 2001:470:539f:1001::1 2001:470:539f:1001:d65d:64ff:febc:ba1f fda9:b38a:2445:1001::1 fda9:b38a:2445:1001:d65d:64ff:febc:ba1f
filter_mac = .*

[address_br_server_0]
# Choosing EUI-64-based addresses.
category = eui64
pattern = 2001:470:539f:1001::$eui64$
ia_type = na

[address_temp_br_server_0]
# Choosing random addresses.
category = random
pattern = 2001:470:539f:1001::$random64$
ia_type = ta

[address_br_server_1]
# Choosing EUI-64-based addresses.
category = eui64
pattern = fda9:b38a:2445:1001::$eui64$
ia_type = na

[address_temp_br_server_1]
# Choosing random addresses.
category = random
pattern = fda9:b38a:2445:1001::$random64$
ia_type = ta

[address_fixed]
category = fixed

[bootfile_br_admin_ipxe]
user_class = iPXE
bootfile_url = tftp://[fda9:b38a:2445:1004::1]/default.ipxe

[bootfile_br_admin_efi32]
client_architecture = 0006
bootfile_url = tftp://[fda9:b38a:2445:1004::1]/efi32/ipxe-snponly.efi

[bootfile_br_admin_efibc]
client_architecture = 0007
bootfile_url = tftp://[fda9:b38a:2445:1004::1]/efi64/ipxe-snponly.efi

[bootfile_br_admin_efi64]
client_architecture = 0009
bootfile_url = tftp://[fda9:b38a:2445:1004::1]/efi32/ipxe-snponly.efi

[bootfile_br_beamer_ipxe]
user_class = iPXE
bootfile_url = tftp://[fda9:b38a:2445:1002::1]/default.ipxe

[bootfile_br_beamer_efi32]
client_architecture = 0006
bootfile_url = tftp://[fda9:b38a:2445:1002::1]/efi32/ipxe-snponly.efi

[bootfile_br_beamer_efibc]
client_architecture = 0007
bootfile_url = tftp://[fda9:b38a:2445:1002::1]/efi64/ipxe-snponly.efi

[bootfile_br_beamer_efi64]
client_architecture = 0009
bootfile_url = tftp://[fda9:b38a:2445:1002::1]/efi32/ipxe-snponly.efi

[bootfile_br_byod_student_ipxe]
user_class = iPXE
bootfile_url = tftp://[fda9:b38a:2445:1011::1]/default.ipxe

[bootfile_br_byod_student_efi32]
client_architecture = 0006
bootfile_url = tftp://[fda9:b38a:2445:1011::1]/efi32/ipxe-snponly.efi

[bootfile_br_byod_student_efibc]
client_architecture = 0007
bootfile_url = tftp://[fda9:b38a:2445:1011::1]/efi64/ipxe-snponly.efi

[bootfile_br_byod_student_efi64]
client_architecture = 0009
bootfile_url = tftp://[fda9:b38a:2445:1011::1]/efi32/ipxe-snponly.efi

[bootfile_br_byod_teacher_ipxe]
user_class = iPXE
bootfile_url = tftp://[fda9:b38a:2445:1010::1]/default.ipxe

[bootfile_br_byod_teacher_efi32]
client_architecture = 0006
bootfile_url = tftp://[fda9:b38a:2445:1010::1]/efi32/ipxe-snponly.efi

[bootfile_br_byod_teacher_efibc]
client_architecture = 0007
bootfile_url = tftp://[fda9:b38a:2445:1010::1]/efi64/ipxe-snponly.efi

[bootfile_br_byod_teacher_efi64]
client_architecture = 0009
bootfile_url = tftp://[fda9:b38a:2445:1010::1]/efi32/ipxe-snponly.efi

[bootfile_br_dmz_ipxe]
user_class = iPXE
bootfile_url = tftp://[fda9:b38a:2445:0:d65d:64ff:febc:ba20]/default.ipxe

[bootfile_br_dmz_efi32]
client_architecture = 0006
bootfile_url = tftp://[fda9:b38a:2445:0:d65d:64ff:febc:ba20]/efi32/ipxe-snponly.efi

[bootfile_br_dmz_efibc]
client_architecture = 0007
bootfile_url = tftp://[fda9:b38a:2445:0:d65d:64ff:febc:ba20]/efi64/ipxe-snponly.efi

[bootfile_br_dmz_efi64]
client_architecture = 0009
bootfile_url = tftp://[fda9:b38a:2445:0:d65d:64ff:febc:ba20]/efi32/ipxe-snponly.efi

[bootfile_br_fallback_ipxe]
user_class = iPXE
bootfile_url = tftp://[fda9:b38a:2445:1020::1]/default.ipxe

[bootfile_br_fallback_efi32]
client_architecture = 0006
bootfile_url = tftp://[fda9:b38a:2445:1020::1]/efi32/ipxe-snponly.efi

[bootfile_br_fallback_efibc]
client_architecture = 0007
bootfile_url = tftp://[fda9:b38a:2445:1020::1]/efi64/ipxe-snponly.efi

[bootfile_br_fallback_efi64]
client_architecture = 0009
bootfile_url = tftp://[fda9:b38a:2445:1020::1]/efi32/ipxe-snponly.efi

[bootfile_br_lan_ipxe]
user_class = iPXE
bootfile_url = tftp://[fda9:b38a:2445:1000::1]/default.ipxe

[bootfile_br_lan_efi32]
client_architecture = 0006
bootfile_url = tftp://[fda9:b38a:2445:1000::1]/efi32/ipxe-snponly.efi

[bootfile_br_lan_efibc]
client_architecture = 0007
bootfile_url = tftp://[fda9:b38a:2445:1000::1]/efi64/ipxe-snponly.efi

[bootfile_br_lan_efi64]
client_architecture = 0009
bootfile_url = tftp://[fda9:b38a:2445:1000::1]/efi32/ipxe-snponly.efi

[bootfile_br_printer_ipxe]
user_class = iPXE
bootfile_url = tftp://[fda9:b38a:2445:1003::1]/default.ipxe

[bootfile_br_printer_efi32]
client_architecture = 0006
bootfile_url = tftp://[fda9:b38a:2445:1003::1]/efi32/ipxe-snponly.efi

[bootfile_br_printer_efibc]
client_architecture = 0007
bootfile_url = tftp://[fda9:b38a:2445:1003::1]/efi64/ipxe-snponly.efi

[bootfile_br_printer_efi64]
client_architecture = 0009
bootfile_url = tftp://[fda9:b38a:2445:1003::1]/efi32/ipxe-snponly.efi

[bootfile_br_server_ipxe]
user_class = iPXE
bootfile_url = tftp://[fda9:b38a:2445:1001::1]/default.ipxe

[bootfile_br_server_efi32]
client_architecture = 0006
bootfile_url = tftp://[fda9:b38a:2445:1001::1]/efi32/ipxe-snponly.efi

[bootfile_br_server_efibc]
client_architecture = 0007
bootfile_url = tftp://[fda9:b38a:2445:1001::1]/efi64/ipxe-snponly.efi

[bootfile_br_server_efi64]
client_architecture = 0009
bootfile_url = tftp://[fda9:b38a:2445:1001::1]/efi32/ipxe-snponly.efi

clients.conf:

[backup2]
address = fda9:b38a:2445:1001::3 2001:470:539f:1001::3 fda9:b38a:2445:1001:215:5dff:feeb:8704 2001:470:539f:1001:215:5dff:feeb:8704
class = default_br_server
hostname = backup2
mac = 00:15:5d:eb:87:04

[rdns]
address = 2001:470:539f::3 fda9:b38a:2445::3 2001:470:539f:0:215:5dff:feeb:8705 fda9:b38a:2445:0:215:5dff:feeb:8705
class = default_br_dmz
hostname = rdns
mac = 00:15:5d:eb:87:05

[repository]
address = 2001:470:539f::4 fda9:b38a:2445::4 2001:470:539f:0:215:5dff:feeb:8711 fda9:b38a:2445:0:215:5dff:feeb:8711
class = default_br_dmz
hostname = repository
mac = 00:15:5d:eb:87:11

[backup]
address = fda9:b38a:2445:1001::2 2001:470:539f:1001::2 fda9:b38a:2445:1001:6d4:c4ff:fef3:3a45 2001:470:539f:1001:6d4:c4ff:fef3:3a45
class = default_br_server
hostname = backup
mac = 04:d4:c4:f3:3a:45

[vm-server-serverview]
address = fda9:b38a:2445:1001::41 2001:470:539f:1001::41 fda9:b38a:2445:1001:921b:eff:fea6:4b55 2001:470:539f:1001:921b:eff:fea6:4b55
class = default_br_server
hostname = vm-server-serverview
mac = 90:1b:0e:a6:4b:55

[vm-server]
address = fda9:b38a:2445:1001::4 2001:470:539f:1001::4 fda9:b38a:2445:1001:921b:eff:feac:c691 2001:470:539f:1001:921b:eff:feac:c691
class = default_br_server
hostname = vm-server
mac = 90:1b:0e:ac:c6:91

Probably the configuration is bit too funky. I have a second dhcpy6d instance not upgraded yet which have a simpler configuration. I will upgrade it and check, if it is also affected by that problem.

HenriWahl commented 2 years ago

Can you capture the communication with Wireshark/tcpdump?

FelixJacobi commented 2 years ago

Sure, will try it this weekend.

HenriWahl commented 2 years ago

According to your log file the client changes its transaction id with every request - thus the server internally starts a new transaction.

Actually the transaction id must not change during a transaction.

HenriWahl commented 2 years ago

I tested with 2 VMs, one working as client and one as server, both with Debian 11. Both worked like this: grafik grafik If looking closer I see the client is also changing its transaction id, whis might in this case lead to no problem because it is getting a default address anyway - which occurs like a bug in dhcpy6d. But in general this client behaviour is pretty strange, making no sense and violates the DHCPv6 protocol. Maybe testing with another, non-ISC client, will bring the desired result? For instance systemd-networkd might be an option worth investigating.

FelixJacobi commented 2 years ago

Can you capture the communication with Wireshark/tcpdump?

Sent via email directly.

FelixJacobi commented 2 years ago

Probably the configuration is bit too funky. I have a second dhcpy6d instance not upgraded yet which have a simpler configuration. I will upgrade it and check, if it is also affected by that problem.

The second instance was also upgraded today and worked before, but is also affected now.

FelixJacobi commented 2 years ago

addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 False

Looking again on the addresses: The False looks suspicious to me. Is this intended?

FelixJacobi commented 2 years ago

addresses: fda9:b38a:2445:1001:0000:0000:0000:0003 2001:0470:539f:1001:0000:0000:0000:0003 fda9:b38a:2445:1001:0215:5dff:feeb:8704 2001:0470:539f:1001:0215:5dff:feeb:8704 fe80:0000:0000:0000:0000:0000:0000:0003 fe80:0000:0000:0000:0215:5dff:feeb:8704 False

Looking again on the addresses: The False looks suspicious to me. Is this intended?

20010470539f00000000000000000004
fda9b38a244500000000000000000004

fda9b38a2445000002155dfffeeb8711
20010470539f000002155dfffeeb8711
Uncolonifyable address: 
Uncolonifyable address: 
2021-10-04 21:41:52,297 dhcpy6d INFO REPLY | transaction: 02e24d | options: [7, 13, 23, 24, 31, 39]  | addresses: 2001:0470:539f:0000:0000:0000:0000:0004 fda9:b38a:2445:0000:0000:0000:0000:0004 False fda9:b38a:2445:0000:0215:5dff:feeb:8711 2001:0470:539f:0000:0215:5dff:feeb:8711 | client_class: default_eth2 | hostname: repository

I added the following statement in https://github.com/HenriWahl/dhcpy6d/blob/1561a64e108104beb967907c54137ce8ce109fa6/dhcpy6d/options/option_3.py#L65:

                            for address in transaction.client.addresses:
                              print(address.ADDRESS)

As you can see there is an empty element in transaction.client.addresses. This also seems to cause the Uncolonifyable address:. Not sure yet from where it comes. It probably breaks the reply?

FelixJacobi commented 2 years ago

I added a workaround in the mentioned for loop which skips when address.ADDRESS ist empty. The issue seems to be gone now. I guess we now need to figure out why an empty element is added there and how to fix the root of this issue,

HenriWahl commented 2 years ago

Great investigations! False ist of course not colonyfiable. Maybe some of the configured addresses in dhcpy6d-clients.conf are not valid?

HenriWahl commented 2 years ago

Can you please show me your changes?

FelixJacobi commented 2 years ago

Sure:

--- /usr/lib/python3/dist-packages/dhcpy6d/options/option_3.py  2021-09-23 21:00:00.000000000 +0200
+++ /usr/lib/python3/dist-packages/dhcpy6d/options/option_3.py  2021-10-04 22:11:16.640443496 +0200
@@ -63,6 +63,9 @@
                         ia_addresses = ''
                         try:
                             for address in transaction.client.addresses:
+                                if address.ADDRESS == '':
+                                    continue
+
                                 if address.IA_TYPE == 'na':
                                     ipv6_address = hexlify(inet_pton(AF_INET6, colonify_ip6(address.ADDRESS))).decode()
                                     # if a transaction consists of too many requests from client -

But I would only consider them as a preliminary fix as this adds a workaround for empty elements in addresses array but does not fix the origin where the empty addresses are inserted.

HenriWahl commented 2 years ago

Yes. I am about to check a test setup with your supplied config and hope to find the real root cause.

HenriWahl commented 2 years ago

Fixed with latest commit