Avahi stopping after VPN IP Change



  • I am having some problems with Avahi stopping occasionally which I think I have tracked down to occurring when my VPN client connection restarts.  From the logs it appears that the sequence of events are:

    • VPN connection drops (perfectly normal) on my dodgy WAN connection

    • VPN reconnects and is allocated a new address

    • rc.newwanip notices the change and restarts Avahi(not sure why)

    • Avahi fails to come up correctly

    I am not sure whether the problem is that Avahi should go through this process but is hanging or if rc.newwanip shouldn't be touching Avahi.  The strange thing (to me) about this is that the VPN interface (BLA_VPN) is set as an excluded interface in the Avahi config page.

    I am running: pfSense 2.3-RELEASE (amd64) and Avahi 1.11_2 - let men now if you need other details.

    Any help to get to the bottom of this one would be appreciated.

    Logs as follows:

    
    Jun 6 23:39:21	kernel		ovpnc1: link state changed to DOWN
    Jun 6 23:39:21	avahi-daemon	22575	Withdrawing workstation service for ovpnc1.
    Jun 6 23:39:21	check_reload_status		Reloading filter
    Jun 6 23:39:22	kernel		ovpnc1: link state changed to UP
    Jun 6 23:39:22	check_reload_status		rc.newwanip starting ovpnc1
    Jun 6 23:39:22	xinetd	17441	Starting reconfiguration
    Jun 6 23:39:22	xinetd	17441	Swapping defaults
    Jun 6 23:39:22	xinetd	17441	readjusting service 6969-udp
    Jun 6 23:39:22	xinetd	17441	Reconfigured: new=0 old=1 dropped=0 (services)
    Jun 6 23:39:23	php-fpm	30725	/rc.newwanip: rc.newwanip: Info: starting on ovpnc1.
    Jun 6 23:39:23	php-fpm	30725	/rc.newwanip: rc.newwanip: on (IP address: xx.xx.xx.198) (interface: BLA_VPN[opt5]) (real interface: ovpnc1).
    Jun 6 23:39:23	php-fpm	30725	/rc.newwanip: IP has changed, killing states on former IP xx.xx.xx.195.
    Jun 6 23:39:23	xinetd	17441	Starting reconfiguration
    Jun 6 23:39:23	xinetd	17441	Swapping defaults
    Jun 6 23:39:23	xinetd	17441	readjusting service 6969-udp
    Jun 6 23:39:23	xinetd	17441	Reconfigured: new=0 old=1 dropped=0 (services)
    Jun 6 23:39:27	php-fpm	30725	/rc.newwanip: Creating rrd update script
    Jun 6 23:39:29	php-fpm	30725	/rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - xx.xx.xx.195 -> xx.xx.xx.198 - Restarting packages.
    Jun 6 23:39:29	check_reload_status		Starting packages
    Jun 6 23:39:30	php-fpm	30725	/rc.start_packages: Restarting/Starting all packages.
    Jun 6 23:39:30	avahi-daemon	22575	Got SIGTERM, quitting.
    Jun 6 23:39:30	avahi-daemon	22575	Leaving mDNS multicast group on interface ovpns2.IPv4 with address 192.168.100.1.
    Jun 6 23:39:30	avahi-daemon	22575	avahi-daemon 0.6.31 exiting.
    Jun 6 23:39:30	php-fpm	30725	/rc.start_packages: The command '/usr/local/etc/rc.d/avahi-daemon.sh stop' returned exit code '1', the output was 'Stopping dbus. Waiting for PIDS: 20535.'
    Jun 6 23:39:30	root		/usr/local/etc/rc.d/dbus: WARNING: failed to start dbus
    Jun 6 23:39:30	root		/usr/local/etc/rc.d/dbus: WARNING: failed to start dbus
    Jun 6 23:39:35	avahi-daemon	386	Found user 'avahi' (UID 558) and group 'avahi' (GID 558).
    Jun 6 23:39:35	avahi-daemon	386	Successfully dropped root privileges.
    Jun 6 23:39:35	avahi-daemon	1696	Found user 'avahi' (UID 558) and group 'avahi' (GID 558).
    Jun 6 23:39:35	avahi-daemon	1549	Found user 'avahi' (UID 558) and group 'avahi' (GID 558).
    Jun 6 23:39:35	avahi-daemon	386	avahi-daemon 0.6.31 starting up.
    Jun 6 23:39:35	avahi-daemon	1696	Successfully dropped root privileges.
    Jun 6 23:39:35	avahi-daemon	1549	Successfully dropped root privileges.
    Jun 6 23:39:35	avahi-daemon	386	WARNING: No NSS support for mDNS detected, consider installing nss-mdns!
    Jun 6 23:39:35	avahi-daemon	1696	open(/var/run/avahi-daemon//pid): File exists
    Jun 6 23:39:35	avahi-daemon	1696	Failed to create PID file: File exists
    Jun 6 23:39:35	avahi-daemon	1549	open(/var/run/avahi-daemon//pid): File exists
    Jun 6 23:39:35	avahi-daemon	1549	Failed to create PID file: File exists
    Jun 6 23:39:35	avahi-daemon	386	dbus_bus_get_private(): Failed to connect to socket /var/run/dbus/system_bus_socket: No such file or directory
    Jun 6 23:39:35	avahi-daemon	386	WARNING: Failed to contact D-Bus daemon.
    Jun 6 23:39:35	avahi-daemon	386	avahi-daemon 0.6.31 exiting.
    
    


  • The avahi shutdown seems to kill the dbus daemon as well which is required for avahi to run. It then fails to start the dbus daemon before attemping to start the avahi daemon again. I would say that restarting of the dbus daemon is unnecessary because it doesn't listen on IP addresses/interfaces and could be left running.


Log in to reply