[Pkg-utopia-maintainers] Bug#823157: network-manager: dhcp6 gets IP but expires it almost instantly
Scott Ashcroft
scott.ashcroft at talk21.com
Sun May 1 15:56:54 UTC 2016
Package: network-manager
Version: 1.2.0-1
Severity: normal
There seems to be some sort of problem where dhclient gets an IPv6 address but it gets expires almost straight away.
Then since dhclient isn't running any more it doesn't get renewed.
Debug log from network manager looks like this:
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.5781] dns-mgr: (device_ip6_config_changed): no DNS changes to commit (0)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.5885] bus-manager: (dhcp) accepted connection 0x17f6e50 on private socket
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.5896] dhcp6 (wlan0): unmapped DHCP state 'PREINIT6'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.5897] dhcp6 (wlan0): DHCP reason 'PREINIT6' -> state 'unknown'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.5906] bus-manager: (dhcp) closed connection 0x17f6e50 on private socket
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6846] bus-manager: (dhcp) accepted connection 0x7fa0ac0110c0 on private socket
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6863] dhcp6 (wlan0): DHCP reason 'BOUND6' -> state 'bound'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6866] (wlan0): option 'dhcp6_client_id'=>'0:4:76:3f:3e:98:47:e1:4d:ca:92:1b:f4:db:2f:ad:93:a0'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6866] (wlan0): option 'requested_dhcp6_name_servers'=>'1'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6867] (wlan0): option 'dhcp6_name_servers'=>'2001:470:6805::2'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6867] (wlan0): option 'rebind'=>'0'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6867] (wlan0): option 'max_life'=>'600'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6867] (wlan0): option 'preferred_life'=>'375'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6867] (wlan0): option 'requested_dhcp6_domain_search'=>'1'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6868] (wlan0): option 'requested_dhcp6_client_id'=>'1'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6868] (wlan0): option 'life_starts'=>'1462059018'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6868] (wlan0): option 'ip6_address'=>'2001:470:6805:0:ffff:ffff:ffff:8534'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6868] (wlan0): option 'ip6_prefixlen'=>'64'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6868] (wlan0): option 'dhcp6_domain_search'=>'intra.qzxyz.com.'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6869] (wlan0): option 'renew'=>'0'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6869] (wlan0): option 'starts'=>'1462059018'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6869] (wlan0): option 'iaid'=>'ae:cf:6e:b2'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6869] (wlan0): option 'dhcp6_server_id'=>'0:1:0:1:19:b1:a:22:3c:d9:2b:b:5:2f'
May 1 16:29:49 bart NetworkManager[13335]: <info> [1462116589.6870] valid_lft 600
May 1 16:29:49 bart NetworkManager[13335]: <info> [1462116589.6870] preferred_lft 375
May 1 16:29:49 bart NetworkManager[13335]: <info> [1462116589.6870] address 2001:470:6805:0:ffff:ffff:ffff:8534
May 1 16:29:49 bart NetworkManager[13335]: <info> [1462116589.6870] nameserver '2001:470:6805::2'
May 1 16:29:49 bart NetworkManager[13335]: <info> [1462116589.6871] domain search 'intra.qzxyz.com.'
May 1 16:29:49 bart NetworkManager[13335]: <info> [1462116589.6871] dhcp6 (wlan0): state changed unknown -> bound, event ID="ae:cf:6e:b2|1462059018"
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6872] device[0x1856cf0] (wlan0): new DHCPv6 client state 1
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6876] device[0x1856cf0] (wlan0): activation-stage: schedule activate_stage5_ip6_config_commit,10 (id 797)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6879] bus-manager: (dhcp) closed connection 0x7fa0ac0110c0 on private socket
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6886] device[0x1856cf0] (wlan0): activation-stage: invoke activate_stage5_ip6_config_commit,10 (id 797)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6889] platform: address: adding or updating IPv6 address: 2001:470:6805:0:2450:248:c3b2:2340/64 lft 2592000sec pref 604800sec lifetime 7-0[604800,2592000] dev 3 flags noprefixroute src unknown
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6890] platform-linux: do-add-ip6-address[3: 2001:470:6805:0:2450:248:c3b2:2340]: success
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6890] platform: address: adding or updating IPv6 address: 2001:470:6805:0:ffff:ffff:ffff:8534/128 lft 600sec pref 375sec lifetime 7-0[375,600] dev 3 src unknown
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6923] platform: signal: route 6 added: 2001:470:6805:0:ffff:ffff:ffff:8534/128 via :: dev 3 metric 256 mss 0 src rtprot-kernel
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6924] device[0x1856cf0] (wlan0): queued IP6 config change
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6924] platform-linux: do-add-ip6-address[3: 2001:470:6805:0:ffff:ffff:ffff:8534]: success
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6927] platform: signal: address 6 added: 2001:470:6805:0:ffff:ffff:ffff:8534/128 lft 600sec pref 375sec lifetime 7-7[375,600] dev 3 flags tentative src kernel
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6927] default-route: resync: schedule on idle
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6928] platform: address: adding or updating IPv6 address: fe80::787c:1707:7e19:d990/64 lft forever pref forever lifetime 7-0[4294967295,4294967295] dev 3 flags permanent src unknown
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6932] platform-linux: do-add-ip6-address[3: fe80::787c:1707:7e19:d990]: success
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6933] route-mgr6: 3: sync 1 IPv6 routes
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6951] device[0x1856cf0] (wlan0): update IP6Config instance (/org/freedesktop/NetworkManager/IP6Config/4)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6951] device[0x1856cf0] (wlan0): update IP6Config instance (/org/freedesktop/NetworkManager/IP6Config/4)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6952] default-route: entry[0/dev:0x1856cf0:wlan0:1:+sync]: record:update ::/0 via fe80::c664:13ff:fe56:7970 dev 3 metric 600 mss 0 src user (600)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6952] default-route: resync: cancelled (800)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6953] default-route: entry[0/dev:0x1856cf0:wlan0:1:+sync]: sync:update ::/0 via fe80::c664:13ff:fe56:7970 dev 3 metric 600 mss 0 src user (600 -> 600)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6953] platform: route: adding or updating IPv6 route: ::/0 via fe80::c664:13ff:fe56:7970 dev 3 metric 600 mss 0 src user
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6960] platform-linux: do-add-ip6-route[3: ::/0 600]: success
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6961] dns-mgr: (device_ip6_config_changed): queueing DNS updates (1)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6962] dns-mgr: (device_ip6_config_changed): DNS configuration changed
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6962] dns-mgr: (device_ip6_config_changed): committing DNS changes (0)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6962] dns-mgr: update-dns: updating resolv.conf
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6963] dns-mgr: update-dns: program not available, writing to resolv.conf
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6968] dispatcher: (4) (wlan0) dispatching action 'dhcp6-change'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6986] device[0x1856cf0] (wlan0): remove_pending_action (0): 'dhcp6' not pending (expected)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6987] device[0x1856cf0] (wlan0): remove_pending_action (0): 'autoconf6' not pending (expected)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.6987] device[0x1856cf0] (wlan0): activation-stage: complete activate_stage5_ip6_config_commit,10 (id 797)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7013] bus-manager: (dhcp) accepted connection 0x7fa0ac0111c0 on private socket
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7019] device[0x1856cf0] (wlan0): update IP6Config instance (/org/freedesktop/NetworkManager/IP6Config/4)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7020] default-route: entry[0/dev:0x1856cf0:wlan0:1:-sync]: record:update ::/0 via fe80::c664:13ff:fe56:7970 dev 3 metric 600 mss 0 src user (600)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7020] dns-mgr: (device_ip6_config_changed): queueing DNS updates (1)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7021] dns-mgr: (device_ip6_config_changed): DNS configuration did not change
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7021] dns-mgr: (device_ip6_config_changed): no DNS changes to commit (0)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7056] dhcp6 (wlan0): unmapped DHCP state 'DEPREF6'
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7057] dhcp6 (wlan0): DHCP reason 'DEPREF6' -> state 'unknown'
May 1 16:29:49 bart NetworkManager[13335]: <info> [1462116589.7058] dhcp6 (wlan0): state changed bound -> unknown
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7058] device[0x1856cf0] (wlan0): new DHCPv6 client state 0
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7099] dispatcher: (4) 01ifupdown succeeded
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7110] bus-manager: (dhcp) closed connection 0x7fa0ac0111c0 on private socket
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7168] bus-manager: (dhcp) accepted connection 0x7fa0ac0112c0 on private socket
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7183] dhcp6 (wlan0): DHCP reason 'EXPIRE6' -> state 'expire'
May 1 16:29:49 bart NetworkManager[13335]: <info> [1462116589.7183] dhcp6 (wlan0): state changed unknown -> expire
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7184] device[0x1856cf0] (wlan0): new DHCPv6 client state 4
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7184] kill child process 'dhcp-client-wlan0' (13506): waiting up to 500 milliseconds for process to terminate normally after sending SIGTERM (15)...
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7202] kill child process 'dhcp-client-wlan0' (13506): after sending SIGTERM (15), process 13506 exited by signal 15 (1799 usec elapsed)
May 1 16:29:49 bart NetworkManager[13335]: <info> [1462116589.7204] dhcp6 (wlan0): canceled DHCP transaction, DHCP client pid 13506
May 1 16:29:49 bart NetworkManager[13335]: <info> [1462116589.7204] dhcp6 (wlan0): state changed expire -> done
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7205] device[0x1856cf0] (wlan0): remove_pending_action (0): 'dhcp6' not pending (expected)
May 1 16:29:49 bart NetworkManager[13335]: <debug> [1462116589.7209] bus-manager: (dhcp) closed connection 0x7fa0ac0112c0 on private socket
The DHCP server is a Debian jessie system running ISC DHCP server 4.3.1.
Can I capture more debug to find out what is going on?
Cheers,
Scott
-- System Information:
Debian Release: stretch/sid
APT prefers testing
APT policy: (500, 'testing')
Architecture: amd64 (x86_64)
Kernel: Linux 4.5.0-1-amd64 (SMP w/4 CPU cores)
Locale: LANG=en_GB.UTF-8, LC_CTYPE=en_GB.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
Versions of packages network-manager depends on:
ii adduser 3.114
ii dbus 1.10.8-1
ii init-system-helpers 1.29
ii isc-dhcp-client 4.3.4-1
ii libaudit1 1:2.4.5-1+b1
ii libbluetooth3 5.36-1
ii libc6 2.22-7
ii libglib2.0-0 2.48.0-1
ii libgnutls30 3.4.10-4
ii libgudev-1.0-0 230-3
ii libmm-glib0 1.4.14-1
ii libndp0 1.4-2
ii libnewt0.52 0.52.18-3
ii libnl-3-200 3.2.27-1
ii libnm0 1.2.0-1
ii libpam-systemd 229-5
ii libpolkit-agent-1-0 0.105-15
ii libpolkit-gobject-1-0 0.105-15
ii libreadline6 6.3-8+b4
ii libselinux1 2.5-1
ii libsoup2.4-1 2.52.2-1
ii libsystemd0 229-5
ii libteamdctl0 1.24-1
ii libuuid1 2.28-1
ii lsb-base 9.20160110
ii policykit-1 0.105-15
ii udev 229-5
ii wpasupplicant 2.3-2.3
Versions of packages network-manager recommends:
ii crda 3.13-1+b1
ii dnsmasq-base 2.75-1
ii iptables 1.6.0-2
ii iputils-arping 3:20150815-2
ii modemmanager 1.4.14-1
ii ppp 2.4.7-1+2
Versions of packages network-manager suggests:
pn libteam-utils <none>
-- Configuration Files:
/etc/NetworkManager/NetworkManager.conf changed:
[main]
plugins=ifupdown,keyfile
[ifupdown]
managed=false
[logging]
level=debug
-- no debconf information
More information about the Pkg-utopia-maintainers
mailing list