Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

DBusException: org.freedesktop.DBus.Error.ServiceUnknown: The name :1.327 was not provided by any .service files #570

Open
Moumoutaru opened this Issue Mar 21, 2019 · 13 comments

Comments

Projects
None yet
2 participants
@Moumoutaru
Copy link

commented Mar 21, 2019

Ansible Version: 2.7.5 (tried 2.7.9 as well)
Ansible Patched: No
Custom Modules: Yes (albeit not likely related to issue)
Have you tried the latest master version from Git?: No
Host and Target Python Versions: 2.7.5
Target OS: CentOS 7.5.1804 (Core)

Base error message:

    "module_stderr": "Traceback (most recent call last):\n  File \"master:/srv/ansible/lib/python2.7/site-packages/ansible_mitogen/runner.py\", line 883, in _run\n    self._run_code(code, mod)\n  File \"master:/srv/ansible/lib/python2.7/site-packages/ansible_mitogen/runner.py\", line 862, in _run_code\n    exec('exec code in vars(mod)')\n  File \"<string>\", line 1, in <module>\n  File \"master:/srv/ansible/lib/python2.7/site-packages/ansible/modules/system/firewalld.py\", line 715, in <module>\n  File \"master:/srv/ansible/lib/python2.7/site-packages/ansible/modules/system/firewalld.py\", line 605, in main\n  File \"master:/srv/ansible/lib/python2.7/site-packages/ansible/modules/system/firewalld.py\", line 171, in __init__\n  File \"master:/srv/ansible/lib/python2.7/site-packages/ansible/module_utils/firewalld.py\", line 75, in __init__\n    self.zone = fw.getDefaultZone()\n  File \"<string>\", line 2, in getDefaultZone\n  File \"/usr/lib/python2.7/site-packages/slip/dbus/polkit.py\", line 103, in _enable_proxy\n    return func(*p, **k)\n  File \"<string>\", line 2, in getDefaultZone\n  File \"/usr/lib/python2.7/site-packages/firewall/client.py\", line 53, in handle_exceptions\n    return func(*args, **kwargs)\n  File \"/usr/lib/python2.7/site-packages/firewall/client.py\", line 2903, in getDefaultZone\n    return dbus_to_python(self.fw.getDefaultZone())\n  File \"/usr/lib/python2.7/site-packages/slip/dbus/proxies.py\", line 50, in __call__\n    return dbus.proxies._ProxyMethod.__call__(self, *args, **kwargs)\n  File \"/usr/lib64/python2.7/site-packages/dbus/proxies.py\", line 145, in __call__\n    **keywords)\n  File \"/usr/lib64/python2.7/site-packages/dbus/connection.py\", line 651, in call_blocking\n    message, timeout)\nDBusException: org.freedesktop.DBus.Error.ServiceUnknown: The name :1.435 was not provided by any .service files\n", 
    "module_stdout": "", 
    "msg": "MODULE FAILURE\nSee stdout/stderr for the exact error", 
    "rc": 1
}

verbose-log-output-dbus-exception.txt

Ansible Config Dump:

ANSIBLE_PIPELINING(/home/amurphy/configuration-management/ansible.cfg) = True
ANSIBLE_SSH_ARGS(/home/amurphy/configuration-management/ansible.cfg) = -o ForwardAgent=yes
ANSIBLE_SSH_CONTROL_PATH(/home/amurphy/configuration-management/ansible.cfg) = %(directory)s/%%h-%%r
DEFAULT_ACTION_PLUGIN_PATH(/home/amurphy/configuration-management/ansible.cfg) = [u'/var/lib/awx/venv/awx/lib/python2.7/site-packages/ara/plugins/actions']
DEFAULT_CALLBACK_PLUGIN_PATH(/home/amurphy/configuration-management/ansible.cfg) = [u'/home/amurphy/configuration-management/plugins/callback_plugins']
DEFAULT_CALLBACK_WHITELIST(/home/amurphy/configuration-management/ansible.cfg) = [u'rc', u'profile_tasks', u'es_annotations']
DEFAULT_LOG_PATH(/home/amurphy/configuration-management/ansible.cfg) = /home/amurphy/ansible.log
DEFAULT_LOOKUP_PLUGIN_PATH(/home/amurphy/configuration-management/ansible.cfg) = [u'/home/amurphy/configuration-management/plugins/lookup']
DEFAULT_MANAGED_STR(/home/amurphy/configuration-management/ansible.cfg) = !! Ansible managed: This file was created by ansible. Do not modify by hand! Changes will be overwritten. !!
DEFAULT_MODULE_PATH(/home/amurphy/configuration-management/ansible.cfg) = [u'/home/amurphy/configuration-management/playbooks/library']
DEFAULT_ROLES_PATH(/home/amurphy/configuration-management/ansible.cfg) = [u'/home/amurphy/configuration-management/playbooks/roles', u'/home/amurphy/roles']
DEFAULT_STRATEGY(/home/amurphy/configuration-management/ansible.cfg) = mitogen_linear
DEFAULT_STRATEGY_PLUGIN_PATH(/home/amurphy/configuration-management/ansible.cfg) = [u'/usr/lib/python2.7/site-packages/ansible_mitogen/plugins/strategy', u'/srv/ansible/lib/python2.7/site-packages/ansible_mitogen/plugins/strategy', u'/srv
DEFAULT_VAULT_IDENTITY_LIST(env: ANSIBLE_VAULT_IDENTITY_LIST) = [u'/******']
INVENTORY_UNPARSED_IS_FAILED(/home/amurphy/configuration-management/ansible.cfg) = True
MAX_FILE_SIZE_FOR_DIFF(/home/amurphy/configuration-management/ansible.cfg) = 204800
RETRY_FILES_ENABLED(/home/amurphy/configuration-management/ansible.cfg) = False

So this error has been occurring when we try to enable a service after restarting firewalld. Reload comes back as changed, going to the enable custom service task and bombs out. This is the task order with the last throwing the error:

- name: Template firewalld configuration
  template:
    src: firewalld.conf.j2
    dest: /etc/firewalld/services/{{ item.name }}.xml
    mode: '0600'
    owner: root
    group: root
  with_items: '{{ firewalld_custom_services }}'
  register: firewall_services_installed

- name: Reload firewalld configuration
  service:
    name: firewalld
    state: restarted
    enabled: yes
  when: firewall_services_installed.changed == true

- name: Enable custom service
  firewalld:
    service: "{{ item.name }}"
    permanent: true
    immediate: true
    state: enabled
  with_items:
    - '{{ firewalld_custom_services }}'
@dw

This comment has been minimized.

Copy link
Owner

commented Mar 21, 2019

This is definitely a new one! Thanks for the clear report.

Exception:

Traceback (most recent call last):
  File "master:/srv/ansible/lib/python2.7/site-packages/ansible_mitogen/runner.py", line 883, in _run
    self._run_code(code, mod)
  File "master:/srv/ansible/lib/python2.7/site-packages/ansible_mitogen/runner.py", line 862, in _run_code
    exec('exec code in vars(mod)')
  File "<string>", line 1, in <module>
  File "master:/srv/ansible/lib/python2.7/site-packages/ansible/modules/system/firewalld.py", line 715, in <module>
  File "master:/srv/ansible/lib/python2.7/site-packages/ansible/modules/system/firewalld.py", line 605, in main
  File "master:/srv/ansible/lib/python2.7/site-packages/ansible/modules/system/firewalld.py", line 171, in __init__
  File "master:/srv/ansible/lib/python2.7/site-packages/ansible/module_utils/firewalld.py", line 75, in __init__
    self.zone = fw.getDefaultZone()
  File "<string>", line 2, in getDefaultZone
  File "/usr/lib/python2.7/site-packages/slip/dbus/polkit.py", line 103, in _enable_proxy
    return func(*p, **k)
  File "<string>", line 2, in getDefaultZone
  File "/usr/lib/python2.7/site-packages/firewall/client.py", line 53, in handle_exceptions
    return func(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/firewall/client.py", line 2903, in getDefaultZone
    return dbus_to_python(self.fw.getDefaultZone())
  File "/usr/lib/python2.7/site-packages/slip/dbus/proxies.py", line 50, in __call__
    return dbus.proxies._ProxyMethod.__call__(self, *args, **kwargs)
  File "/usr/lib64/python2.7/site-packages/dbus/proxies.py", line 145, in __call__
    **keywords)
  File "/usr/lib64/python2.7/site-packages/dbus/connection.py", line 651, in call_blocking
    message, timeout)
DBusException: org.freedesktop.DBus.Error.ServiceUnknown: The name :1.435 was not provided by any .service files

@dw

This comment has been minimized.

Copy link
Owner

commented Mar 21, 2019

Have you noticed if that ":1.435" name varies across runs? I haven't touched DBUS in a while, so wondering if the '435' is maybe a PID

@dw

This comment has been minimized.

Copy link
Owner

commented Mar 21, 2019

This seems to work fine with 2.7.9 against CentOS 7, I'll need to grab a 7.5 VM to try again.

I doubt it's relevant, but does your service XML use any fancy firewalld modules etc? This looks like a DBUS configuration error (clearly), so probably it's not related to the contents of your config at all

@dw

This comment has been minimized.

Copy link
Owner

commented Mar 21, 2019

@dw

This comment has been minimized.

Copy link
Owner

commented Mar 21, 2019

multiple suggestions (here: http://gnome-evolution-general.1774414.n4.nabble.com/The-name-1-157-was-not-provided-by-any-service-files-td4668022.html#a4668037 and flatpak/flatpak#1845 here) the error might relate to the backing service going away somehow

@Moumoutaru

This comment has been minimized.

Copy link
Author

commented Mar 21, 2019

@dw The :1.435 section seems to vary for me across runs. Haven't taken a look at your links yet. I am noticing, however, that it doesn't seem to happen all the time. For example, the first time calling the template, reload, and enable tasks steps for a service worked but the second time did not.

TASK [firewalld-custom-service : Template firewalld configuration] **********************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:46 -0400 (0:00:00.197)       0:01:21.376 ******** 
changed: [testhost.test.mydomain.io] => (item={u'ports': [{u'protocol': u'tcp', u'name': u'node_exporter', u'port': u'9100'}], u'name': u'node_exporter', u'description': u'node_exporter '})

TASK [firewalld-custom-service : Reload firewalld configuration] ************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:46 -0400 (0:00:00.209)       0:01:21.586 ******** 
changed: [testhost.test.mydomain.io]

TASK [firewalld-custom-service : Enable custom service] *********************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:47 -0400 (0:00:01.057)       0:01:22.643 ******** 
changed: [testhost.test.mydomain.io] => (item={u'ports': [{u'protocol': u'tcp', u'name': u'node_exporter', u'port': u'9100'}], u'name': u'node_exporter', u'description': u'node_exporter '})

TASK [firewalld-custom-service : Status firewalld] **************************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:48 -0400 (0:00:00.543)       0:01:23.187 ******** 
ok: [testhost.test.mydomain.io]

TASK [prometheus_exporters : Download the exporter binary] ******************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:48 -0400 (0:00:00.126)       0:01:23.314 ******** 
changed: [testhost.test.mydomain.io]

TASK [prometheus_exporters : Update Firewall Rules] *************************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:48 -0400 (0:00:00.731)       0:01:24.046 ******** 
ok: [testhost.test.mydomain.io]

TASK [prometheus_exporters : Template systemd unit file] ********************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:49 -0400 (0:00:00.111)       0:01:24.157 ******** 
changed: [testhost.test.mydomain.io]

TASK [prometheus_exporters : Create exporter optional config files] *********************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:49 -0400 (0:00:00.253)       0:01:24.411 ******** 

TASK [prometheus_exporters : Add runtime options] ***************************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:49 -0400 (0:00:00.092)       0:01:24.504 ******** 
changed: [testhost.test.mydomain.io]

TASK [prometheus_exporters : Start exporter] ********************************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:49 -0400 (0:00:00.152)       0:01:24.657 ******** 
changed: [testhost.test.mydomain.io]

TASK [firewalld-custom-service : Template firewalld configuration] **********************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:49 -0400 (0:00:00.199)       0:01:24.856 ******** 
changed: [testhost.test.mydomain.io] => (item={u'ports': [{u'protocol': u'tcp', u'name': u'process_exporter_ops', u'port': u'9113'}], u'name': u'process_exporter_ops', u'description': u'process_exporter '})

TASK [firewalld-custom-service : Reload firewalld configuration] ************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:49 -0400 (0:00:00.130)       0:01:24.987 ******** 
changed: [testhost.test.mydomain.io]

TASK [firewalld-custom-service : Enable custom service] *********************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:50 -0400 (0:00:01.063)       0:01:26.050 ******** 
An exception occurred during task execution. To see the full traceback, use -vvv. The error was: DBusException: org.freedesktop.DBus.Error.ServiceUnknown: The name :1.29 was not provided by any .service files
failed: [testhost.test.mydomain.io] (item={u'ports': [{u'protocol': u'tcp', u'name': u'process_exporter_ops', u'port': u'9113'}], u'name': u'process_exporter_ops', u'description': u'process_exporter '}) => {"changed": false, "item": {"description": "process_exporter ", "name": "process_exporter_ops", "ports": [{"name": "process_exporter_ops", "port": "9113", "protocol": "tcp"}]}, "module_stderr": "Traceback (most recent call last):\n  File \"master:/srv/ansible/lib/python2.7/site-packages/ansible_mitogen/runner.py\", line 883, in _run\n    self._run_code(code, mod)\n  File \"master:/srv/ansible/lib/python2.7/site-packages/ansible_mitogen/runner.py\", line 862, in _run_code\n    exec('exec code in vars(mod)')\n  File \"<string>\", line 1, in <module>\n  File \"master:/srv/ansible/lib/python2.7/site-packages/ansible/modules/system/firewalld.py\", line 718, in <module>\n  File \"master:/srv/ansible/lib/python2.7/site-packages/ansible/modules/system/firewalld.py\", line 608, in main\n  File \"master:/srv/ansible/lib/python2.7/site-packages/ansible/modules/system/firewalld.py\", line 171, in __init__\n  File \"master:/srv/ansible/lib/python2.7/site-packages/ansible/module_utils/firewalld.py\", line 75, in __init__\n    self.zone = fw.getDefaultZone()\n  File \"<string>\", line 2, in getDefaultZone\n  File \"/usr/lib/python2.7/site-packages/slip/dbus/polkit.py\", line 103, in _enable_proxy\n    return func(*p, **k)\n  File \"<string>\", line 2, in getDefaultZone\n  File \"/usr/lib/python2.7/site-packages/firewall/client.py\", line 53, in handle_exceptions\n    return func(*args, **kwargs)\n  File \"/usr/lib/python2.7/site-packages/firewall/client.py\", line 2903, in getDefaultZone\n    return dbus_to_python(self.fw.getDefaultZone())\n  File \"/usr/lib/python2.7/site-packages/slip/dbus/proxies.py\", line 50, in __call__\n    return dbus.proxies._ProxyMethod.__call__(self, *args, **kwargs)\n  File \"/usr/lib64/python2.7/site-packages/dbus/proxies.py\", line 145, in __call__\n    **keywords)\n  File \"/usr/lib64/python2.7/site-packages/dbus/connection.py\", line 651, in call_blocking\n    message, timeout)\nDBusException: org.freedesktop.DBus.Error.ServiceUnknown: The name :1.29 was not provided by any .service files\n", "module_stdout": "", "msg": "MODULE FAILURE\nSee stdout/stderr for the exact error", "rc": 1}

RUNNING HANDLER [time : restart chronyd] ************************************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:50 -0400 (0:00:00.087)       0:01:26.137 ******** 

RUNNING HANDLER [prometheus_exporters : systemctl daemon-reload] ************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:50 -0400 (0:00:00.005)       0:01:26.143 ******** 

RUNNING HANDLER [prometheus_exporters : restart exporter] *******************************************************************************************************************************************************************************************************************************************************************
Thursday 21 March 2019  12:17:51 -0400 (0:00:00.004)       0:01:26.148 ******** 

PLAY RECAP ******************************************************************************************************************************************************************************************************************************************************************************************************************
testhost.test.mydomain.io : ok=45   changed=24   unreachable=0    failed=1   
@Moumoutaru

This comment has been minimized.

Copy link
Author

commented Mar 21, 2019

This seems to work fine with 2.7.9 against CentOS 7, I'll need to grab a 7.5 VM to try again.

I doubt it's relevant, but does your service XML use any fancy firewalld modules etc? This looks like a DBUS configuration error (clearly), so probably it's not related to the contents of your config at all

Service files are pretty basic:

[root@l-docker101 ~]# cat /etc/firewalld/services/*exporter*.xml
<?xml version="1.0" encoding="utf-8"?>
<service>
    <short>node_exporter</short>
    <description>node_exporter </description>
        <port port="9100" protocol="tcp"/>
    </service>
<?xml version="1.0" encoding="utf-8"?>
<service>
    <short>process_exporter_ops</short>
    <description>process_exporter </description>
        <port port="9113" protocol="tcp"/>
    </service>
[root@l-docker101 ~]# 
@Moumoutaru

This comment has been minimized.

Copy link
Author

commented Mar 21, 2019

Also, changing mitogen_linear to linear seems to resolve the issue.. albeit it's painfully slow. Let me know if there are any debugging steps you'd like me to go through as I am able to reproduce this fairly easily.

@dw

This comment has been minimized.

Copy link
Owner

commented Mar 21, 2019

I haven't figured out what's broken yet (haven't reproduced yet either!), but the rough guess is that the glib dbus client in the persistent interpreter is being broken somehow. I notice some ugly looking initialization code, it's possible it's being partially reinitialized twice, or similar.

This stuff has a fairly mature design, so whatever the problem I'm pretty sure the fix will be straightforwrad :)

@Moumoutaru

This comment has been minimized.

Copy link
Author

commented Mar 21, 2019

https://github.com/firewalld/firewalld/blob/v0.5.3/src/firewall/client.py appears to be the version shipped with 7.5

That is the file present on my installation of Centos 7.5

@dw

This comment has been minimized.

Copy link
Owner

commented Mar 22, 2019

Reproduced it.. doesn't happen on first module invocation, but on second. So there is some shared component that is getting trashed somehow

@dw

This comment has been minimized.

Copy link
Owner

commented Mar 22, 2019

Hah! Real stupid bug. We restart firewalld, but keep a copy of the old firewall client around, which knows firewalld by a different name -- that ":1:123" crap is a needlessly cryptic unique name generated by dbus on initial connection by any app. So on second invocation, the cached client tries to talk to a dbus client that no longer exists.

Should be an easy fix, but for the time being, you can simply run the firewalld in isolated mode:

- name: Enable custom service
  firewalld:
    service: foo
    permanent: true
    immediate: true
    state: enabled 
  vars:
    mitogen_task_isolation: fork

dw added a commit that referenced this issue Mar 22, 2019

dw added a commit that referenced this issue Mar 22, 2019

Merge pull request #572 from dw/issue570
issue #570: add firewalld to always-fork list for now.
@Moumoutaru

This comment has been minimized.

Copy link
Author

commented Mar 25, 2019

Thanks for the help @dw

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.