Bug#929010: [Pkg-utopia-maintainers] Bug#929010: avahi-daemon: /etc/network/if-post-down.d/avahi-daemon is slow on eth0

[Vincent Lefevre]

On 2019-05-16 16:09:04 +0200, Vincent Lefevre wrote:
> On 2019-05-16 15:59:09 +0200, Vincent Lefevre wrote:
> > On 2019-05-16 14:41:44 +0200, Michael Biebl wrote:
> > > Am 16.05.19 um 14:22 schrieb Vincent Lefevre:
> > > > On 2019-05-16 14:15:37 +0200, Michael Biebl wrote:
> > > >> Looks like you have a local resolver configured in /etc/resolv.conf
> > > >> (which should be reachable via lo, even if eth0 is down).
> > > > 
> > > > Yes, /etc/resolv.conf contains
> > > > 
> > > > nameserver 127.0.0.1
> > > > nameserver 192.168.1.1
> > > > 
> > > > as I use "unbound".
> > > 
> > > So host talks to unbound, which apparently takes those 12s to answer.
> > > Not sure what can be done about this in avahi-daemon. Ideas?
> > 
> > Should this be regarded as a bug in unbound, then?
> 
> Actually, no, unbound is not the problem:
> 
> Whether I have
> 
> nameserver 127.0.0.1
> nameserver 192.168.1.1
> 
> or just
> 
> nameserver 192.168.1.1
> 
> in /etc/resolv.conf, "time host -t soa local." shows a 10-second
> timeout.
> 
> Or would the old /etc/resolv.conf (with 127.0.0.1) be cached somewhere
> on the system?

According to strace (see attached output), even though /etc/resolv.conf
is read, there is a connection to 127.0.0.1, though this may not be
related. But... unbound is still not the issue. The strace output shows
that it is not 127.0.0.1 (unbound) that times out, but 192.168.1.1.

And indeed, with only

nameserver 127.0.0.1

in /etc/resolv.conf, "host -t soa local." immediately gives

Host local not found: 2(SERVFAIL)

-- 
Vincent Lefèvre  - Web: 
100% accessible validated (X)HTML - Blog: 
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)


str1.out.xz
Description: Binary data

Bug#929010: [Pkg-utopia-maintainers] Bug#929010: avahi-daemon: /etc/network/if-post-down.d/avahi-daemon is slow on eth0

[Vincent Lefevre]

On 2019-05-16 15:59:09 +0200, Vincent Lefevre wrote:
> On 2019-05-16 14:41:44 +0200, Michael Biebl wrote:
> > Am 16.05.19 um 14:22 schrieb Vincent Lefevre:
> > > On 2019-05-16 14:15:37 +0200, Michael Biebl wrote:
> > >> Looks like you have a local resolver configured in /etc/resolv.conf
> > >> (which should be reachable via lo, even if eth0 is down).
> > > 
> > > Yes, /etc/resolv.conf contains
> > > 
> > > nameserver 127.0.0.1
> > > nameserver 192.168.1.1
> > > 
> > > as I use "unbound".
> > 
> > So host talks to unbound, which apparently takes those 12s to answer.
> > Not sure what can be done about this in avahi-daemon. Ideas?
> 
> Should this be regarded as a bug in unbound, then?

Actually, no, unbound is not the problem:

Whether I have

nameserver 127.0.0.1
nameserver 192.168.1.1

or just

nameserver 192.168.1.1

in /etc/resolv.conf, "time host -t soa local." shows a 10-second
timeout.

Or would the old /etc/resolv.conf (with 127.0.0.1) be cached somewhere
on the system?

-- 
Vincent Lefèvre  - Web: 
100% accessible validated (X)HTML - Blog: 
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)

Bug#929010: [Pkg-utopia-maintainers] Bug#929010: avahi-daemon: /etc/network/if-post-down.d/avahi-daemon is slow on eth0

[Vincent Lefevre]

On 2019-05-16 14:41:44 +0200, Michael Biebl wrote:
> Am 16.05.19 um 14:22 schrieb Vincent Lefevre:
> > On 2019-05-16 14:15:37 +0200, Michael Biebl wrote:
> >> Looks like you have a local resolver configured in /etc/resolv.conf
> >> (which should be reachable via lo, even if eth0 is down).
> > 
> > Yes, /etc/resolv.conf contains
> > 
> > nameserver 127.0.0.1
> > nameserver 192.168.1.1
> > 
> > as I use "unbound".
> 
> So host talks to unbound, which apparently takes those 12s to answer.
> Not sure what can be done about this in avahi-daemon. Ideas?

Should this be regarded as a bug in unbound, then?

-- 
Vincent Lefèvre  - Web: 
100% accessible validated (X)HTML - Blog: 
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)

Bug#929010: [Pkg-utopia-maintainers] Bug#929010: avahi-daemon: /etc/network/if-post-down.d/avahi-daemon is slow on eth0

[Michael Biebl]

Am 16.05.19 um 14:22 schrieb Vincent Lefevre:
> On 2019-05-16 14:15:37 +0200, Michael Biebl wrote:
>> Looks like you have a local resolver configured in /etc/resolv.conf
>> (which should be reachable via lo, even if eth0 is down).
> 
> Yes, /etc/resolv.conf contains
> 
> nameserver 127.0.0.1
> nameserver 192.168.1.1
> 
> as I use "unbound".

So host talks to unbound, which apparently takes those 12s to answer.
Not sure what can be done about this in avahi-daemon. Ideas?


-- 
Why is it that all of the instruments seeking intelligent life in the
universe are pointed away from Earth?



signature.asc
Description: OpenPGP digital signature

Bug#929010: [Pkg-utopia-maintainers] Bug#929010: avahi-daemon: /etc/network/if-post-down.d/avahi-daemon is slow on eth0

[Vincent Lefevre]

On 2019-05-16 14:15:37 +0200, Michael Biebl wrote:
> Looks like you have a local resolver configured in /etc/resolv.conf
> (which should be reachable via lo, even if eth0 is down).

Yes, /etc/resolv.conf contains

nameserver 127.0.0.1
nameserver 192.168.1.1

as I use "unbound".

-- 
Vincent Lefèvre  - Web: 
100% accessible validated (X)HTML - Blog: 
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)

Bug#929010: [Pkg-utopia-maintainers] Bug#929010: avahi-daemon: /etc/network/if-post-down.d/avahi-daemon is slow on eth0

[Michael Biebl]

Am 16.05.19 um 00:27 schrieb Vincent Lefevre:
> On 2019-05-15 12:50:49 +0200, Michael Biebl wrote:
>> Which part of /usr/lib/avahi/avahi-daemon-check-dns.sh is taking so long?
>> Can you add a "set -x" and then manually invoke "ifdown eth0"
> 
> I get:
> 
> + PATH=/bin:/usr/bin:/sbin:/usr/sbin
> + RUNDIR=/var/run/avahi-daemon/
> + DISABLE_TAG=/var/run/avahi-daemon//disabled-for-unicast-local
> + NS_CACHE=/var/run/avahi-daemon//checked_nameservers
> + AVAHI_DAEMON_DETECT_LOCAL=1
> + test -f /etc/default/avahi-daemon
> + . /etc/default/avahi-daemon
> + AVAHI_DAEMON_DETECT_LOCAL=1
> + [ 1 != 1 ]
> + dns_reachable
> + grep -q nameserver /etc/resolv.conf
> + 
> + egrep -q nameserver 127.0.0.1|::1 /etc/resolv.conf
> + 
> + return 0
> + dns_needs_check
> + TMP_CACHE=/var/run/avahi-daemon//checked_nameservers.8379
> + RET=0
> + ensure_rundir
> + [ ! -d /var/run/avahi-daemon/ ]
> + cat /etc/resolv.conf
> + grep nameserver
> + sort
> + [ -e /var/run/avahi-daemon//checked_nameservers ]
> + mv /var/run/avahi-daemon//checked_nameservers.8379 
> /var/run/avahi-daemon//checked_nameservers
> + return 0
> + dns_has_local
> + [ -n  ]
> + LC_ALL=C host -t soa local.
> + OUT=;; connection timed out; no servers could be reached
> + [ 1 -eq 0 ]
> + rm -f /var/run/avahi-daemon//checked_nameservers
> + return 1
> + enable_avahi
> + [ -e /var/run/avahi-daemon//disabled-for-unicast-local ]
> + exit 0
> 
> with several seconds between
> 
> + LC_ALL=C host -t soa local.
> 
> and
> 
> + OUT=;; connection timed out; no servers could be reached
> 
> At least, this is consistent with the timeout.
> 
> Moreover, I don't understand why it tries to reach servers as eth0
> is down (this is called in an if-post-down.d script).
> 

Looks like you have a local resolver configured in /etc/resolv.conf
(which should be reachable via lo, even if eth0 is down).

-- 
Why is it that all of the instruments seeking intelligent life in the
universe are pointed away from Earth?



signature.asc
Description: OpenPGP digital signature

Bug#929010: [Pkg-utopia-maintainers] Bug#929010: avahi-daemon: /etc/network/if-post-down.d/avahi-daemon is slow on eth0

[Vincent Lefevre]

On 2019-05-15 12:50:49 +0200, Michael Biebl wrote:
> Which part of /usr/lib/avahi/avahi-daemon-check-dns.sh is taking so long?
> Can you add a "set -x" and then manually invoke "ifdown eth0"

I get:

+ PATH=/bin:/usr/bin:/sbin:/usr/sbin
+ RUNDIR=/var/run/avahi-daemon/
+ DISABLE_TAG=/var/run/avahi-daemon//disabled-for-unicast-local
+ NS_CACHE=/var/run/avahi-daemon//checked_nameservers
+ AVAHI_DAEMON_DETECT_LOCAL=1
+ test -f /etc/default/avahi-daemon
+ . /etc/default/avahi-daemon
+ AVAHI_DAEMON_DETECT_LOCAL=1
+ [ 1 != 1 ]
+ dns_reachable
+ grep -q nameserver /etc/resolv.conf
+ 
+ egrep -q nameserver 127.0.0.1|::1 /etc/resolv.conf
+ 
+ return 0
+ dns_needs_check
+ TMP_CACHE=/var/run/avahi-daemon//checked_nameservers.8379
+ RET=0
+ ensure_rundir
+ [ ! -d /var/run/avahi-daemon/ ]
+ cat /etc/resolv.conf
+ grep nameserver
+ sort
+ [ -e /var/run/avahi-daemon//checked_nameservers ]
+ mv /var/run/avahi-daemon//checked_nameservers.8379 
/var/run/avahi-daemon//checked_nameservers
+ return 0
+ dns_has_local
+ [ -n  ]
+ LC_ALL=C host -t soa local.
+ OUT=;; connection timed out; no servers could be reached
+ [ 1 -eq 0 ]
+ rm -f /var/run/avahi-daemon//checked_nameservers
+ return 1
+ enable_avahi
+ [ -e /var/run/avahi-daemon//disabled-for-unicast-local ]
+ exit 0

with several seconds between

+ LC_ALL=C host -t soa local.

and

+ OUT=;; connection timed out; no servers could be reached

At least, this is consistent with the timeout.

Moreover, I don't understand why it tries to reach servers as eth0
is down (this is called in an if-post-down.d script).

-- 
Vincent Lefèvre  - Web: 
100% accessible validated (X)HTML - Blog: 
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)

Bug#929010: [Pkg-utopia-maintainers] Bug#929010: avahi-daemon: /etc/network/if-post-down.d/avahi-daemon is slow on eth0

[Michael Biebl]

Control: tags -1 + moreinfo

Am 15.05.19 um 10:29 schrieb Vincent Lefevre:
> Package: avahi-daemon
> Version: 0.7-4+b1
> Severity: normal
> 
> /etc/network/if-post-down.d/avahi-daemon takes 12 seconds to complete,
> slowing the shutdown:
> 
> [...]
> May 15 10:23:47 zira dhclient[19399]: DHCPRELEASE of 192.168.1.3 on eth0 to 
> 192.168.1.1 port 67
> May 15 10:23:47 zira ifdown[19369]: DHCPRELEASE of 192.168.1.3 on eth0 to 
> 192.168.1.1 port 67
> May 15 10:23:47 zira root[19415]: 
> /etc/dhcp/dhclient-enter-hooks.d/google-tcp-dns with reason=RELEASE
> May 15 10:23:47 zira root[19418]: 
> /etc/dhcp/dhclient-exit-hooks.d/0google-tcp-dns with reason=RELEASE
> May 15 10:23:47 zira ifdown[19369]: /bin/ip link set dev eth0 down
> May 15 10:23:47 zira kernel: e1000e: eth0 NIC Link is Down
> May 15 10:23:47 zira ifdown[19369]: /bin/run-parts --verbose 
> /etc/network/if-post-down.d
> May 15 10:23:47 zira ifdown[19369]: run-parts: executing 
> /etc/network/if-post-down.d/0ifupdown
> May 15 10:23:47 zira ifupdown[19431]: IFACE=eth0 ADDRFAM=inet METHOD=dhcp 
> PHASE=post-down
> May 15 10:23:47 zira ifdown[19369]: run-parts: executing 
> /etc/network/if-post-down.d/avahi-daemon

Which part of /usr/lib/avahi/avahi-daemon-check-dns.sh is taking so long?
Can you add a "set -x" and then manually invoke "ifdown eth0"

-- 
Why is it that all of the instruments seeking intelligent life in the
universe are pointed away from Earth?



signature.asc
Description: OpenPGP digital signature