dhcp 4.2.0 -> dhclient -6 -P ppp0

Thu Sep 2 16:26:46 UTC 2010

David,

On 2010-09-01 22:46, David W. Hankins wrote:
> On Wed, Sep 01, 2010 at 03:26:38PM +0200, Udo van den Heuvel wrote:
>> How would I find out why that is?
> 
> If this is the case then I think the server is not advertising any
> addresses (or prefixes, or temporary addresses).
> 
> Can you quote your lease structure from dhclient6.leases?

Sure:

# cat dhclient6.leases
default-duid "\000\001\000\001\024\022a?\000 at c\366\002\001";
lease6 {
  interface "ppp0";
  ia-pd 00:00:00:00 {
    starts 1283440643;
    renew 0;
    rebind 0;
    iaprefix 2001:980:3180::/48 {
      starts 1283440643;
      preferred-life 7200;
      max-life 7200;
    }
  }
  option dhcp6.client-id 0:1:0:1:14:12:61:3f:0:40:63:f6:2:1;
  option dhcp6.server-id
0:2:0:0:a:4c:45:33:32:30:2f:37:34:35:41:43:33:33:45:58:32:2f:1;
  option dhcp6.reconf-accept ;
  option dhcp6.name-servers 2001:888:0:6::66,2001:888:0:9::99;
  option dhcp6.status-code success;
}
lease6 {
  interface "ppp0";
  ia-pd 00:00:00:00 {
    starts 1283444243;
    renew 0;
    rebind 0;
    iaprefix 2001:980:3180::/48 {
      starts 1283444243;
      preferred-life 7200;
      max-life 7200;
    }
  }
  option dhcp6.client-id 0:1:0:1:14:12:61:3f:0:40:63:f6:2:1;
  option dhcp6.server-id
0:2:0:0:a:4c:45:33:32:30:2f:37:34:35:41:43:33:33:45:58:32:2f:1;
  option dhcp6.reconf-accept ;
  option dhcp6.name-servers 2001:888:0:6::66,2001:888:0:9::99;
  option dhcp6.status-code success;
}

(yes, the leases file grows!)

Some `logging`:

(....)
XMT: Solicit on ppp0, interval 128810ms.
XMT: Forming Solicit, 655350 ms elapsed.
XMT:  X-- IA_PD 00:00:00:00
XMT:  | X-- Request renew in  +3600
XMT:  | X-- Request rebind in +5400
XMT: Solicit on ppp0, interval 124180ms.
XMT: Forming Solicit, 655350 ms elapsed.
XMT:  X-- IA_PD 00:00:00:00
XMT:  | X-- Request renew in  +3600
XMT:  | X-- Request rebind in +5400
XMT: Solicit on ppp0, interval 109020ms.
XMT: Forming Solicit, 655350 ms elapsed.
XMT:  X-- IA_PD 00:00:00:00
XMT:  | X-- Request renew in  +3600
XMT:  | X-- Request rebind in +5400
XMT: Solicit on ppp0, interval 122060ms.
XMT: Forming Solicit, 655350 ms elapsed.
XMT:  X-- IA_PD 00:00:00:00
XMT:  | X-- Request renew in  +3600
XMT:  | X-- Request rebind in +5400
XMT: Solicit on ppp0, interval 122070ms.
XMT: Forming Solicit, 655350 ms elapsed.
XMT:  X-- IA_PD 00:00:00:00
XMT:  | X-- Request renew in  +3600
XMT:  | X-- Request rebind in +5400
XMT: Solicit on ppp0, interval 111360ms.
RCV: Advertise message on ppp0 from fe80::90:1a00:1a1:88e6.
RCV:  X-- IA_PD 00:00:00:00
RCV:  | X-- starts 1283440642
RCV:  | X-- t1 - renew  +0
RCV:  | X-- t2 - rebind +0
RCV:  | X-- [Options]
RCV:  | | X-- IAPREFIX 2001:980:3180::/48
RCV:  | | | X-- Preferred lifetime 7200.
RCV:  | | | X-- Max lifetime 7200.
RCV:  X-- Server ID: 00:02:00:00:0a:4c:45:33:32:30:2f:37:34:35:41:43:33
message status code Success.
RCV:  Advertisement immediately selected.
PRC: Selecting best advertised lease.
PRC: Considering best lease.
PRC:  X-- Initial candidate
00:02:00:00:0a:4c:45:33:32:30:2f:37:34:35:41:43 (s: 154, p: 0).
XMT: Forming Request, 0 ms elapsed.
XMT:  X-- IA_PD 00:00:00:00
XMT:  | X-- Requested renew  +3600
XMT:  | X-- Requested rebind +5400
XMT:  | | X-- IAPREFIX 2001:980:3180::/48
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  V IA_PD appended.
XMT: Request on ppp0, interval 1010ms.
RCV: Reply message on ppp0 from fe80::90:1a00:1a1:88e6.
RCV:  X-- IA_PD 00:00:00:00
RCV:  | X-- starts 1283440643
RCV:  | X-- t1 - renew  +0
RCV:  | X-- t2 - rebind +0
RCV:  | X-- [Options]
RCV:  | | X-- IAPREFIX 2001:980:3180::/48
RCV:  | | | X-- Preferred lifetime 7200.
RCV:  | | | X-- Max lifetime 7200.
RCV:  X-- Server ID: 00:02:00:00:0a:4c:45:33:32:30:2f:37:34:35:41:43:33
message status code Success.
PRC: Bound to lease 00:02:00:00:0a:4c:45:33:32:30:2f:37:34:35:41:43:33:33.
BOUND6
----
interface=ppp0
new_life_starts=1283440643
new_max_life=7200
new_starts=1283440643
reason=BOUND6
new_dhcp6_client_id=0:1:0:1:14:12:61:3f:0:40:63:f6:2:1
new_preferred_life=7200
new_ip6_prefix=2001:980:3180::/48
new_iaid=00:00:00:00
new_rebind=0
pid=20237
new_dhcp6_server_id=0:2:0:0:a:4c:45:33:32:30:2f:37:34:35:41:43:33:33:45:58:32:2f:1
PWD=/usr/src/dhcp-4.1.1/client
new_renew=0
new_dhcp6_name_servers=2001:888:0:6::66 2001:888:0:9::99
new_dhcp6_status_code=success
SHLVL=1
_=/bin/env
----
BOUND6 <-----------
huuh
PRC: Renewal event scheduled in 3600 seconds, to run for 1800 seconds.
PRC: Depreference scheduled in 7200 seconds.
PRC: Expiration scheduled in 7200 seconds.
PRC: Renewing lease on ppp0.
XMT: Forming Renew, 0 ms elapsed.
XMT:  X-- IA_PD 00:00:00:00
XMT:  | X-- Requested renew  +3600
XMT:  | X-- Requested rebind +5400
XMT:  | | X-- IAPREFIX 2001:980:3180::/48
XMT:  | | | X-- Preferred lifetime +7200
XMT:  | | | X-- Max lifetime +7500
XMT:  V IA_PD appended.
XMT: Renew on ppp0, interval 10070ms.
RCV: Reply message on ppp0 from fe80::90:1a00:1a1:88e6.
RCV:  X-- IA_PD 00:00:00:00
RCV:  | X-- starts 1283444243
RCV:  | X-- t1 - renew  +0
RCV:  | X-- t2 - rebind +0
RCV:  | X-- [Options]
RCV:  | | X-- IAPREFIX 2001:980:3180::/48
RCV:  | | | X-- Preferred lifetime 7200.
RCV:  | | | X-- Max lifetime 7200.
RCV:  X-- Server ID: 00:02:00:00:0a:4c:45:33:32:30:2f:37:34:35:41:43:33
message status code Success.
PRC: Bound to lease 00:02:00:00:0a:4c:45:33:32:30:2f:37:34:35:41:43:33:33.
RENEW6
----
old_renew=0
old_dhcp6_server_id=0:2:0:0:a:4c:45:33:32:30:2f:37:34:35:41:43:33:33:45:58:32:2f:1
old_max_life=7200
old_starts=1283440643
interface=ppp0
new_life_starts=1283444243
new_max_life=7200
new_starts=1283444243
reason=RENEW6
new_dhcp6_client_id=0:1:0:1:14:12:61:3f:0:40:63:f6:2:1
new_preferred_life=7200
new_ip6_prefix=2001:980:3180::/48
old_ip6_prefix=2001:980:3180::/48
new_iaid=00:00:00:00
old_iaid=00:00:00:00
new_rebind=0
old_preferred_life=7200
pid=20237
new_dhcp6_server_id=0:2:0:0:a:4c:45:33:32:30:2f:37:34:35:41:43:33:33:45:58:32:2f:1
PWD=/usr/src/dhcp-4.1.1/client
old_rebind=0
new_renew=0
new_dhcp6_name_servers=2001:888:0:6::66 2001:888:0:9::99
new_dhcp6_status_code=success
old_dhcp6_status_code=success
SHLVL=1
old_dhcp6_client_id=0:1:0:1:14:12:61:3f:0:40:63:f6:2:1
old_life_starts=1283440643
old_dhcp6_name_servers=2001:888:0:6::66 2001:888:0:9::99
_=/bin/env
----
RENEW6 <-----------
PRC: Renewal event scheduled in 3600 seconds, to run for 1800 seconds.
PRC: Depreference scheduled in 7200 seconds.
PRC: Expiration scheduled in 7200 seconds.

I added some debug printing. Also `env` dumps the variables.
The 'huuh' is when dh6config discovers there's no ipv6 number.

So what would I do next?
I cannot run dhclient on ppp0 without the patch.
So please have a look at the patch, mentioned in the bugzilla entry:
https://lists.isc.org/pipermail/dhcp-users/attachments/20100426/9deb431f/attachment.bin
Maybe the patch is introducing the issue?

Kind regards,
Udo