test: restart firewalld before checking ports status

[richm]

tests_imuxsock_files.yml on el10 leaves firewalld in a really strange
state such that when started it reports

and firewall-cmd fails because firewalld is not listening to dbus.

ERROR: Exception DBusException: org.freedesktop.DBus.Error.AccessDenied: Request to own name refused by policy

Restaring firewalld here seems to clear the condition.

Signed-off-by: Rich Megginson [email protected]

[richm]

[citest]

[erig0]

It sounds like when firewalld is started dbus-broker hasn't loaded the policy for firewalld (/usr/share/dbus-1/system.d/FirewallD.conf). Is there any chance that firewalld is installed after dbus-broker (or the host) is started?

[richm]

I previously had the results for el9, not el10. el10 results are coming.

[richm]

It sounds like when firewalld is started dbus-broker hasn't loaded the policy for firewalld (/usr/share/dbus-1/system.d/FirewallD.conf). Is there any chance that firewalld is installed after dbus-broker (or the host) is started?

centos-10:

+ systemctl status dbus-broker.service
● dbus-broker.service - D-Bus System Message Bus
     Loaded: loaded (/usr/lib/systemd/system/dbus-broker.service; enabled; preset: enabled)
     Active: active (running) since Fri 2024-08-23 09:40:36 EDT; 1min 9s ago
 Invocation: d665983ef83440b9a37bceac1d1f28c5
TriggeredBy: ● dbus.socket
       Docs: man:dbus-broker-launch(1)
   Main PID: 830 (dbus-broker-lau)
      Tasks: 2 (limit: 10828)
     Memory: 2.4M (peak: 3.8M)
        CPU: 116ms
     CGroup: /system.slice/dbus-broker.service
             ├─830 /usr/bin/dbus-broker-launch --scope system --audit
             └─848 dbus-broker --log 4 --controller 9 --machine-id 642eb5513d7746eaaab6ba590bd6814d --max-bytes 536870912 --max-fds 4096 --max-matches 131072 --audit

Aug 23 09:40:36 localhost systemd[1]: Starting dbus-broker.service - D-Bus System Message Bus...
Aug 23 09:40:36 localhost systemd[1]: Started dbus-broker.service - D-Bus System Message Bus.

dbus.socket

+ systemctl status dbus.socket
● dbus.socket - D-Bus System Message Bus Socket
     Loaded: loaded (/usr/lib/systemd/system/dbus.socket; enabled; preset: enabled)
     Active: active (running) since Fri 2024-08-23 09:40:36 EDT; 1min 10s ago
 Invocation: 54bdfb9c5d7f46b68a1f8076dfa47ac6
   Triggers: ● dbus-broker.service
     Listen: /run/dbus/system_bus_socket (Stream)
     CGroup: /system.slice/dbus.socket

Aug 23 09:40:36 localhost systemd[1]: Listening on dbus.socket - D-Bus System Message Bus Socket.

firewalld is installed at 09:41:50

        "Installed: firewalld-2.2.1-1.el10.noarch",

and started at 09:41:54

    "name": "firewalld",
    "state": "started",
    "status": {
        "AccessSELinuxContext": "system_u:object_r:firewalld_unit_file_t:s0",
        "ActiveEnterTimestampMonotonic": "0",
        "ActiveExitTimestampMonotonic": "0",
        "ActiveState": "inactive",
        "After": "sysinit.target basic.target dbus.socket polkit.service system.slice dbus-broker.service",
...
        "SubState": "dead",
...

[erig0]

That looks like dbus starts before firewalld is installed (and thus firewalld's dbus policy). So when firewalld attempts to claim the bus it's rejected. systemctl reload dbus-broker should work.

[richm]

That looks like dbus starts before firewalld is installed (and thus firewalld's dbus policy). So when firewalld attempts to claim the bus it's rejected. systemctl reload dbus-broker should work.

ok, but is this some new behavior in el10? Because I don't see this issue on fedora, el9, or earlier.

[erig0]

ok, but is this some new behavior in el10? Because I don't see this issue on fedora, el9, or earlier.

I don't think so. I don't see any firewalld.spec magic to reload dbus policies either.

Is it possible that for fedora, el9, etc. that the dbus policy was already in place?

[richm]

ok, but is this some new behavior in el10? Because I don't see this issue on fedora, el9, or earlier.

I don't think so. I don't see any firewalld.spec magic to reload dbus policies either.

Is it possible that for fedora, el9, etc. that the dbus policy was already in place?

Maybe - will have to check - but if so, then we have been "getting lucky" all this time in the firewall role, and the actual fix is to change the firewall role like this: https://github.com/linux-system-roles/firewall/blob/main/tasks/firewalld.yml#L32

- name: Install firewalld
  package:
    name: "{{ __firewall_packages_base }}"
    state: present
    use: "{{ (__firewall_is_ostree | d(false)) |
      ternary('ansible.posix.rhel_rpm_ostree', omit) }}"
  register: firewall_package_result

- name: Restart dbus-broker to ensure firewalld policy is loaded
  service:
    name: dbus-broker
    state: restarted
  when: firewall_package_result is changed

@erig0 wdyt?

[erig0]

@erig0 wdyt?

I think it's an acceptable quick fix.

I would expect this to be a common RPM scenario and thus have existing %post hooks similar to enabling the systemd service. A quick google search didn't yield anything.

[msekletar]

@richm restarting D-Bus message broker (original implementation or dbus-broker) is not supported during system runtime as it may have various negative consequences for software which is not able to deal with this (which is most dbus clients unfortunately). IOW, you certainly don't want restart but reload.

[erig0]

restarting D-Bus message broker (original implementation or dbus-broker) is not supported during system runtime

Right. A reload should work.

[richm]

restarting D-Bus message broker (original implementation or dbus-broker) is not supported during system runtime

Right. A reload should work.

@msekletar @erig0 ok - but - why is this now necessary in el10 after restarting journald? on el9 and earlier the code works fine even after restarting journald - on el10 it works fine if I do not restart journald

[erig0]

why is this now necessary in el10 after restarting journald?

I have no idea.

[richm]

why is this now necessary in el10 after restarting journald?

I have no idea.

@msekletar for context - the problem only happens after the logging test that configures rsyslog to listen to /dev/log, then restores journald to listen to /dev/log - https://github.com/linux-system-roles/logging/blob/main/tests/tests_imuxsock_files.yml#L107 - something about that restore process messes up firewalld listening to dbus - and it is only a problem on el10 - works fine on el9 and earlier

[msekletar]

@richm In general there is a bad design choice in D-Bus when it comes to handling configuration. It is loaded automatically and asynchronously based on inotify notification. You install the package which drops the policy and then you proceed with immediate start of the service then you might run into this problem. If you want to 100% avoid it you must reload D-Bus before attempting to start the service.

Why it happens now and wasn't happening previously I don't know but potential for the race was always there I think.

[richm]

@richm In general there is a bad design choice in D-Bus when it comes to handling configuration. It is loaded automatically and asynchronously based on inotify notification. You install the package which drops the policy and then you proceed with immediate start of the service then you might run into this problem. If you want to 100% avoid it you must reload D-Bus before attempting to start the service.

Why it happens now and wasn't happening previously I don't know but potential for the race was always there I think.

So we need to have something like this in every single system role that manages a dbus service?

- name: Install packages for $rolename
  package:
    name: "{{ __rolename_packages }}"
    state: present
    use: ...
  register: rolename_package_result

- name: Get services
  service_facts:
  when: rolename_package_result is changed

- name: Reload dbus service
  service:
    name: "{{ __dbus_service }}"
    state: reloaded
  vars:
    __dbus_service: "{{ 'dbus-broker' if 'dbus-broker' in ansible_facts['services']
      else 'dbus' }}"
  when: rolename_package_result is changed

- name: Start and enable services for $rolename
  service:
    name: "{{ item }"
    state: started
...

?

[erig0]

IMO, this should be fixed at the RPM/packaging level... or dbus itself considers a reload of policies when a bus claim is rejected due to policy. The latter may be DoS-y though.

[msekletar]

I agree, global posttrans file trigger might be the first step. Also maybe there is something to be addressed on D-Bus side.

[richm]

Closing in favor of #416