Re: NM 0.8.2-rc1: nm_dispatcher_action: Invalid connection: '(null)' / 'connection setting not found' invalid: 1

[Jirka Klimes <jklimes redhat com>]

On Friday 05 of November 2010 20:17:41 Andrey Borzenkov wrote:
> I get the above error after every device (de-)activation. The
> connection itself is correctly activated (respectively deactivated).
> Device activation log below. Anything I can do to collect more
> information? Thank you!
> 

Thanks for reporting!
The error should already be fixed by this commit:
http://cgit.freedesktop.org/NetworkManager/NetworkManager/commit/?id=4501e33b852be184a30cbdc2e49803d341db9d0c

> -Andrey
> 
> Nov  5 22:03:47 cooker NetworkManager[2383]: <info> (wlan0): now managed
> Nov  5 22:03:47 cooker NetworkManager[2383]: <info> (wlan0): device
> state change: 1 -> 2 (reason 2)
> Nov  5 22:03:47 cooker NetworkManager[2383]: <info> (wlan0): bringing up
> device. Nov  5 22:03:47 cooker kernel: ADDRCONF(NETDEV_UP): wlan0: link is
> not ready Nov  5 22:03:47 cooker NetworkManager[2383]: <info> (wlan0):
> preparing device. Nov  5 22:03:47 cooker NetworkManager[2383]: <info>
> (wlan0):
> deactivating device (reason: 2).
> Nov  5 22:03:47 cooker NetworkManager[2383]: <info> (eth0): now managed
> Nov  5 22:03:47 cooker NetworkManager[2383]: <info> (eth0): device
> state change: 1 -> 2 (reason 2)
> Nov  5 22:03:47 cooker NetworkManager[2383]: <info> (eth0): bringing up
> device. Nov  5 22:03:47 cooker NetworkManager[2383]: <info> (eth0):
> preparing device. Nov  5 22:03:47 cooker NetworkManager[2383]: <info>
> (eth0):
> deactivating device (reason: 2).
> Nov  5 22:03:47 cooker kernel: ADDRCONF(NETDEV_UP): eth0: link is not ready
> Nov  5 22:03:47 cooker NetworkManager[2383]: <info> (wlan0):
> supplicant interface state:  starting -> ready
> Nov  5 22:03:47 cooker NetworkManager[2383]: <info> (wlan0): device
> state change: 2 -> 3 (reason 42)
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> starting connection 'System Home, sweet home'
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> (wlan0): device
> state change: 3 -> 4 (reason 0)
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 1 of 5 (Device Prepare) scheduled...
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 1 of 5 (Device Prepare) started...
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 2 of 5 (Device Configure) scheduled...
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 1 of 5 (Device Prepare) complete.
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 2 of 5 (Device Configure) starting...
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> (wlan0): device
> state change: 4 -> 5 (reason 0)
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation
> (wlan0/wireless): access point 'System Home, sweet home' has security,
> but secrets are required.
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> (wlan0): device
> state change: 5 -> 6 (reason 0)
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 2 of 5 (Device Configure) complete.
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 1 of 5 (Device Prepare) scheduled...
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 1 of 5 (Device Prepare) started...
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> (wlan0): device
> state change: 6 -> 4 (reason 0)
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 2 of 5 (Device Configure) scheduled...
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 1 of 5 (Device Prepare) complete.
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 2 of 5 (Device Configure) starting...
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> (wlan0): device
> state change: 4 -> 5 (reason 0)
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation
> (wlan0/wireless): connection 'System Home, sweet home' has security,
> and secrets exist.  No new secrets needed.
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Config: added
> 'ssid' value 'Home, sweet home'
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Config: added
> 'scan_ssid' value '1'
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Config: added
> 'key_mgmt' value 'WPA-PSK'
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Config: added
> 'psk' value '<omitted>'
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Config: added
> 'proto' value 'WPA RSN'
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 2 of 5 (Device Configure) complete.
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> Config: set
> interface ap_scan to 1
> Nov  5 22:03:50 cooker NetworkManager[2383]: <info> (wlan0):
> supplicant connection state:  inactive -> scanning
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> (wlan0):
> supplicant connection state:  scanning -> associating
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> (wlan0):
> supplicant connection state:  associating -> associated
> Nov  5 22:03:52 cooker kernel: ADDRCONF(NETDEV_CHANGE): wlan0: link
> becomes ready
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> (wlan0):
> supplicant connection state:  associated -> 4-way handshake
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> (wlan0):
> supplicant connection state:  4-way handshake -> group handshake
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> (wlan0):
> supplicant connection state:  group handshake -> completed
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> Activation
> (wlan0/wireless) Stage 2 of 5 (Device Configure) successful.
> Connected to wireless network 'Home, sweet home'.
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 3 of 5 (IP Configure Start) scheduled.
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 3 of 5 (IP Configure Start) started...
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> (wlan0): device
> state change: 5 -> 7 (reason 0)
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Beginning DHCPv4 transaction (timeout in 45 seconds)
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> dhclient started
> with pid 23598
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 3 of 5 (IP Configure Start) complete.
> Nov  5 22:03:52 cooker dhclient: Internet Systems Consortium DHCP Client
> 4.2.0 Nov  5 22:03:52 cooker dhclient: Copyright 2004-2010 Internet
> Systems Consortium.
> Nov  5 22:03:52 cooker dhclient: All rights reserved.
> Nov  5 22:03:52 cooker dhclient: For info, please visit
> https://www.isc.org/software/dhcp/
> Nov  5 22:03:52 cooker dhclient:
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> (wlan0): DHCPv4
> state changed nbi -> preinit
> Nov  5 22:03:52 cooker dhclient: Listening on LPF/wlan0/00:1f:3c:9c:47:ba
> Nov  5 22:03:52 cooker dhclient: Sending on   LPF/wlan0/00:1f:3c:9c:47:ba
> Nov  5 22:03:52 cooker dhclient: Sending on   Socket/fallback
> Nov  5 22:03:52 cooker dhclient: DHCPREQUEST on wlan0 to 255.255.255.255
> port 67 Nov  5 22:03:52 cooker dhclient: DHCPACK from 192.168.10.1
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> (wlan0): DHCPv4
> state changed preinit -> reboot
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 4 of 5 (IP4 Configure Get) scheduled...
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 4 of 5 (IP4 Configure Get) started...
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info>   address
> 192.168.10.104 Nov  5 22:03:52 cooker NetworkManager[2383]: <info>  
> prefix 24 (255.255.255.0) Nov  5 22:03:52 cooker NetworkManager[2383]:
> <info>   gateway 192.168.10.1 Nov  5 22:03:52 cooker NetworkManager[2383]:
> <info>   nameserver '192.168.10.1' Nov  5 22:03:52 cooker
> NetworkManager[2383]: <info>   nameserver '195.34.32.116' Nov  5 22:03:52
> cooker NetworkManager[2383]: <info>   nameserver '212.188.4.10' Nov  5
> 22:03:52 cooker NetworkManager[2383]: <info> Activation (wlan0) Stage 5 of
> 5 (IP Configure Commit) scheduled...
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 4 of 5 (IP4 Configure Get) complete.
> Nov  5 22:03:52 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 5 of 5 (IP Configure Commit) started...
> Nov  5 22:03:52 cooker dhclient: bound to 192.168.10.104 -- renewal in
> 36477 seconds.
> Nov  5 22:03:53 cooker NetworkManager[2383]: <info> (wlan0): writing
> resolv.conf to /sbin/resolvconf
> Nov  5 22:03:53 cooker NetworkManager[2383]: <info> (wlan0): device
> state change: 7 -> 8 (reason 0)
> Nov  5 22:03:53 cooker NetworkManager[2383]: <info> Policy set 'System
> Home, sweet home' (wlan0) as default for IPv4 routing and DNS.
> Nov  5 22:03:53 cooker NetworkManager[2383]: <info> Updating
> /etc/hosts with new system hostname
> Nov  5 22:03:53 cooker NetworkManager[2383]: <info> Activation (wlan0)
> successful, device activated.
> Nov  5 22:03:53 cooker NetworkManager[2383]: <info> Activation (wlan0)
> Stage 5 of 5 (IP Configure Commit) complete.
> Nov  5 22:03:53 cooker nm-dispatcher.action: nm_dispatcher_action:
> Invalid connection: '(null)' / 'connection setting not found' invalid:
> 1
> _______________________________________________
> networkmanager-list mailing list
> networkmanager-list gnome org
> http://mail.gnome.org/mailman/listinfo/networkmanager-list