dbus policy file (nm-avahi-autoipd.conf) not properly deployed in package (Was: link local ip address setting does not work with NetworkManager)

Also been experiencing this. After installing 8.10, I've noticed IP's thorugh avahi haven't been getting assigned. I set my wired (eth0) device to be link-local:

Nov 1 13:13:08 philia NetworkManager: <info> Activation (eth0) starting connection 'Auto eth0'
Nov 1 13:13:08 philia NetworkManager: <info> (eth0): device state change: 3 -> 4
Nov 1 13:13:08 philia NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Nov 1 13:13:08 philia NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Nov 1 13:13:08 philia NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Nov 1 13:13:08 philia NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Nov 1 13:13:08 philia NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Nov 1 13:13:08 philia NetworkManager: <info> (eth0): device state change: 4 -> 5
Nov 1 13:13:08 philia NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Nov 1 13:13:08 philia NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Nov 1 13:13:08 philia NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Nov 1 13:13:08 philia NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Nov 1 13:13:08 philia NetworkManager: <info> (eth0): device state change: 5 -> 7
Nov 1 13:13:08 philia NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started avahi-autoipd...
Nov 1 13:13:08 philia NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Nov 1 13:13:28 philia NetworkManager: <info> eth0: avahi-autoipd timed out.
Nov 1 13:13:28 philia NetworkManager: <debug> [1225559608.982397] aipd_cleanup(): waiting for ppp pid 7396 to exit
Nov 1 13:13:28 philia NetworkManager: <debug> [1225559608.994576] aipd_cleanup(): ppp pid 7396 cleaned up
Nov 1 13:13:28 philia NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Timeout) scheduled...
Nov 1 13:13:28 philia NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Timeout) started...
Nov 1 13:13:28 philia NetworkManager: <info> (eth0): device state change: 7 -> 9
Nov 1 13:13:28 philia NetworkManager: <info> Marking connection 'Auto eth0' invalid.
Nov 1 13:13:28 philia NetworkManager: <info> Activation (eth0) failed.
Nov 1 13:13:28 philia NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Timeout) complete.
Nov 1 13:13:28 philia NetworkManager: <info> (eth0): device state change: 9 -> 3
Nov 1 13:13:28 philia NetworkManager: <info> (eth0): deactivating device (reason: 0).

However when I run avahi-autoipd manually, it works well and correctly assigns an IP.

you see in log that there are 20 seconds between avahi-autoipd being started and the error ... could you please check with ps or something which command line that avahi-autoipd was run with?

First shows:
114 2205 0.0 0.0 14444 892 ? S 11:27 0:00 avahi-autoipd: [eth0] probing 169.254.3.173
root 2206 0.0 0.0 6024 332 ? Ss 11:27 0:00 avahi-autoipd: [eth0] callout dispatcher

Then:
114 2205 0.0 0.0 14444 896 ? S 11:27 0:00 avahi-autoipd: [eth0] announcing 169.254.3.173
root 2206 0.0 0.0 6024 444 ? Ss 11:27 0:00 avahi-autoipd: [eth0] callout dispatcher

Lastly before going away:
114 2205 0.0 0.0 14444 912 ? S 11:27 0:00 avahi-autoipd: [eth0] bound 169.254.3.173
root 2206 0.0 0.0 6024 444 ? Ss 11:27 0:00 avahi-autoipd: [eth0] callout dispatcher

UID 114 is avahi-autoipd user, not sure why doesn't show that in the ps.

Watched the behavior compared to when i run avahi-autoipd manually, and it's the same (except it doesn't stop). Also watching eth0:avahi, it never gets an IP with network manager, but does when ran manually

most likely thats the problem. what id does avahi-autoipd have in /etc/passwd? for me its not 114.

$ cat /etc/passwd | grep avahi
avahi:x:104:112:Avahi mDNS daemon,,,:/var/run/avahi-daemon:/bin/false
avahi-autoipd:x:114:127:Avahi autoip daemon,,,:/var/lib/avahi-autoipd:/bin/false

Was the first thing I checked, only 'ps' is reporting it like that. Other tools like top, htop, and gnome system monitor all correctly show the right user instead of just the UID

$ cat /etc/passwd | grep avahi
avahi-autoipd:x:103:111:Avahi autoip daemon,,,:/var/lib/avahi-autoipd:/bin/false
avahi:x:105:114:Avahi mDNS daemon,,,:/var/run/avahi-daemon:/bin/false

different UID here but that's not the case

NetworkManager is waiting for some signal from avahi-autoipd and it doesn't get it.
My network consists of two linux hosts connected via crossover cable - both running avahi-autoipd.

please put this file in /etc/dbus-1/system.d/ and run sudo /etc/init.d/dbus reload and see if that helps.

ok i fixed this in the 0.7 packaging head.

waiting with fix landing on stable package branch for configuration that this is enough.

This helped a little ( avahi-autoipd doesn't timeout ) but something is calling UNBIND on this interface - log below:

Nov 2 23:42:14 viper NetworkManager: <info> Activation (eth0) starting connection 'avahi'
Nov 2 23:42:14 viper NetworkManager: <info> (eth0): device state change: 3 -> 4
Nov 2 23:42:14 viper NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled...
Nov 2 23:42:14 viper NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started...
Nov 2 23:42:14 viper NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled...
Nov 2 23:42:14 viper NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete.
Nov 2 23:42:14 viper NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting...
Nov 2 23:42:14 viper NetworkManager: <info> (eth0): device state change: 4 -> 5
Nov 2 23:42:14 viper NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful.
Nov 2 23:42:14 viper NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled.
Nov 2 23:42:14 viper NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete.
Nov 2 23:42:14 viper NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started...
Nov 2 23:42:14 viper NetworkManager: <info> (eth0): device state change: 5 -> 7
Nov 2 23:42:14 viper NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started avahi-autoipd...
Nov 2 23:42:14 viper NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete.
Nov 2 23:42:19 viper NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) scheduled...
Nov 2 23:42:19 viper NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) started...
Nov 2 23:42:19 viper NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled...
Nov 2 23:42:19 viper NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Get) complete.
Nov 2 23:42:19 viper NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) started...
Nov 2 23:42:19 viper avahi-daemon[6884]: Joining mDNS multicast group on interface eth0.IPv4 with address 169.254.0.69.
Nov 2 23:42:19 viper avahi-daemon[6884]: New relevant interface eth0.IPv4 for mDNS.
Nov 2 23:42:19 viper avahi-daemon[6884]: Registering new address record for 169.254.0.69 on eth0.IPv4.
Nov 2 23:42:20 viper NetworkManager: <info> (wlan0): writing resolv.conf to /sbin/resolvconf
Nov 2 23:42:20 viper NetworkManager: <info> Policy set 'Auto tomato' (wlan0) as default for routing and DNS.
Nov 2 23:42:20 viper NetworkManager: <info> (eth0): device state change: 7 -> 8
Nov 2 23:42:20 viper NetworkManager: <info> Activation (eth0) successful, device activated.
Nov 2 23:42:20 viper NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete.
Nov 2 23:42:20 viper NetworkManager: <WARN> nm_device_handle_autoip4_event(): eth0: autoip address 169.254.0.69 no longer valid because 'UNBIND'.
Nov 2 23:42:20 viper Netwo...

It looks like that indeed did the trick. Thanks!

Rafal, i guess its because you are using resolvconf ... it most likely runs a avahi hook. /etc/resolvconf/update-libc.d/avahi-daemon should do nothing when run from networkmanager. file a bug against resolvconf or avahi-daemon or whatever for that issue, but let us know about the bug id.

anyway, the fix seems so be good. will pull it into the first SRU round.

upload SRU: network-manager_0.7~~svn20081018t105859-0ubuntu1.8.10.1_source.changes to ubuntu/intrepid-proposed

This bug was fixed in the package network-manager - 0.7~~svn20081018t105859-0ubuntu2

---------------
network-manager (0.7~~svn20081018t105859-0ubuntu2) jaunty; urgency=low

  * fix LP: #292054 - Some drivers take too long to associate (Was:
    network-manager 0.7 always asks for WPA passphrase); we workaround
    this driver/wpasupplicant bug by giving association more time
    (e.g. 60sec instead of 25sec)
    - add debian/patches/lp292054_tune_supplicant_timeout_60s.patch
    - update debian/patches/series
  * fix LP: #256905 - dbus policy file (nm-avahi-autoipd.conf) not properly
    deployed in package; install nm-avahi-autoipd.conf
    - update debian/network-manager.install
  * fix LP: #282207 - [Sierra] NM 0.7 does not set APN for AT&T 3G connection;
    apply fix from Jerone Young
    - add debian/patches/lp282207_set_apn_at_syntax.patch
    - update debian/patches/series
  * fix LP: #268667 - not all required ppp options get set on command line
    which makes ppp use bad values from /etc/ppp/options; we backport upstream
    fix
    - add debian/patches/lp268667_more_ppp_default_options.patch
    - update debian/patches/series
  * fix LP: #291564 - ifupdown network manager does not blacklist/unmanage
    mapped devices in managed=false mode; thanks to Stephan Trebels for the
    patch
    - add debian/patches/lp291564_ifupdown_unmanage_mapping_and_iface.patch
    - update debian/patches/series
  * fix LP: #291902 - ifupdown plugin should not export any parsed connection
    configuration when running in managed=false mode; we fix this by exporting
    empty connection list in unmanaged mode
    - add debian/patches/lp291902_IFUPDOWN_dont_export_connection_in_unmanaged_mode.patch
    - update debian/patches/series
  * belt-and-braces fix LP: #290468 VPN fails, "/usr/bin/nm-ppp-starter
    missing"; we remove obsolete conffiles in -pptp .preinst; in case user
    modified them they will be renamed to .dpkg-bak; this patch takes care that
    NM doesn't consider files in /etc/NetworkManager/VPN that don't have a
    .name filename suffix.
    - add debian/patches/lp290468_only_consider_name_suffix_VPN_service_files.patch
    - update debian/patches/series
  * fix LP: #303142 - 3G [Option] some modems take a while time to register on
    network (CREG); we use g_timeout_add instead of _idle_add to give the
    modem some rest during registration phase.
    - add debian/patches/lp303142_more_time_for_automatic_registration.patch
    - update debian/patches/series

 -- Alexander Sack <email address hidden> Fri, 28 Nov 2008 13:47:07 +0100

Accepted network-manager into intrepid-proposed, please test and give feedback here. Please see https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you in advance!

On Fri, Nov 28, 2008 at 01:43:26PM -0000, Martin Pitt wrote:
> Accepted network-manager into intrepid-proposed, please test and give
> feedback here. Please see https://wiki.ubuntu.com/Testing/EnableProposed
> for documentation how to enable and use -proposed. Thank you in advance!
>
> ** Changed in: network-manager (Ubuntu Intrepid)
> Status: In Progress => Fix Committed
> Target: intrepid-updates => None
>
> ** Tags added: verification-needed
>

I think we already got positive feedback for the PPA package. But
still, could someone please verify that this package still works?

 - Alexander

I had been using the -proposed version for several days in multiple wifi environments (at home and three different conference/hotel places), worked fine.

This bug was fixed in the package network-manager - 0.7~~svn20081018t105859-0ubuntu1.8.10.1

---------------
network-manager (0.7~~svn20081018t105859-0ubuntu1.8.10.1) intrepid-proposed; urgency=low

  * fix LP: #292054 - Some drivers take too long to associate (Was:
    network-manager 0.7 always asks for WPA passphrase); we workaround
    this driver/wpasupplicant bug by giving association more time
    (e.g. 60sec instead of 25sec)
    - add debian/patches/lp292054_tune_supplicant_timeout_60s.patch
    - update debian/patches/series
  * fix LP: #256905 - dbus policy file (nm-avahi-autoipd.conf) not properly
    deployed in package; install nm-avahi-autoipd.conf
    - update debian/network-manager.install
  * fix LP: #282207 - [Sierra] NM 0.7 does not set APN for AT&T 3G connection;
    apply fix from Jerone Young
    - add debian/patches/lp282207_set_apn_at_syntax.patch
    - update debian/patches/series
  * fix LP: #268667 - not all required ppp options get set on command line
    which makes ppp use bad values from /etc/ppp/options; we backport upstream
    fix
    - add debian/patches/lp268667_more_ppp_default_options.patch
    - update debian/patches/series
  * fix LP: #291564 - ifupdown network manager does not blacklist/unmanage
    mapped devices in managed=false mode; thanks to Stephan Trebels for the
    patch
    - add debian/patches/lp291564_ifupdown_unmanage_mapping_and_iface.patch
    - update debian/patches/series
  * fix LP: #291902 - ifupdown plugin should not export any parsed connection
    configuration when running in managed=false mode; we fix this by exporting
    empty connection list in unmanaged mode
    - add debian/patches/lp291902_IFUPDOWN_dont_export_connection_in_unmanaged_mode.patch
    - update debian/patches/series
  * belt-and-braces fix LP: #290468 VPN fails, "/usr/bin/nm-ppp-starter
    missing"; we remove obsolete conffiles in -pptp .preinst; in case user
    modified them they will be renamed to .dpkg-bak; this patch takes care that
    NM doesn't consider files in /etc/NetworkManager/VPN that don't have a
    .name filename suffix.
    - add debian/patches/lp290468_only_consider_name_suffix_VPN_service_files.patch
    - update debian/patches/series
  * fix LP: #303142 - 3G [Option] some modems take a while time to register on
    network (CREG); we use g_timeout_add instead of _idle_add to give the
    modem some rest during registration phase.
    - add debian/patches/lp303142_more_time_for_automatic_registration.patch
    - update debian/patches/series

 -- Alexander Sack <email address hidden> Fri, 28 Nov 2008 13:48:34 +0100