[clug] Problem getting a working IPv6 connection
Simon Fowler
sjjf at himi.org
Sat Feb 2 06:55:22 MST 2013
On Sun, Feb 03, 2013 at 12:09:54AM +1100, Simon Fowler wrote:
> On Sat, Feb 02, 2013 at 09:31:12PM +1100, Dale Shaw wrote:
> > Maybe bump up your debug/logging level and see what's happening during
> > IP6CP negotiation, and what's happening when DHCPv6 does its thing.
>
> Just enabled debugging, but my wife is watching stuff on Youtube and
> will kill me if I take things down.
Here we are (lots of guff coming):
Feb 3 00:26:42 lassus pppd[10746]: pppd 2.4.5 started by root, uid 0
Feb 3 00:26:42 lassus pppd[10746]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Feb 3 00:26:42 lassus pppd[10746]: dst ff:ff:ff:ff:ff:ff src 0:22:19:dd:57:2c
Feb 3 00:26:42 lassus pppd[10746]: [service-name] [host-uniq fa 29 00 00]
Feb 3 00:26:42 lassus pppd[10746]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 45
Feb 3 00:26:42 lassus pppd[10746]: dst 0:22:19:dd:57:2c src 0:90:1a:42:77:c6
Feb 3 00:26:42 lassus pppd[10746]: [AC-name nkyp-kent] [host-uniq fa 29 00 00] [service-name] [AC-cookie 04 7d 1a 09 9c c1 df 03 aa d7 89 40 79 23 1e 18]
Feb 3 00:26:42 lassus pppd[10746]: Send PPPOE Discovery V1T1 PADR session 0x0 length 32
Feb 3 00:26:42 lassus pppd[10746]: dst 0:90:1a:42:77:c6 src 0:22:19:dd:57:2c
Feb 3 00:26:42 lassus pppd[10746]: [service-name] [host-uniq fa 29 00 00] [AC-cookie 04 7d 1a 09 9c c1 df 03 aa d7 89 40 79 23 1e 18]
Feb 3 00:26:46 lassus pppd[10746]: Recv PPPOE Discovery V1T1 PADT session 0x849 length 0
Feb 3 00:26:46 lassus pppd[10746]: dst 0:22:19:dd:57:2c src 0:90:1a:42:77:c6
Feb 3 00:26:51 lassus pppd[10746]: Send PPPOE Discovery V1T1 PADR session 0x0 length 32
Feb 3 00:26:51 lassus pppd[10746]: dst 0:90:1a:42:77:c6 src 0:22:19:dd:57:2c
Feb 3 00:26:51 lassus pppd[10746]: [service-name] [host-uniq fa 29 00 00] [AC-cookie 04 7d 1a 09 9c c1 df 03 aa d7 89 40 79 23 1e 18]
Feb 3 00:26:51 lassus pppd[10746]: Recv PPPOE Discovery V1T1 PADS session 0x861 length 45
Feb 3 00:26:51 lassus pppd[10746]: dst 0:22:19:dd:57:2c src 0:90:1a:42:77:c6
Feb 3 00:26:51 lassus pppd[10746]: [service-name] [host-uniq fa 29 00 00] [AC-name nkyp-kent] [AC-cookie 04 7d 1a 09 9c c1 df 03 aa d7 89 40 79 23 1e 18]
Feb 3 00:26:51 lassus pppd[10746]: PADS: Service-Name: ''
Feb 3 00:26:51 lassus pppd[10746]: PPP session is 2145
Feb 3 00:26:51 lassus pppd[10746]: Connected to 00:90:1a:42:77:c6 via interface eth0.2
Feb 3 00:26:51 lassus pppd[10746]: using channel 7
Feb 3 00:26:51 lassus pppd[10746]: Using interface ppp0
Feb 3 00:26:51 lassus pppd[10746]: Connect: ppp0 <--> eth0.2
Feb 3 00:26:51 lassus pppd[10746]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0xcafaea8d>]
Feb 3 00:26:51 lassus pppd[10746]: rcvd [LCP ConfReq id=0x5a <mru 1492> <auth chap MD5> <magic 0x1d153a45>]
Feb 3 00:26:51 lassus pppd[10746]: sent [LCP ConfAck id=0x5a <mru 1492> <auth chap MD5> <magic 0x1d153a45>]
Feb 3 00:26:51 lassus pppd[10746]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0xcafaea8d>]
Feb 3 00:26:51 lassus pppd[10746]: sent [LCP EchoReq id=0x0 magic=0xcafaea8d]
Feb 3 00:26:51 lassus pppd[10746]: rcvd [LCP EchoRep id=0x0 magic=0x1d153a45]
Feb 3 00:26:51 lassus pppd[10746]: rcvd [LCP ConfReq id=0x1 <mru 1492> <auth chap MD5> <magic 0xaed83c66>]
Feb 3 00:26:51 lassus pppd[10746]: sent [LCP ConfReq id=0x2 <mru 1492> <magic 0xa06ff830>]
Feb 3 00:26:51 lassus pppd[10746]: sent [LCP ConfAck id=0x1 <mru 1492> <auth chap MD5> <magic 0xaed83c66>]
Feb 3 00:26:51 lassus pppd[10746]: rcvd [LCP ConfAck id=0x2 <mru 1492> <magic 0xa06ff830>]
Feb 3 00:26:51 lassus pppd[10746]: sent [LCP EchoReq id=0x0 magic=0xa06ff830]
<snip CHAP conversation>
Feb 3 00:26:51 lassus pppd[10746]: CHAP authentication succeeded
Feb 3 00:26:51 lassus pppd[10746]: peer from calling number 00:90:1A:42:77:C6 authorized
Feb 3 00:26:51 lassus pppd[10746]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Feb 3 00:26:51 lassus pppd[10746]: sent [IPV6CP ConfReq id=0x1 <addr fe80::c890:2b91:7af1:e65c>]
Feb 3 00:26:51 lassus pppd[10746]: rcvd [IPCP ConfReq id=0x1 <addr 150.101.199.159>]
Feb 3 00:26:51 lassus pppd[10746]: sent [IPCP ConfAck id=0x1 <addr 150.101.199.159>]
Feb 3 00:26:51 lassus pppd[10746]: rcvd [IPCP ConfNak id=0x1 <addr 59.167.140.208> <ms-dns1 192.231.203.132> <ms-dns2 192.231.203.3>]
Feb 3 00:26:51 lassus pppd[10746]: sent [IPCP ConfReq id=0x2 <addr 59.167.140.208> <ms-dns1 192.231.203.132> <ms-dns2 192.231.203.3>]
Feb 3 00:26:51 lassus pppd[10746]: rcvd [IPV6CP ConfReq id=0x1 <addr fe80::0224:14ff:fe9a:a410>]
Feb 3 00:26:51 lassus pppd[10746]: sent [IPV6CP ConfAck id=0x1 <addr fe80::0224:14ff:fe9a:a410>]
Feb 3 00:26:51 lassus pppd[10746]: rcvd [IPV6CP ConfAck id=0x1 <addr fe80::c890:2b91:7af1:e65c>]
Feb 3 00:26:51 lassus pppd[10746]: local LL address fe80::c890:2b91:7af1:e65c
Feb 3 00:26:51 lassus pppd[10746]: remote LL address fe80::0224:14ff:fe9a:a410
Feb 3 00:26:51 lassus pppd[10746]: Script /etc/ppp/ipv6-up started (pid 10757)
Feb 3 00:26:51 lassus pppd[10746]: Script /etc/ppp/ipv6-up finished (pid 10757), status = 0x0
Feb 3 00:26:51 lassus pppd[10746]: rcvd [IPCP ConfAck id=0x2 <addr 59.167.140.208> <ms-dns1 192.231.203.132> <ms-dns2 192.231.203.3>]
Feb 3 00:26:51 lassus pppd[10746]: local IP address 59.167.140.208
Feb 3 00:26:51 lassus pppd[10746]: remote IP address 150.101.199.159
Feb 3 00:26:51 lassus pppd[10746]: primary DNS address 192.231.203.132
Feb 3 00:26:51 lassus pppd[10746]: secondary DNS address 192.231.203.3
Feb 3 00:26:51 lassus pppd[10746]: Script /etc/ppp/ip-up started (pid 10769)
Feb 3 00:27:56 lassus pppd[10746]: Script /etc/ppp/ip-up finished (pid 10769), status = 0x0
simon at lassus:/etc/init.d$ sudo dhcp6c -D -f -c /etc/wide-dhcpv6/dhcp6c.conf ppp0
Feb/03/2013 00:34:26: get_duid: extracted an existing DUID from /var/lib/dhcpv6/dhcp6c_duid: 00:01:00:01:18:9c:fa:ed:00:22:19:dd:57:2c
Feb/03/2013 00:34:26: cfdebug_print: <3>comment [# Default dhpc6c configuration: it assumes the address is autoconfigured using] (78)
Feb/03/2013 00:34:26: cfdebug_print: <3>comment [# router advertisements.] (24)
Feb/03/2013 00:34:26: cfdebug_print: <3>[interface] (9)
Feb/03/2013 00:34:26: cfdebug_print: <5>[ppp0] (4)
Feb/03/2013 00:34:26: cfdebug_print: <3>begin of closure [{] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>[send] (4)
Feb/03/2013 00:34:26: cfdebug_print: <3>[ia-pd] (5)
Feb/03/2013 00:34:26: cfdebug_print: <3>[0] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of sentence [;] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>[script] (6)
Feb/03/2013 00:34:26: cfdebug_print: <3>["/etc/wide-dhcpv6/dhcp6c-script"] (32)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of sentence [;] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of closure [}] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of sentence [;] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>[id-assoc] (8)
Feb/03/2013 00:34:26: cfdebug_print: <15>[pd] (2)
Feb/03/2013 00:34:26: cfdebug_print: <15>begin of closure [{] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>[prefix-interface] (16)
Feb/03/2013 00:34:26: cfdebug_print: <5>[eth0] (4)
Feb/03/2013 00:34:26: cfdebug_print: <3>begin of closure [{] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>[sla-id] (6)
Feb/03/2013 00:34:26: cfdebug_print: <3>[1] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of sentence [;] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>[sla-len] (7)
Feb/03/2013 00:34:26: cfdebug_print: <3>[8] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of sentence [;] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of closure [}] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of sentence [;] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>[prefix-interface] (16)
Feb/03/2013 00:34:26: cfdebug_print: <5>[eth0.2] (6)
Feb/03/2013 00:34:26: cfdebug_print: <3>begin of closure [{] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>[sla-id] (6)
Feb/03/2013 00:34:26: cfdebug_print: <3>[254] (3)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of sentence [;] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>[sla-len] (7)
Feb/03/2013 00:34:26: cfdebug_print: <3>[8] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of sentence [;] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of closure [}] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of sentence [;] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of closure [}] (1)
Feb/03/2013 00:34:26: cfdebug_print: <3>end of sentence [;] (1)
Feb/03/2013 00:34:26: configure_pool: called
Feb/03/2013 00:34:26: clear_poolconf: called
Feb/03/2013 00:34:26: dhcp6_reset_timer: reset a timer on ppp0, state=INIT, timeo=0, retrans=344
Feb/03/2013 00:34:27: client6_send: a new XID (1f2512) is generated
Feb/03/2013 00:34:27: copy_option: set client ID (len 14)
Feb/03/2013 00:34:27: copy_option: set elapsed time (len 2)
Feb/03/2013 00:34:27: copyout_option: set IA_PD
Feb/03/2013 00:34:27: client6_send: send solicit to ff02::1:2%ppp0
Feb/03/2013 00:34:27: dhcp6_reset_timer: reset a timer on ppp0, state=SOLICIT, timeo=0, retrans=1069
Feb/03/2013 00:34:27: client6_recv: receive advertise from fe80::224:14ff:fe9a:a410%ppp0 on ppp0
Feb/03/2013 00:34:27: dhcp6_get_options: get DHCP option server ID, len 10
Feb/03/2013 00:34:27: DUID: 00:03:00:01:00:24:14:9a:a4:10
Feb/03/2013 00:34:27: dhcp6_get_options: get DHCP option client ID, len 14
Feb/03/2013 00:34:27: DUID: 00:01:00:01:18:9c:fa:ed:00:22:19:dd:57:2c
Feb/03/2013 00:34:27: dhcp6_get_options: get DHCP option IA_PD, len 41
Feb/03/2013 00:34:27: IA_PD: ID=0, T1=1800, T2=2880
Feb/03/2013 00:34:27: copyin_option: get DHCP option IA_PD prefix, len 25
Feb/03/2013 00:34:27: copyin_option: IA_PD prefix: 2001:44b8:317e:8a00::/56 pltime=3600 vltime=7201
Feb/03/2013 00:34:27: dhcp6_get_options: get DHCP option DNS, len 32
Feb/03/2013 00:34:27: dhcp6_get_options: get DHCP option domain search list, len 1
Feb/03/2013 00:34:27: dhcp6_get_options: get DHCP option SIP domain name, len 22
Feb/03/2013 00:34:27: dhcp6_get_options: get DHCP option NTP server, len 16
Feb/03/2013 00:34:27: client6_recvadvert: server ID: 00:03:00:01:00:24:14:9a:a4:10, pref=-1
Feb/03/2013 00:34:27: client6_recvadvert: reset timer for ppp0 to 0.887500
Feb/03/2013 00:34:28: select_server: picked a server (ID: 00:03:00:01:00:24:14:9a:a4:10)
Feb/03/2013 00:34:28: client6_send: a new XID (db795b) is generated
Feb/03/2013 00:34:28: copy_option: set client ID (len 14)
Feb/03/2013 00:34:28: copy_option: set server ID (len 10)
Feb/03/2013 00:34:28: copy_option: set elapsed time (len 2)
Feb/03/2013 00:34:28: copyout_option: set IA_PD prefix
Feb/03/2013 00:34:28: copyout_option: set IA_PD
Feb/03/2013 00:34:28: client6_send: send request to ff02::1:2%ppp0
Feb/03/2013 00:34:28: dhcp6_reset_timer: reset a timer on ppp0, state=REQUEST, timeo=0, retrans=1034
Feb/03/2013 00:34:28: client6_recv: receive reply from fe80::224:14ff:fe9a:a410%ppp0 on ppp0
Feb/03/2013 00:34:28: dhcp6_get_options: get DHCP option server ID, len 10
Feb/03/2013 00:34:28: DUID: 00:03:00:01:00:24:14:9a:a4:10
Feb/03/2013 00:34:28: dhcp6_get_options: get DHCP option client ID, len 14
Feb/03/2013 00:34:28: DUID: 00:01:00:01:18:9c:fa:ed:00:22:19:dd:57:2c
Feb/03/2013 00:34:28: dhcp6_get_options: get DHCP option IA_PD, len 41
Feb/03/2013 00:34:28: IA_PD: ID=0, T1=1800, T2=2880
Feb/03/2013 00:34:28: copyin_option: get DHCP option IA_PD prefix, len 25
Feb/03/2013 00:34:28: copyin_option: IA_PD prefix: 2001:44b8:317e:8a00::/56 pltime=3600 vltime=7201
Feb/03/2013 00:34:28: dhcp6_get_options: get DHCP option DNS, len 32
Feb/03/2013 00:34:28: dhcp6_get_options: get DHCP option domain search list, len 1
Feb/03/2013 00:34:28: dhcp6_get_options: get DHCP option SIP domain name, len 22
Feb/03/2013 00:34:28: dhcp6_get_options: get DHCP option NTP server, len 16
Feb/03/2013 00:34:28: info_printf: nameserver[0] 2001:44b8:1::1
Feb/03/2013 00:34:28: info_printf: nameserver[1] 2001:44b8:2::2
Feb/03/2013 00:34:28: info_printf: Domain search list[0] .
Feb/03/2013 00:34:28: info_printf: NTP server[0] 2001:44b8:1::1
Feb/03/2013 00:34:28: info_printf: SIP domain name[0] sip.internode.on.net.
Feb/03/2013 00:34:28: client6_recvreply: executes /etc/wide-dhcpv6/dhcp6c-script
Feb/03/2013 00:34:28: client6_script: script "/etc/wide-dhcpv6/dhcp6c-script" terminated
Feb/03/2013 00:34:28: get_ia: make an IA: PD-0
Feb/03/2013 00:34:28: update_prefix: create a prefix 2001:44b8:317e:8a00::/56 pltime=3600, vltime=30064778273
Feb/03/2013 00:34:28: ifaddrconf: add an address 2001:44b8:317e:8a01:222:19ff:fedd:572c/64 on eth0
Feb/03/2013 00:34:28: ifaddrconf: add an address 2001:44b8:317e:8afe:222:19ff:fedd:572c/64 on eth0.2
Feb/03/2013 00:34:28: dhcp6_remove_event: removing an event on ppp0, state=REQUEST
Feb/03/2013 00:34:28: dhcp6_remove_event: removing server (ID: 00:03:00:01:00:24:14:9a:a4:10)
Feb/03/2013 00:34:28: client6_recvreply: got an expected reply, sleeping.
No idea what to expect from any of these.
Simon
--
PGP public key Id 0x96263cef
Homepage: http://himi.org
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 490 bytes
Desc: Digital signature
URL: <http://lists.samba.org/pipermail/linux/attachments/20130203/4d33c2ec/attachment.pgp>
More information about the linux
mailing list