DBUS communication problem?

[Barney Livingston <barney barnoid org uk>]

Hi.

NetworkManager on my Debian etch/unstable laptop seems to have trouble 
communicating with dhclient over DBUS. It gets most of the way with 
configuring the wired interface but then gives up when it comes to running 
dhclient such that it never runs (see attached syslog extract).

My user is in the netdev group and dhclient-script seems to be including the 
required dbus code from /etc/dhcp3/dhclient-exit-hooks.d/dhcdbd. Everything 
works manually.

Some package versions:
dbus  1.0.2-1
libdbus-1-3  1.0.2-1
dhcp3-client  3.0.4-13
dhcdbd  2.0-2
network-manager  0.6.4-6
network-manager-kde  1:0.1-4

Kernel 2.6.17.6-suspend2

Hardware: Thinkpad T60, IPW3945 wireless, E1000 wired

Thanks,

Barney

Feb  8 12:33:40 jarvis NetworkManager: <information>^IWill activate connection 'eth-wired'.
Feb  8 12:33:40 jarvis NetworkManager: <information>^IDevice eth-wired activation scheduled...
Feb  8 12:33:40 jarvis NetworkManager: <information>^IActivation (eth-wired) started...
Feb  8 12:33:40 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 1 of 5 (Device Prepare) scheduled...
Feb  8 12:33:40 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 1 of 5 (Device Prepare) started...
Feb  8 12:33:40 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 2 of 5 (Device Configure) scheduled...
Feb  8 12:33:40 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 1 of 5 (Device Prepare) complete.
Feb  8 12:33:40 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 2 of 5 (Device Configure) starting...
Feb  8 12:33:40 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 2 of 5 (Device Configure) successful.
Feb  8 12:33:40 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 3 of 5 (IP Configure Start) scheduled.
Feb  8 12:33:40 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 2 of 5 (Device Configure) complete.
Feb  8 12:33:40 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 3 of 5 (IP Configure Start) started...
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) Beginning DHCP transaction.
Feb  8 12:33:41 jarvis NetworkManager: <WARNING>^I nm_dhcp_manager_begin_transaction (): nm_dhcp_manager_begin_transaction(): Couldn't allocate the dbus message
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) failure scheduled...
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 3 of 5 (IP Configure Start) complete.
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) failed.
Feb  8 12:33:41 jarvis NetworkManager: <information>^IDeactivating device eth-wired.
Feb  8 12:33:41 jarvis NetworkManager: <information>^ISWITCH: no current connection, found better connection 'eth-wired'.
Feb  8 12:33:41 jarvis NetworkManager: <WARNING>^I nm_dhcp_manager_get_state_for_device (): nm_dhcp_manager_get_state_for_device(): Couldn't allocate the dbus message
Feb  8 12:33:41 jarvis NetworkManager: <information>^IWill activate connection 'eth-wired'.
Feb  8 12:33:41 jarvis NetworkManager: <information>^IDevice eth-wired activation scheduled...
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) started...
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 1 of 5 (Device Prepare) scheduled...
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 1 of 5 (Device Prepare) started...
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 2 of 5 (Device Configure) scheduled...
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 1 of 5 (Device Prepare) complete.
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 2 of 5 (Device Configure) starting...
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 2 of 5 (Device Configure) successful.
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 3 of 5 (IP Configure Start) scheduled.
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 2 of 5 (Device Configure) complete.
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 3 of 5 (IP Configure Start) started...
Feb  8 12:33:41 jarvis NetworkManager: <information>^IGoing to sleep.
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired): cancelling...
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired) cancellation handler scheduled...
Feb  8 12:33:41 jarvis NetworkManager: <information>^IActivation (eth-wired): waiting for device to cancel activation.
Feb  8 12:33:42 jarvis NetworkManager: <information>^IActivation (eth-wired) Beginning DHCP transaction.
Feb  8 12:33:42 jarvis NetworkManager: <WARNING>^I nm_dhcp_manager_begin_transaction (): nm_dhcp_manager_begin_transaction(): Couldn't allocate the dbus message
Feb  8 12:33:42 jarvis NetworkManager: <information>^IActivation (eth-wired) failure scheduled...
Feb  8 12:33:42 jarvis NetworkManager: <information>^IActivation (eth-wired) Stage 3 of 5 (IP Configure Start) complete.
Feb  8 12:33:42 jarvis NetworkManager: <information>^IActivation (eth-wired) cancellation handled.
Feb  8 12:33:42 jarvis NetworkManager: <information>^IActivation (eth-wired): cancelled.
Feb  8 12:33:42 jarvis NetworkManager: <information>^IActivation (eth-wired) failed.
Feb  8 12:33:42 jarvis NetworkManager: <information>^IDeactivating device eth-wired.