[Bug 1925233] Re: [bionic-ussuri] next charm fails to start mdns service

Tue Feb 8 15:14:37 UTC 2022

Checking designate/2.

 ~/Downloads/f1badd08-a9a6-405a-b0be-d7f49ece023c/designate_2 $ tail
var/log/designate/designate-mdns.log -n 2
2021-04-19 16:04:24.389 64928 ERROR designate
oslo_db.exception.CantStartEngineError: No sql_connection parameter is
established
2021-04-19 16:04:24.389 64928 ERROR designate 

The last line logged by designate-mdns was at 16:04. While the
configuration files were rendered at 16:05:12

$ grep -C 2 base-config.rendered var/log/juju/unit-designate-2.log |
head -n 5
2021-04-19 16:05:12 DEBUG jujuc server.go:211 running hook tool "juju-
log" for designate/2-identity-service-relation-changed-
330171960584494981
2021-04-19 16:05:12 DEBUG juju-log identity-service:105: tracer>
tracer: set flag base-config.rendered
tracer: ++   queue handler
reactive/designate_handlers.py:144:run_db_migration
tracer: ++   queue handler
reactive/designate_handlers.py:155:sync_pool_manager_cache

designate-mdns failed to start because the systemd service hit start-
limit-hit

Apr 19 16:04:24 juju-9669d8-4-lxd-3 systemd[1]: designate-mdns.service:
Failed with result 'exit-code'.
Apr 19 16:04:24 juju-9669d8-4-lxd-3 systemd[1]: designate-mdns.service:
Service hold-off time over, scheduling restart.
Apr 19 16:04:24 juju-9669d8-4-lxd-3 systemd[1]: designate-mdns.service:
Scheduled restart job, restart counter is at 481.
Apr 19 16:04:24 juju-9669d8-4-lxd-3 systemd[1]: designate-mdns.service:
Failed to reset devices.list: Operation not permitted
Apr 19 16:04:24 juju-9669d8-4-lxd-3 systemd[1]: designate-mdns.service:
Start request repeated too quickly.
Apr 19 16:04:24 juju-9669d8-4-lxd-3 systemd[1]: designate-mdns.service:
Failed with result 'start-limit-hit'.

I think this is something that should be fixed in the package, since we
may need to do adjustments to designate-mdns.service

https://www.freedesktop.org/software/systemd/man/systemd.unit.html#StartLimitIntervalSec=interval

** Also affects: designate (Ubuntu)
   Importance: Undecided
       Status: New

** Summary changed:

- [bionic-ussuri] next charm fails to start mdns service
+ [bionic-ussuri] designate-mdns.service Failed with result 'start-limit-hit'

** Summary changed:

- [bionic-ussuri] designate-mdns.service Failed with result 'start-limit-hit'
+ [bionic-ussuri] designate-mdns.service: Failed with result 'start-limit-hit'

-- 
You received this bug notification because you are a member of Ubuntu
OpenStack, which is subscribed to designate in Ubuntu.
https://bugs.launchpad.net/bugs/1925233

Title:
  [bionic-ussuri] designate-mdns.service: Failed with result 'start-
  limit-hit'

Status in OpenStack Designate Charm:
  Incomplete
Status in designate package in Ubuntu:
  New

Bug description:
  On a bionic ussuri deploy with charms next, both the designate units are stuck waiting for the designate-mdns service to start.  The journal shows that the service goes up and down multiple times and fails to reset the device list.
  Apr 19 10:04:12 juju-9669d8-0-lxd-3 systemd[1]: designate-mdns.service: Service hold-off time over, scheduling restart.
  Apr 19 10:04:12 juju-9669d8-0-lxd-3 systemd[1]: designate-mdns.service: Scheduled restart job, restart counter is at 503.
  Apr 19 10:04:12 juju-9669d8-0-lxd-3 systemd[1]: Stopped OpenStack Designate DNSaaS mdns.
  Apr 19 10:04:12 juju-9669d8-0-lxd-3 systemd[1]: designate-mdns.service: Failed to reset devices.list: Operation not permitted
  Apr 19 10:04:12 juju-9669d8-0-lxd-3 systemd[1]: Started OpenStack Designate DNSaaS mdns.
  Apr 19 10:04:15 juju-9669d8-0-lxd-3 systemd[1]: designate-mdns.service: Main process exited, code=exited, status=1/FAILURE
  Apr 19 10:04:15 juju-9669d8-0-lxd-3 systemd[1]: designate-mdns.service: Failed with result 'exit-code'.

  Additionally the mdns log shows it failing to connect to sql:
  2021-04-19 16:04:23.818 70854 INFO designate.mdns.base [-] Initialized mDNS xfr endpoint
  2021-04-19 16:04:24.429 70854 CRITICAL designate [-] Unhandled error: oslo_db.exception.CantStartEngineError: No sql_connection parameter is established
  2021-04-19 16:04:24.429 70854 ERROR designate Traceback (most recent call last):
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/bin/designate-mdns", line 10, in <module>
  2021-04-19 16:04:24.429 70854 ERROR designate     sys.exit(main())
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/designate/cmd/mdns.py", line 41, in main
  2021-04-19 16:04:24.429 70854 ERROR designate     server = mdns_service.Service()
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/designate/mdns/service.py", line 47, in __init__
  2021-04-19 16:04:24.429 70854 ERROR designate     self.dns_application, self.tg,
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/designate/utils.py", line 256, in wrapper
  2021-04-19 16:04:24.429 70854 ERROR designate     cache.append(function(cls_instance))
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/designate/mdns/service.py", line 78, in dns_application
  2021-04-19 16:04:24.429 70854 ERROR designate     application = handler.RequestHandler(self.storage, self.tg)
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/designate/mdns/service.py", line 65, in storage
  2021-04-19 16:04:24.429 70854 ERROR designate     CONF['service:mdns'].storage_driver
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/designate/storage/__init__.py", line 36, in get_storage
  2021-04-19 16:04:24.429 70854 ERROR designate     return cls()
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/designate/storage/impl_sqlalchemy/__init__.py", line 40, in __init__
  2021-04-19 16:04:24.429 70854 ERROR designate     super(SQLAlchemyStorage, self).__init__()
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/designate/sqlalchemy/base.py", line 72, in __init__
  2021-04-19 16:04:24.429 70854 ERROR designate     self.engine = session.get_engine(self.get_name())
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/designate/sqlalchemy/session.py", line 47, in get_engine
  2021-04-19 16:04:24.429 70854 ERROR designate     facade = _create_facade_lazily(cfg_group)
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/designate/sqlalchemy/session.py", line 40, in _create_facade_lazily
  2021-04-19 16:04:24.429 70854 ERROR designate     **conf
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 1295, in __init__
  2021-04-19 16:04:24.429 70854 ERROR designate     slave_connection=slave_connection)
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 510, in _start
  2021-04-19 16:04:24.429 70854 ERROR designate     engine_args, maker_args)
  2021-04-19 16:04:24.429 70854 ERROR designate   File "/usr/lib/python3/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 532, in _setup_for_connection
  2021-04-19 16:04:24.429 70854 ERROR designate     "No sql_connection parameter is established")
  2021-04-19 16:04:24.429 70854 ERROR designate oslo_db.exception.CantStartEngineError: No sql_connection parameter is established
  2021-04-19 16:04:24.429 70854 ERROR designate

  Test run artifacts are at https://oil-jenkins.canonical.com/artifacts/9d23156f-b697-49f0-8a04-f87452fdfc18/index.html 
  and the crashdump is at https://oil-jenkins.canonical.com/artifacts/9d23156f-b697-49f0-8a04-f87452fdfc18/generated/generated/openstack/juju-crashdump-openstack-2021-04-19-19.23.41.tar.gz

  these logs snippets were taken from designate_0, but dessignate_1 has
  similar logs.

To manage notifications about this bug go to:
https://bugs.launchpad.net/charm-designate/+bug/1925233/+subscriptions