lxd-bridge.service exits success on failure to run dnsmasq

[Scott Moser]

I recently upgraded during yakkety development cycle, rebooted and found i could not launch containers. The failure can be seen below.

The issue seemed to be that dnsmasq is installed and was binding to all port 53 leaving lxd-bridge unable to bind. However, the systemd service does not recognize it failed. it seems an error in the '|| cleanup' in /usr/lib/lxd/lxd-bridge
I think chaning that to simply '|| exit' would correctly show failure.

$ systemctl status lxd-bridge --no-pager -l
● lxd-bridge.service - LXD - network bridge
   Loaded: loaded (/lib/systemd/system/lxd-bridge.service; static; vendor preset: enabled)
   Active: active (exited) since Mon 2016-08-15 09:37:38 EDT; 1 day 3h ago
     Docs: man:lxd(1)
 Main PID: 4426 (code=exited, status=0/SUCCESS)
    Tasks: 0 (limit: 4915)
   Memory: 0B
      CPU: 0
   CGroup: /system.slice/lxd-bridge.service

Aug 15 09:37:38 milhouse systemd[1]: Starting LXD - network bridge...
Aug 15 09:37:38 milhouse lxd-bridge.start[4426]: dnsmasq: failed to create listening socket for 10.8.1.1: Address already in use
Aug 15 09:37:38 milhouse lxd-bridge.start[4426]: Failed to setup lxd-bridge.
Aug 15 09:37:38 milhouse systemd[1]: Started LXD - network bridge.

==== Failure example ===
$ lxc launch ubuntu-daily:yakkety y1
Creating y1
Starting y1
error: Error calling 'lxd forkstart y1 /var/lib/lxd/containers /var/log/lxd/y1/lxc.conf': err='exit status 1'
Try `lxc info --show-log y1` for more info

$ lxc info --show-log y1
Name: y1
Architecture: x86_64
Created: 2016/08/15 20:00 UTC
Status: Stopped
Type: persistent
Profiles: default

Log:

            lxc 20160815160056.225 INFO lxc_start - start.c:lxc_check_inherited:251 - closed inherited fd 3
            lxc 20160815160056.225 INFO lxc_start - start.c:lxc_check_inherited:251 - closed inherited fd 10
            lxc 20160815160056.228 INFO lxc_container - lxccontainer.c:do_lxcapi_start:797 - Attempting to set proc title to [lxc monitor] /var/lib/lxd/containers y1
            lxc 20160815160056.228 INFO lxc_start - start.c:lxc_check_inherited:251 - closed inherited fd 10
            lxc 20160815160056.228 INFO lxc_lsm - lsm/lsm.c:lsm_init:48 - LSM security driver AppArmor
            lxc 20160815160056.228 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .reject_force_umount # comment this to allow umount -f; not recommended.
            lxc 20160815160056.228 INFO lxc_seccomp - seccomp.c:parse_config_v2:446 - Adding native rule for reject_force_umount action 0
            lxc 20160815160056.228 INFO lxc_seccomp - seccomp.c:do_resolve_add_rule:216 - Setting seccomp rule to reject force umounts

            lxc 20160815160056.228 INFO lxc_seccomp - seccomp.c:parse_config_v2:449 - Adding compat rule for reject_force_umount action 0
            lxc 20160815160056.228 INFO lxc_seccomp - seccomp.c:do_resolve_add_rule:216 - Setting seccomp rule to reject force umounts

            lxc 20160815160056.228 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .[all].
            lxc 20160815160056.228 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .kexec_load errno 1.
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:446 - Adding native rule for kexec_load action 327681
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:449 - Adding compat rule for kexec_load action 327681
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .open_by_handle_at errno 1.
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:446 - Adding native rule for open_by_handle_at action 327681
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:449 - Adding compat rule for open_by_handle_at action 327681
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .init_module errno 1.
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:446 - Adding native rule for init_module action 327681
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:449 - Adding compat rule for init_module action 327681
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .finit_module errno 1.
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:446 - Adding native rule for finit_module action 327681
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:449 - Adding compat rule for finit_module action 327681
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:342 - processing: .delete_module errno 1.
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:446 - Adding native rule for delete_module action 327681
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:449 - Adding compat rule for delete_module action 327681
            lxc 20160815160056.229 INFO lxc_seccomp - seccomp.c:parse_config_v2:456 - Merging in the compat seccomp ctx into the main one
            lxc 20160815160056.229 INFO lxc_conf - conf.c:run_script_argv:367 - Executing script '/usr/bin/lxd callhook /var/lib/lxd 546 start' for container 'y1', config section 'lxc'
            lxc 20160815160056.229 INFO lxc_start - start.c:lxc_check_inherited:251 - closed inherited fd 3
            lxc 20160815160056.229 INFO lxc_start - start.c:lxc_check_inherited:251 - closed inherited fd 10
            lxc 20160815160056.232 INFO lxc_monitor - monitor.c:lxc_monitor_sock_name:178 - using monitor sock name lxc/d78a9d7e97b4b375//var/lib/lxd/containers
            lxc 20160815160056.315 DEBUG lxc_start - start.c:setup_signal_fd:289 - sigchild handler set
            lxc 20160815160056.316 DEBUG lxc_console - console.c:lxc_console_peer_default:469 - no console peer
            lxc 20160815160056.316 INFO lxc_start - start.c:lxc_init:488 - 'y1' is initialized
            lxc 20160815160056.317 DEBUG lxc_start - start.c:__lxc_start:1326 - Not dropping cap_sys_boot or watching utmp
            lxc 20160815160056.317 INFO lxc_start - start.c:resolve_clone_flags:1013 - Cloning a new user namespace
            lxc 20160815160056.317 INFO lxc_confile - confile.c:config_idmap:1500 - read uid map: type u nsid 0 hostid 165536 range 65536
            lxc 20160815160056.317 INFO lxc_confile - confile.c:config_idmap:1500 - read uid map: type g nsid 0 hostid 165536 range 65536
            lxc 20160815160056.322 ERROR lxc_conf - conf.c:instantiate_veth:2595 - failed to attach 'vethB0Y46P' to the bridge 'lxdbr0': Operation not permitted
            lxc 20160815160056.356 ERROR lxc_conf - conf.c:lxc_create_network:2872 - failed to create netdev
            lxc 20160815160056.356 ERROR lxc_start - start.c:lxc_spawn:1080 - failed to create the network
            lxc 20160815160056.356 ERROR lxc_start - start.c:__lxc_start:1353 - failed to spawn 'y1'
            lxc 20160815160056.357 INFO lxc_conf - conf.c:run_script_argv:367 - Executing script '/usr/share/lxcfs/lxc.reboot.hook' for container 'y1', config section 'lxc'
            lxc 20160815160056.860 INFO lxc_conf - conf.c:run_script_argv:367 - Executing script '/usr/bin/lxd callhook /var/lib/lxd 546 stop' for container 'y1', config section 'lxc'
            lxc 20160815160056.934 WARN lxc_commands - commands.c:lxc_cmd_rsp_recv:172 - command get_cgroup failed to receive response
            lxc 20160815160056.934 WARN lxc_commands - commands.c:lxc_cmd_rsp_recv:172 - command get_cgroup failed to receive response
            lxc 20160815160056.937 INFO lxc_confile - confile.c:config_idmap:1500 - read uid map: type u nsid 0 hostid 165536 range 65536
            lxc 20160815160056.937 INFO lxc_confile - confile.c:config_idmap:1500 - read uid map: type g nsid 0 hostid 165536 range 65536
            lxc 20160815160124.089 INFO lxc_confile - confile.c:config_idmap:1500 - read uid map: type u nsid 0 hostid 165536 range 65536
            lxc 20160815160124.089 INFO lxc_confile - confile.c:config_idmap:1500 - read uid map: type g nsid 0 hostid 165536 range 65536
            lxc 20160815160124.093 INFO lxc_confile - confile.c:config_idmap:1500 - read uid map: type u nsid 0 hostid 165536 range 65536
            lxc 20160815160124.093 INFO lxc_confile - confile.c:config_idmap:1500 - read uid map: type g nsid 0 hostid 165536 range 65536

ProblemType: Bug
DistroRelease: Ubuntu 16.10
Package: lxd 2.0.3-0ubuntu2
ProcVersionSignature: Ubuntu 4.4.0-34.53-generic 4.4.15
Uname: Linux 4.4.0-34-generic x86_64
NonfreeKernelModules: zfs zunicode zcommon znvpair zavl
ApportVersion: 2.20.3-0ubuntu7
Architecture: amd64
CurrentDesktop: Unity
Date: Tue Aug 16 12:44:17 2016
EcryptfsInUse: Yes
InstallationDate: Installed on 2015-07-23 (390 days ago)
InstallationMedia: Ubuntu 15.10 "Wily Werewolf" - Alpha amd64 (20150722.1)
SourcePackage: lxd
UpgradeStatus: No upgrade log present (probably fresh install)

Related bugs:
 * bug 1613820: lxd-bridge.service races against dnsmasq package's dnsmasq.service

[Launchpad Janitor (janitor)]

This bug was fixed in the package lxd - 2.1-0ubuntu1

---------------
lxd (2.1-0ubuntu1) yakkety; urgency=medium

  * New upstream release (2.1)
    - All the bugfixes listed as part of LXD 2.0.1, 2.0.2, 2.0.3 and 2.0.4

    - client: Add a lxc shell alias by default
    - client: Build unix-like aliases directly into LXC
    - client: Generate the client certificate on-demand
    - client/copy: Allow additional profiles and config (LP: #1585307)
    - client/copy: Pick a random name if not specified (LP: #1585308)
    - client/image: Add --format and json output
    - client/image: Allow deleting multiple images at once
    - client/list: Add support for config key columns
    - client/profile: lxc profile apply is now lxc profile assign
    - client/profile: New lxc profile add and lxc profile remove sub-commands
    - client/version: Do not show the version command by default
    - daemon: Add a global core.https_allowed_credentials key
    - daemon: Implement ETag support for all PUT calls
    - daemon: Implement PKI authentication
    - daemon: Implement the PATCH method for all endpoints that have PUT
    - daemon/container: Add config key for container force shutdown timeout
    - daemon/container: Add some seccomp knobs
    - daemon/container: Add support for the "usb" device type
    - daemon/container: Record the last used date for containers
    - daemon/zfs: Allow forcing snapshot removal through configuration
    - tests: Fix for newer shellcheck
    - lxd-bridge: Fail on dnsmasq failure (LP: #1613815)
    - c/r: switch to the new ->migrate API
    - c/r: use liblxc's new preserves_inodes feature
    - c/r: bump ghost limit

 -- Stéphane Graber <email address hidden> Wed, 17 Aug 2016 19:31:36 -0400

[Daniel Chow (simech)]

I'm having what appears to be this same issue:
root@mcnode2:~# lxd --version
2.0.9

root@mcnode2:/var/lib/lxd# service lxd status
● lxd.service - LXD - main daemon
   Loaded: loaded (/lib/systemd/system/lxd.service; indirect; vendor preset: enabled)
   Active: inactive (dead)
     Docs: man:lxd(1)

oot@mcnode2:~# systemctl status lxd-bridge.service
● lxd-bridge.service - LXD - network bridge
   Loaded: loaded (/lib/systemd/system/lxd-bridge.service; static; vendor preset: enabled)
   Active: failed (Result: exit-code) since Mon 2017-03-27 14:33:33 PDT; 16s ago
     Docs: man:lxd(1)
  Process: 7567 ExecStart=/usr/lib/lxd/lxd-bridge.start (code=exited, status=2)
 Main PID: 7567 (code=exited, status=2)

Mar 27 14:33:33 mcnode2 systemd[1]: Starting LXD - network bridge...
Mar 27 14:33:33 mcnode2 lxd-bridge.start[7567]: dnsmasq: failed to create listening socket for 10.50.146.1: Address already in use
Mar 27 14:33:33 mcnode2 lxd-bridge.start[7567]: Failed to setup lxd-bridge.
Mar 27 14:33:33 mcnode2 systemd[1]: lxd-bridge.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Mar 27 14:33:33 mcnode2 systemd[1]: Failed to start LXD - network bridge.
Mar 27 14:33:33 mcnode2 systemd[1]: lxd-bridge.service: Unit entered failed state.
Mar 27 14:33:33 mcnode2 systemd[1]: lxd-bridge.service: Failed with result 'exit-code'.

root@mcnode2:~# /usr/lib/lxd/lxd-bridge.start
dnsmasq: failed to create listening socket for 10.50.146.1: Address already in use
Failed to setup lxd-bridge.

root@mcnode2:~# cat /usr/lib/lxd/lxd-bridge | grep 53
    iptables "${use_iptables_lock}" -I INPUT -i "${LXD_BRIDGE}" -p udp --dport 53 -j ACCEPT -m comment --comment "managed by lxd-bridge"
    iptables "${use_iptables_lock}" -I INPUT -i "${LXD_BRIDGE}" -p tcp --dport 53 -j ACCEPT -m comment --comment "managed by lxd-bridge"
...

[Stéphane Graber (stgraber)]

No, this issue was that lxd-bridge would succeed to start even though the script failed.

In your case, lxd-bridge failed as it should since you're running a conflicting DNS server on your machine.