avahi-daemon high cpu, unusable networking

Hi Matt,

Thanks for the report. I'd like to profile avahi using perf to get information on what functions are being executed. Could you run the following commands to generate such data?

If you are unsure about any of this feel free to ask.

echo "deb http://ddebs.ubuntu.com $(lsb_release -cs) main restricted universe multiverse" | sudo tee -a /etc/apt/sources.list.d/ddebs.list
sudo apt update
sudo apt install linux-tools-generic ubuntu-dbgsym-keyring linux-cloud-tools-generic
sudo apt update
sudo apt install avahi-daemon-dbgsym libavahi-common3-dbgsym libavahi-core7-dbgsym libavahi-glib1-dbgsym libc6-dbgsym libcap2-dbgsym libdaemon0-dbgsym libdbus-1-3-dbgsym libecore-avahi1-dbgsym libexpat1-dbgsym libgcrypt20-dbgsym libgpg-error0-dbgsym liblz4-1-dbgsym liblzma5-dbgsym libnss-systemd-dbgsym libsystemd0-dbgsym

then to record a profile:

sudo perf record -p $(cat /run/avahi-daemon/pid) -g -- sleep 60

This will exit after 60 seconds, then generate perf script output:

sudo perf script > avahi-perf.script.txt
sudo perf report -n --stdio > avahi-perf.report.txt

And then upload the resulting avahi-perf.script.txt and avahi-perf.report.txt for analysis.

You'll want to make sure avahi is using 100%+ CPU at the time you do this.

Lastly from the same bootup, can you please collect the log info from journalctl:
journalctl -u avahi-daemon --no-pager --no-tail > avahi-journal.txt

Thanks for reporting the bug! Hopefully we can figure it out.

In the mean time if you want to disable avahi you can try this:
sudo systemctl disable avahi-daemon.socket avahi-daemon
sudo systemctl stop avahi-daemon.socket avahi-daemon

(to re-enable change to start and enable)

Regards,
Trent

Ok, the issue seems gone! I cannot recreate it, and I'm not sure why.

First, thank you for the quick reply. When I first read your response, I ran the

`echo "deb http://ddebs.ubuntu.com $(lsb_release -cs) main restricted universe multiverse" | sudo tee -a /etc/apt/sources.list.d/ddebs.list`

command, and then realized the CPU wasn't being maximally taxed so I didn't continue and decided to try again later. I then ran the disable and stop commands to get rid of the issue temporarily.

I later decided to try to recreate the issue, so I ran the corresponding enable and start commands, and the CPU didn't increase. I then restarted my system a couple times, but have yet to see the high CPU and bad networking issues. I can confirm that the avahi-daemon is indeed running. Running `ps aux | grep avahi` yields,

avahi 915 0.0 0.0 18920 3868 ? Ss 23:46 0:00 avahi-daemon: running [tomboy.local]
avahi 1035 0.0 0.0 18716 348 ? S 23:46 0:00 avahi-daemon: chroot helper

Since my initial post I have performed a couple normal package updates, so perhaps one of them solved the issue? The Kubuntu 18.10 I am on is a new release, so perhaps something was discovered and fixed.

Ok, ignore previous post. My laptop was sitting unused and suddenly I hear the fans spin up (which they almost never do). Sure enough, the avahi-daemon was running up a full cpu core. I've attached the logs.

Thanks for looking into it.

Ok, ignore previous post. My laptop was sitting unused and suddenly I hear the fans spin up (which they almost never do). Sure enough, the avahi-daemon was running up a full cpu core. I've attached the logs.

Thanks for looking into it.

Ok, ignore previous post. My laptop was sitting unused and suddenly I hear the fans spin up (which they almost never do). Sure enough, the avahi-daemon was running up a full cpu core. I've attached the logs.

Thanks for looking into it.

A similar bug happened here on 2 different Ubuntu installs once they upgraded to Ubuntu 18.10.

Another symptom of the bug was periodic addition of IPv6 addresses to the `ip addr` listing. If you wait a while, the list had thousands of IPv6 entries in it!

Apparently every time it decided to fetch new IPv6 addresses it also did a RST on all the IPv4 connections, which is why webpages fail to load a lot of the time.

Once I completely disabled IPv6 support on my machine via:

/etc/sysctl.d/99-sysctl.conf:net.ipv6.conf.all.disable_ipv6 = 1
/etc/sysctl.d/99-sysctl.conf:net.ipv6.conf.default.disable_ipv6 = 1
/etc/sysctl.d/99-sysctl.conf:net.ipv6.conf.lo.disable_ipv6 = 1

The problem went away.

So I don't know what the exact problem is -- but this narrows it down.

Same problem with high CPU, but I'm not able to disable ipv6 (ipv6 network). avahi-daemon is almost always at first place by CPU usage.

Hi, I'm hitting this quite consistently on Pop!_OS 19.04 in Virtualbox (Windows 10 host) on Lenovo T460.

Essentially, the CPU usage goes up to 100% for avahi-daemon, and the strace shows it stuck in a loop, reading/writing to a named pipe, like so:

poll([{fd=6, events=POLLIN}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=12, events=POLLIN}, {fd=11, events=POLLIN}, {fd=10, events=POLLIN}, {fd=3, events=POLLIN}, {fd=8, events=POLLIN}], 8, 0) = 3 ([{fd=14, revents=POLLIN|POLLERR}, {fd=12, revents=POLLIN}, {fd=10, revents=POLLIN}])
write(7, "W", 1) = 1
write(7, "W", 1) = 1
read(6, "WW", 10) = 2
poll([{fd=6, events=POLLIN}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=12, events=POLLIN}, {fd=11, events=POLLIN}, {fd=10, events=POLLIN}, {fd=3, events=POLLIN}, {fd=8, events=POLLIN}], 8, 0) = 3 ([{fd=14, revents=POLLIN|POLLERR}, {fd=12, revents=POLLIN}, {fd=10, revents=POLLIN}])
write(7, "W", 1) = 1
write(7, "W", 1) = 1
write(7, "W", 1) = 1
write(7, "W", 1) = 1
read(6, "WWWW", 10) = 4
poll([{fd=6, events=POLLIN}, {fd=14, events=POLLIN}, {fd=13, events=POLLIN}, {fd=12, events=POLLIN}, {fd=11, events=POLLIN}, {fd=10, events=POLLIN}, {fd=3, events=POLLIN}, {fd=8, events=POLLIN}], 8, 0) = 3 ([{fd=14, revents=POLLIN|POLLERR}, {fd=12, revents=POLLIN}, {fd=10, revents=POLLIN}])
^Cstrace: Process 782 detached

root@pop-os:/# ls -ltr /proc/782/fd
total 0
lrwx------ 1 root root 64 Sep 25 13:03 14 -> 'socket:[20288]'
lrwx------ 1 root root 64 Sep 25 13:03 13 -> 'socket:[20287]'
lrwx------ 1 root root 64 Sep 25 13:03 12 -> 'socket:[20286]'
lr-x------ 1 root root 64 Sep 25 13:03 11 -> anon_inode:inotify
lrwx------ 1 root root 64 Sep 25 13:03 10 -> 'socket:[20154]'
l-wx------ 1 root root 64 Sep 25 13:03 9 -> 'pipe:[20153]'
lr-x------ 1 root root 64 Sep 25 13:03 8 -> 'pipe:[20153]'
l-wx------ 1 root root 64 Sep 25 13:03 7 -> 'pipe:[20152]'
lr-x------ 1 root root 64 Sep 25 13:03 6 -> 'pipe:[20152]'
lrwx------ 1 root root 64 Sep 25 13:03 5 -> 'socket:[20141]'
lrwx------ 1 root root 64 Sep 25 13:03 4 -> 'socket:[19687]'
lrwx------ 1 root root 64 Sep 25 13:03 3 -> 'socket:[17872]'
lrwx------ 1 root root 64 Sep 25 13:03 2 -> 'socket:[19192]'
lrwx------ 1 root root 64 Sep 25 13:03 1 -> 'socket:[19192]'
lr-x------ 1 root root 64 Sep 25 13:03 0 -> /dev/null
root@pop-os:/#

My avahi config is:

    ## /etc/avah/avahi-daemon.conf
    [server]
    use-ipv4=yes
    use-ipv6=no

    ratelimit-interval-usec=1000000
    ratelimit-burst=1000

    [wide-area]
    enable-wide-area=yes

    [publish]
    publish-hinfo=no
    publish-workstation=no

    [reflector]
    [rlimits]

The journal log is overgrown with messages like so: (I've replaced parts of the ipv6 addresses with XXXX)
Sep 25 10:34:11 pop-os avahi-daemon[782]: Registering new address record for 2606:b400:818:64:485e:XXXX:XXXX:XXXX on enp0s8.*.
Sep 25 10:34:11 pop-os avahi-daemon[782]: Registering new address record for 2606:b400:818:64:28d5:XXXX:XXXX:XXXX on enp0s8.*.
Sep 25 10:34:11 pop-os avahi-daemon[782]: Registering ne...

Also, startlingly, I seem to have thousands of ipv6 addresses assigned to enp0s8:

ip addr
3: enp0s8: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group default qlen 1000
    link/ether 08:00:27:47:xx:xx brd ff:ff:ff:ff:ff:ff
    inet 10.169.110.168/21 brd 10.169.111.255 scope global dynamic noprefixroute enp0s8
       valid_lft 6027sec preferred_lft 6027sec
    inet6 2606:b400:818:61:c70:xxxx:xxxx:xxxx/64 scope global temporary dynamic
       valid_lft 604796sec preferred_lft 86280sec
    inet6 2606:b400:818:61:eece:xxxx:xxxx:xxxx/64 scope global dynamic mngtmpaddr noprefixroute
       valid_lft 2591939sec preferred_lft 604739sec
    inet6 2606:b400:818:64:c70:xxxx:xxxx:xxxx/64 scope global temporary dynamic
       valid_lft 604796sec preferred_lft 86280sec
    inet6 2606:b400:818:64:6745:xxxx:xxxx:xxxx/64 scope global dynamic mngtmpaddr noprefixroute
       valid_lft 2591996sec preferred_lft 604796sec
    inet6 2606:b400:818:64:d7:xxxx:xxxx:xxxx0/64 scope global temporary dynamic
       valid_lft 604740sec preferred_lft 86224sec
    ....
    ....

# ip addr | grep inet6 | cat -n

  6294 inet6 2606:b400:818:64:XXXX:XXXX:XXXX:XXXX/64 scope global temporary deprecated dynamic
  6295 inet6 2606:b400:818:61:XXXX:XXXX:XXXX:XXXX/64 scope global temporary deprecated dynamic
  6296 inet6 2606:b400:818:61:XXXX:XXXX:XXXX:XXXX/64 scope global temporary deprecated dynamic
  6297 inet6 2606:b400:818:64:XXXX:XXXX:XXXX:XXXX/64 scope global temporary deprecated dynamic
  6298 inet6 2606:b400:818:64:XXXX:XXXX:XXXX:XXXX/64 scope global temporary deprecated dynamic
  6299 inet6 2606:b400:818:61:XXXX:XXXX:XXXX:XXXXc/64 scope global temporary deprecated dynamic
  6300 inet6 2606:b400:818:61:XXXX:XXXX:XXXX:XXXX/64 scope global temporary deprecated dynamic
  6301 inet6 2606:b400:818:64:XXXX:XXXX:XXXX:XXXX/64 scope global temporary deprecated dynamic
  6302 inet6 2606:b400:818:64:XXXX:XXXX:XXXX:XXXX/64 scope global temporary deprecated dynamic
  6303 inet6 2606:b400:818:61:XXXX:XXXX:XXXX:XXXX/64 scope global temporary deprecated dynamic
  6304 inet6 fe80::4721:XXXX:XXXX:XXXX/64 scope link noprefixroute

I'm seeing exactly the same issue on Ubuntu 19.04

That's with avahi-daemon 0.7-4ubuntu5

Hi,

I'm wondering if the fix for this is https://github.com/lathiat/avahi/pull/366 and whether or not that fix can be SRU'd into Jammy, which uses avahi 0.8-5ubuntu5.1 ?

That patch was already pulled in to 0.8-6 (https://salsa.debian.org/utopia-team/avahi/-/commit/cf97e08b52cd2194c4f7a516c3929ea79d39696a) which is included in Kinetic+.

Thanks for considering this :)