Dear Maintainer,

After upgrading to Debian Bullseye, I noticed that the Avahi CPU usage on my server machine was
quite high (eventually 100% of one core). After resetting Avahi, the CPU usage was normal then
eventually increased over time again until it was again rather high. The
increase appears to be (very roughly) 1 or 2% per hour on my rather humble Intel(R) Celeron(R)
CPU 4205U @ 1.80GHz.

Checking the journal, I only see the following sorts of lines:

Aug 25 16:21:30 zeta avahi-daemon[313333]: avahi_normalize_name() failed.
Aug 25 16:21:30 zeta avahi-daemon[313333]: avahi_key_new() failed.
Aug 25 16:21:30 zeta avahi-daemon[313333]: avahi_normalize_name() failed.
Aug 25 16:21:30 zeta avahi-daemon[313333]: avahi_key_new() failed.
Aug 25 16:21:31 zeta avahi-daemon[313333]: avahi_normalize_name() failed.
Aug 25 16:21:31 zeta avahi-daemon[313333]: avahi_key_new() failed.

Which was around the time I turned on another machine on my network.
However, the timing was not aligned with when Avahi CPU usage increased.
Instead, it seems to be aligned with when I turn on my printer, but nothing
of note was printed in the log when that happened.

Is there any means for me to gather additional information to help
diagnose this problem?

Thanks,
Ryan

If it is useful, here are two screenshots of netdata. "First instance
and reset" shows the CPU usage when unchecked, then reset to zero by
restarting Avahi. "later instance starting" shows flat/low CPU usage of
avahi, then a continual increase starting at 6:30 am when I had turned
on my printer.

Ryan

I edited my Avahi service to add the --debug flag to see if added
anything useful. It doesn't seem so, but here it is regardless. I've
attached both the full log (gzipped) and an annotated and simplified log.

I may try and attach to the process with GDB in the future to trace what
part of the code it is primarily working in.

Ryan

I have made an attempt at profiling where the avahi-daemon is getting
stuck. Hopefully this is useful to someone. I downloaded the source
package for avahi-daemon, then rebuilt it and installed the resulting
debug packages. After waiting for the CPU usage to reach around 70% or
so, I attempted to profile where it is executing.

My initial attempt at running `perf record -p 514 -g` failed; when
running `perf report` after, the report was fully blank. As a result, I
decided to go back to my original plan and just break a few times in gdb
to see where it stopped. See the attached log for a full log of that
session. It seemed to be usually in one of two places:

#0  0x00007ff359801fb0 in find_next_timeout (s=<optimized out>) at
simple-watch.c:431
#1  0x00007ff3598027ea in avahi_simple_poll_prepare
(s=s@entry=0x558f0b1e5ff0, timeout=timeout@entry=-1) at simple-watch.c:481
#2  0x00007ff359802c69 in avahi_simple_poll_iterate (s=0x558f0b1e5ff0,
timeout=timeout@entry=-1) at simple-watch.c:599
#3  0x0000558f09c929ee in run_server (c=0x558f09cb01e0 <config>) at
main.c:1268
#4  main (argc=<optimized out>, argv=<optimized out>) at main.c:1686

or

#0  0x00007ff35962d3c3 in __GI___poll (fds=0x558f0b1eec90, nfds=10,
timeout=2209504) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x00007ff359802aa1 in avahi_simple_poll_run (s=0x558f0b1e5ff0) at
simple-watch.c:527
#2  avahi_simple_poll_run (s=0x558f0b1e5ff0) at simple-watch.c:518
#3  0x00007ff359802c78 in avahi_simple_poll_iterate (s=0x558f0b1e5ff0,
timeout=timeout@entry=-1) at simple-watch.c:602
#4  0x0000558f09c929ee in run_server (c=0x558f09cb01e0 <config>) at
main.c:1268
#5  main (argc=<optimized out>, argv=<optimized out>) at main.c:1686

Ryan

I have the exact same problem for quite some time already (certainly 6
months, likely more), using Debian sid.

I'm surprised that this bug report is the only mention of the issue I could
find on the net. It's reproducible every time I switch on my printer, but
it takes quite some hours, in the order of a few days, before it turns into
a significant problem. Running `sudo avahi-daemon -k` kills the process and
a new one is started, which behaves well until I switch on my printer.

It looks like Ryan already did what I was planning to do, i.e. debug
through the daemon and do some Monte Carlo profiling. If there is anything
I can do to help triage the problem, please let me know. For now I can only
share details of my home setup that may or may not be helpful: the printer
is an HP Deskjet-3630; DNS is handled by a FritzBox! but I believe the
issue also showed up while I was using my home grown dnsmasq server.

Best,

Andreas

Hey,

I noticed this problem a while ago and did some investigation
yesterday. perf showed find_next_timeout as the culprit indeed, and gdb
helped me realize the timeout linked list was just growing infinitely
large...

Here's the fix: https://github.com/lathiat/avahi/pull/366

Cheers,

Gustavo

I've looked at the atop logs since the machine got rebooted.
The CPU usage actually increases during the first 24 hours
to reach about 100%:
  00:30  1%
  00:40  2%
  01:00  3%
  01:10  4%
  01:20  5%
  02:00  6%
  03:00  8%
  04:00 11%
  05:00  9%
  06:00 11%
  07:00 12%
  08:00 14%
  09:00 10%
  10:00 10%
  11:00 12%
  12:00 16%
  13:00 17%
  14:00 18%
  15:00 20%
  16:00 21%
  17:00 24%
  18:00 29%
  19:00 38%
  20:00 42%
  21:00 49%
  21:30 59%
  22:00 68%
  22:30 86%
  23:00 93%
  24:00 96%

So bug 922630 looks like the same bug as bug 993051.

I've been running with the patch linked to by Gustavo Noronha Silva
<kov@debian.org> for a few days now, and for me it seems to have solved
this problem.  I'd suggest patching Debian's version until upstream
makes a release including this fix.

Hi there,

On at least 3 different computer I hit this bug.

Do anyone made a patched .deb or is there any notion that there could be
an updated package anytime soon?

(or any alternative software suggest)


Regards,

Am 05.06.22 um 17:10 schrieb Mathieu ROY:

I don't see anyone having provided a patch for this issue.

My recommendation would be to file this issue upstream at
https://github.com/lathiat/avahi/issues

Upstream can probably help you with debugging this issue.
Once a fix/patch is available, we can cherry-pick that in the Debian
package.

Michael

We believe that the bug you reported is fixed in the latest version of
avahi, which is due to be installed in the Debian FTP archive.

A summary of the changes between this version and the previous one is
attached.

Thank you for reporting the bug, which will now be closed.  If you
have further comments please address them to 993051@bugs.debian.org,
and the maintainer will reopen the bug report if appropriate.

Debian distribution maintenance software
pp.
Michael Biebl <biebl@debian.org> (supplier of updated avahi package)

(This message was generated automatically at their request; if you
believe that there is a problem with it please contact the archive
administrators by mailing ftpmaster@ftp-master.debian.org)
Format: 1.8
Date: Sun, 05 Jun 2022 18:33:10 +0200
Source: avahi
Built-For-Profiles: nocheck
Architecture: source
Version: 0.8-6
Distribution: unstable
Urgency: medium
Maintainer: Utopia Maintenance Team <pkg-utopia-maintainers@lists.alioth.debian.org>
Changed-By: Michael Biebl <biebl@debian.org>
Closes: 986018 993051
Changes:
 avahi (0.8-6) unstable; urgency=medium
 .
   [ Luca Boccassi ]
   * avahi-daemon: depend on default-dbus-system-bus | dbus-system-bus.
     This allows the reference implementation to be removed if using a
     different system bus implementation such as dbus-broker.
     [smcv: Adjust commit message]
 .
   [ Simon McVittie ]
   * Add patch to fix display of URLs containing '&' in avahi-discover
   * Standards-Version: 4.6.0 (no changes required)
   * Use recommended debhelper compat level 13
 .
   [ Michael Biebl ]
   * Do not disable timeout cleanup on watch cleanup.
     This was causing timeouts to never be removed from the linked list that
     tracks them, resulting in both memory and CPU usage to grow larger over
     time. Thanks to Gustavo Noronha Silva (Closes: #993051)
   * Drop obsolete lsb-base Depends
   * Fix NULL pointer crashes when trying to resolve badly-formatted hostnames.
     Fixes a local DoS in avahi-daemon that can be triggered by trying to
     resolve badly-formatted hostnames on the /run/avahi-daemon/socket
     interface. (CVE-2021-3502, Closes: #986018)
Checksums-Sha1:
 a1a2d27cfb3eba3436d7e527410be1b0676d5ebd 3949 avahi_0.8-6.dsc
 1b99269af00046da5d95a60df770111677f6896c 36560 avahi_0.8-6.debian.tar.xz
 cae15711c51bf081910c7a2ec4aecb41baa274b8 7365 avahi_0.8-6_source.buildinfo
Checksums-Sha256:
 587a204d0197d95457837fffb05864625d9c4a727c3170de693fb49d4bfaff00 3949 avahi_0.8-6.dsc
 9dde4f73aecb8e39e63e0de282699775c8f031dd779c08f044c7701fa575a094 36560 avahi_0.8-6.debian.tar.xz
 be50e3814d92cc2a322fb464c0997d5f951cb2fca5c0159b354aecee2ea85724 7365 avahi_0.8-6_source.buildinfo
Files:
 90285f50f4577efea0b571cec5ed0ab8 3949 net optional avahi_0.8-6.dsc
 6ffde0887d6db76dc22787b54ae34af5 36560 net optional avahi_0.8-6.debian.tar.xz
 7c1f872b61f459b733063e0488d8ee5a 7365 net optional avahi_0.8-6_source.buildinfo
-----BEGIN PGP SIGNATURE-----

iQIzBAEBCAAdFiEECbOsLssWnJBDRcxUauHfDWCPItwFAmKc3xYACgkQauHfDWCP
Itz0EBAAlvDo8f+7ZOsWqNSqh3UVObQ6kBi3lnsjxa6XH4+CQc7Sd4iO42N+TAg3
u5ZWwlAL8mDa8B5UUwnM6pnhG2nLfXbBlxS33MeTnFRRPSqGfl6X7lo7A9LBFhZ/
gOyI++Lrnmu5bc923WO82Tv63eTAf4egVz6Y4k65WWP2EwTeARMv1HkEe9TgNg+1
xPTBQVjuCssvqOZn+Tj/1ZQsTCKpCWJcdu1OIqcDojp9Blm4ANVfQ0IdpyXz8IGK
UUBPf1o5acqnaTQE2gO6iWIm36sJJ8mHpur+r0H5biJrUbXDbOXspTJPvFbv4nxr
hrj5iTFqBqoQocH0u0BaC3RL4Vtu1yjwxC786hSmaEDRScpVtUAnD3e0j3gZkTM/
0tfnCje/P5zOGruy34/H9qO97BNdZPhFWGmN/vuky7F1tVC8c6mky1lULh9o0cVR
VKBgkj8bBk3ePeRjQ7v4YOOfsxP5bfJMNjv3sBGmiJ6cP5BIfUQIDktpGf1BsA5F
idzGPl8Dk287gfPebhWCmoVg6xg1TgdLY4IRTwCaokZ6dk4R6FjYRgpkFOEsPuD0
BbCrrWaPABkBeqe8unlJVbla4rXAJdPG4CPPnHcXuGF54dytPJVUP2pLm0pcc41s
11BjLleF+MAYKpVxSgWIKyGyZBE+CrO8x0LuCo8t6KJ4sfUb5ME=
=OZO7
-----END PGP SIGNATURE-----

Hello,

Bug #993051 in avahi reported by you has been fixed in the
Git repository and is awaiting an upload. You can see the commit
message below and you can check the diff of the fix at:

https://salsa.debian.org/utopia-team/avahi/-/commit/cf97e08b52cd2194c4f7a516c3929ea79d39696a
------------------------------------------------------------------------
Do not disable timeout cleanup on watch cleanup

This was causing timeouts to never be removed from the linked list that
tracks them, resulting in both memory and CPU usage to grow larger over
time.

Closes: #993051
Thanks: Gustavo Noronha Silva
------------------------------------------------------------------------

(this message was generated automatically)
-- 
Greetings

https://bugs.debian.org/993051