You are not logged in.

#1 2024-01-30 22:30:21

Altay_H
Member
Registered: 2009-01-31
Posts: 40

[SOLVED] Log spam from iwd

Starting around 2024-01-24 iwd has been spamming the following two warnings to my systemd logs every 5 minutes:

iwd[349]: WARNING: src/resolve.c:resolve_systemd_set_domains() condition !systemd_state.is_ready failed
iwd[349]: WARNING: src/resolve.c:resolve_systemd_set_dns() condition !systemd_state.is_ready failed

These are coming from here and here respectively.

As far as I can tell my WiFi connection is fine, but the log spam is annoying. Is anyone else experiencing this, and is it actionable in any way?

Last edited by Altay_H (2024-02-01 14:55:23)

Offline

#2 2024-01-30 22:48:29

seth
Member
Registered: 2012-09-03
Posts: 51,332

Re: [SOLVED] Log spam from iwd

every 5 minutes

Are you running concurrent services?
Please post the output of

find /etc/systemd -type l -exec test -f {} \; -print | awk -F'/' '{ printf ("%-40s | %s\n", $(NF-0), $(NF-1)) }' | sort -f

https://gitlab.archlinux.org/archlinux/ … 84723eda5c doesn't look like it'd cause different behavior

Offline

#3 2024-01-30 22:50:37

Altay_H
Member
Registered: 2009-01-31
Posts: 40

Re: [SOLVED] Log spam from iwd

$ find /etc/systemd -type l -exec test -f {} \; -print | awk -F'/' '{ printf ("%-40s | %s\n", $(NF-0), $(NF-1)) }' | sort -f
certbot-renew.timer                      | timers.target.wants
ddclient.service                         | multi-user.target.wants
disable-transparent-huge-pages.service   | basic.target.wants
fstrim.timer                             | timers.target.wants
getty@tty1.service                       | getty.target.wants
httpd.service                            | multi-user.target.wants
iwd.service                              | multi-user.target.wants
mongodb.service                          | multi-user.target.wants
nfs-server.service                       | multi-user.target.wants
p11-kit-server.socket                    | sockets.target.wants
php-fpm.service                          | multi-user.target.wants
pipewire.socket                          | sockets.target.wants
pm2-altay.service                        | multi-user.target.wants
pulseaudio.socket                        | sockets.target.wants
remote-fs.target                         | multi-user.target.wants
sshd.service                             | multi-user.target.wants
systemd-timesyncd.service                | sysinit.target.wants
udisks2.service                          | graphical.target.wants
xdg-user-dirs-update.service             | default.target.wants

Offline

#4 2024-01-30 22:53:35

seth
Member
Registered: 2012-09-03
Posts: 51,332

Re: [SOLVED] Log spam from iwd

"No" - instead of the date, check the pacman log which iwd versions were actually involved on the critical update during that time.
Did you maybe switch from dbus-daemon to dbus-broker at that time?
Is there more context to the warnings (other services)?

Offline

#5 2024-01-30 23:13:39

Altay_H
Member
Registered: 2009-01-31
Posts: 40

Re: [SOLVED] Log spam from iwd

seth wrote:

"No" - instead of the date, check the pacman log which iwd versions were actually involved on the critical update during that time.

Here's everything from my pacman log on that day:

[2024-01-24T09:35:45-0500] [PACMAN] Running 'pacman --sync -y -u --'
[2024-01-24T09:35:45-0500] [PACMAN] synchronizing package lists
[2024-01-24T09:35:45-0500] [PACMAN] starting full system upgrade
[2024-01-24T09:35:53-0500] [ALPM] running '60-mkinitcpio-remove.hook'...
[2024-01-24T09:35:53-0500] [ALPM] transaction started
[2024-01-24T09:35:53-0500] [ALPM] upgraded ca-certificates-mozilla (3.96.1-1 -> 3.97-1)
[2024-01-24T09:35:53-0500] [ALPM] upgraded glib2 (2.78.3-1 -> 2.78.4-1)
[2024-01-24T09:35:53-0500] [ALPM] warning: directory permissions differ on /usr/share/polkit-1/rules.d/filesystem: 750  package: 755
[2024-01-24T09:35:53-0500] [ALPM] upgraded fwupd (1.9.11-2 -> 1.9.12-1)
[2024-01-24T09:35:53-0500] [ALPM] upgraded libcolord (1.4.6-1 -> 1.4.7-1)
[2024-01-24T09:35:53-0500] [ALPM] upgraded gtk3 (1:3.24.40-2 -> 1:3.24.41-1)
[2024-01-24T09:35:53-0500] [ALPM] upgraded nss (3.96.1-1 -> 3.97-1)
[2024-01-24T09:35:53-0500] [ALPM] upgraded lib32-nss (3.96.1-1 -> 3.97-1)
[2024-01-24T09:35:54-0500] [ALPM] upgraded linux (6.7.arch3-1 -> 6.7.1.arch1-1)
[2024-01-24T09:35:54-0500] [ALPM] upgraded orc (0.4.34-1 -> 0.4.35-1)
[2024-01-24T09:35:54-0500] [ALPM] upgraded xdg-utils (1.2.0r25+g0f49cf5-1 -> 1.2.0r28+g9b7d253-1)
[2024-01-24T09:35:54-0500] [ALPM] transaction completed
[2024-01-24T09:35:54-0500] [ALPM] running '20-systemd-sysusers.hook'...
[2024-01-24T09:35:54-0500] [ALPM] running '30-systemd-daemon-reload-system.hook'...
[2024-01-24T09:35:55-0500] [ALPM] running '30-systemd-udev-reload.hook'...
[2024-01-24T09:35:55-0500] [ALPM] running '30-systemd-update.hook'...
[2024-01-24T09:35:55-0500] [ALPM] running '40-update-ca-trust.hook'...
[2024-01-24T09:35:56-0500] [ALPM] running '60-depmod.hook'...
[2024-01-24T09:35:57-0500] [ALPM] running '90-mkinitcpio-install.hook'...
[2024-01-24T09:35:57-0500] [ALPM-SCRIPTLET] ==> Building image from preset: /etc/mkinitcpio.d/linux.preset: 'default'
[2024-01-24T09:35:57-0500] [ALPM-SCRIPTLET] ==> Using default configuration file: '/etc/mkinitcpio.conf'
[2024-01-24T09:35:57-0500] [ALPM-SCRIPTLET]   -> -k /boot/vmlinuz-linux -g /boot/initramfs-linux.img --microcode /boot/intel-ucode.img
[2024-01-24T09:35:57-0500] [ALPM-SCRIPTLET] ==> Starting build: '6.7.1-arch1-1'
[2024-01-24T09:35:57-0500] [ALPM-SCRIPTLET]   -> Running build hook: [base]
[2024-01-24T09:35:57-0500] [ALPM-SCRIPTLET]   -> Running build hook: [udev]
[2024-01-24T09:35:58-0500] [ALPM-SCRIPTLET]   -> Running build hook: [autodetect]
[2024-01-24T09:35:58-0500] [ALPM-SCRIPTLET]   -> Running build hook: [modconf]
[2024-01-24T09:35:58-0500] [ALPM-SCRIPTLET]   -> Running build hook: [kms]
[2024-01-24T09:35:58-0500] [ALPM-SCRIPTLET]   -> Running build hook: [keyboard]
[2024-01-24T09:35:58-0500] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: 'xhci_pci'
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET]   -> Running build hook: [keymap]
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET]   -> Running build hook: [consolefont]
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET] ==> WARNING: consolefont: no font found in configuration
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET]   -> Running build hook: [block]
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET]   -> Running build hook: [filesystems]
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET]   -> Running build hook: [fsck]
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET] ==> Generating module dependencies
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET] ==> Creating zstd-compressed initcpio image: '/boot/initramfs-linux.img'
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET] ==> Image generation successful
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET] ==> Building image from preset: /etc/mkinitcpio.d/linux.preset: 'fallback'
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET] ==> Using default configuration file: '/etc/mkinitcpio.conf'
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET]   -> -k /boot/vmlinuz-linux -g /boot/initramfs-linux-fallback.img -S autodetect --microcode /boot/intel-ucode.img
[2024-01-24T09:35:59-0500] [ALPM-SCRIPTLET] ==> Starting build: '6.7.1-arch1-1'
[2024-01-24T09:36:00-0500] [ALPM-SCRIPTLET]   -> Running build hook: [base]
[2024-01-24T09:36:00-0500] [ALPM-SCRIPTLET]   -> Running build hook: [udev]
[2024-01-24T09:36:00-0500] [ALPM-SCRIPTLET]   -> Running build hook: [modconf]
[2024-01-24T09:36:00-0500] [ALPM-SCRIPTLET]   -> Running build hook: [kms]
[2024-01-24T09:36:06-0500] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: 'ast'
[2024-01-24T09:36:07-0500] [ALPM-SCRIPTLET]   -> Running build hook: [keyboard]
[2024-01-24T09:36:07-0500] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: 'xhci_pci'
[2024-01-24T09:36:07-0500] [ALPM-SCRIPTLET]   -> Running build hook: [keymap]
[2024-01-24T09:36:07-0500] [ALPM-SCRIPTLET]   -> Running build hook: [consolefont]
[2024-01-24T09:36:07-0500] [ALPM-SCRIPTLET] ==> WARNING: consolefont: no font found in configuration
[2024-01-24T09:36:07-0500] [ALPM-SCRIPTLET]   -> Running build hook: [block]
[2024-01-24T09:36:08-0500] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: 'qed'
[2024-01-24T09:36:08-0500] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: 'qla2xxx'
[2024-01-24T09:36:08-0500] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: 'bfa'
[2024-01-24T09:36:08-0500] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: 'aic94xx'
[2024-01-24T09:36:08-0500] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: 'wd719x'
[2024-01-24T09:36:08-0500] [ALPM-SCRIPTLET] ==> WARNING: Possibly missing firmware for module: 'qla1280'
[2024-01-24T09:36:10-0500] [ALPM-SCRIPTLET]   -> Running build hook: [filesystems]
[2024-01-24T09:36:11-0500] [ALPM-SCRIPTLET]   -> Running build hook: [fsck]
[2024-01-24T09:36:12-0500] [ALPM-SCRIPTLET] ==> Generating module dependencies
[2024-01-24T09:36:12-0500] [ALPM-SCRIPTLET] ==> Creating zstd-compressed initcpio image: '/boot/initramfs-linux-fallback.img'
[2024-01-24T09:36:14-0500] [ALPM-SCRIPTLET] ==> Image generation successful
[2024-01-24T09:36:14-0500] [ALPM] running 'dbus-reload.hook'...
[2024-01-24T09:36:14-0500] [ALPM] running 'glib-compile-schemas.hook'...
[2024-01-24T09:36:14-0500] [ALPM] running 'gtk-query-immodules-3.0.hook'...
[2024-01-24T09:36:14-0500] [ALPM] running 'gtk-update-icon-cache.hook'...
[2024-01-24T11:10:31-0500] [PACMAN] Running 'pacman --sync -y -u --'
[2024-01-24T11:10:31-0500] [PACMAN] synchronizing package lists
[2024-01-24T11:10:31-0500] [PACMAN] starting full system upgrade
[2024-01-24T11:16:36-0500] [PACMAN] Running 'pacman --sync -y -u --'
[2024-01-24T11:16:36-0500] [PACMAN] synchronizing package lists
[2024-01-24T11:16:36-0500] [PACMAN] starting full system upgrade
[2024-01-24T15:11:31-0500] [PACMAN] Running 'pacman --sync -y -u --'
[2024-01-24T15:11:31-0500] [PACMAN] synchronizing package lists
[2024-01-24T15:11:31-0500] [PACMAN] starting full system upgrade
[2024-01-24T15:17:12-0500] [PACMAN] Running 'pacman --sync -y -u --'
[2024-01-24T15:17:12-0500] [PACMAN] synchronizing package lists
[2024-01-24T15:17:12-0500] [PACMAN] starting full system upgrade
[2024-01-24T17:24:19-0500] [PACMAN] Running 'pacman --sync -y -u --'
[2024-01-24T17:24:19-0500] [PACMAN] synchronizing package lists
[2024-01-24T17:24:20-0500] [PACMAN] starting full system upgrade
[2024-01-24T17:52:28-0500] [PACMAN] Running 'pacman --sync -y -u --'
[2024-01-24T17:52:28-0500] [PACMAN] synchronizing package lists
[2024-01-24T17:52:29-0500] [PACMAN] starting full system upgrade
[2024-01-24T17:52:32-0500] [ALPM] transaction started
[2024-01-24T17:52:32-0500] [ALPM] upgraded openmpi (4.1.6-2 -> 4.1.6-3)
[2024-01-24T17:52:32-0500] [ALPM] transaction completed
[2024-01-24T17:52:32-0500] [ALPM] running '30-systemd-update.hook'...
seth wrote:

Did you maybe switch from dbus-daemon to dbus-broker at that time?

No, I made that switch on the 9th.

[2024-01-09T16:45:05-0500] [ALPM] installed dbus-broker (35-2)
seth wrote:

Is there more context to the warnings (other services)?

Not in journalctl. It's pretty much just these warnings back-to-back.

Jan 30 18:00:37 thinkpad-x1-yoga-g2 iwd[349]: WARNING: src/resolve.c:resolve_systemd_set_domains() condition !systemd_state.is_ready failed
Jan 30 18:00:37 thinkpad-x1-yoga-g2 iwd[349]: WARNING: src/resolve.c:resolve_systemd_set_dns() condition !systemd_state.is_ready failed
Jan 30 17:55:53 thinkpad-x1-yoga-g2 iwd[349]: WARNING: src/resolve.c:resolve_systemd_set_domains() condition !systemd_state.is_ready failed
Jan 30 17:55:53 thinkpad-x1-yoga-g2 iwd[349]: WARNING: src/resolve.c:resolve_systemd_set_dns() condition !systemd_state.is_ready failed
Jan 30 17:51:08 thinkpad-x1-yoga-g2 iwd[349]: WARNING: src/resolve.c:resolve_systemd_set_domains() condition !systemd_state.is_ready failed
Jan 30 17:51:08 thinkpad-x1-yoga-g2 iwd[349]: WARNING: src/resolve.c:resolve_systemd_set_dns() condition !systemd_state.is_ready failed
Jan 30 17:46:06 thinkpad-x1-yoga-g2 iwd[349]: WARNING: src/resolve.c:resolve_systemd_set_domains() condition !systemd_state.is_ready failed
Jan 30 17:46:06 thinkpad-x1-yoga-g2 iwd[349]: WARNING: src/resolve.c:resolve_systemd_set_dns() condition !systemd_state.is_ready failed
Jan 30 17:34:11 thinkpad-x1-yoga-g2 iwd[349]: WARNING: src/resolve.c:resolve_systemd_set_domains() condition !systemd_state.is_ready failed
Jan 30 17:34:11 thinkpad-x1-yoga-g2 iwd[349]: WARNING: src/resolve.c:resolve_systemd_set_dns() condition !systemd_state.is_ready failed

I have been getting these messages for as far back as my logs go, but it used to be more like twice a day:

Oct 20 11:49:56 thinkpad-x1-yoga-g2 iwd[362]: WARNING: src/resolve.c:resolve_systemd_set_domains() condition !systemd_state.is_ready failed
Oct 20 11:49:56 thinkpad-x1-yoga-g2 iwd[362]: WARNING: src/resolve.c:resolve_systemd_set_dns() condition !systemd_state.is_ready failed
Oct 20 11:49:56 thinkpad-x1-yoga-g2 iwd[362]: [DHCPv4] dhcp_client_rx_message:900 Entering state: DHCP_STATE_BOUND
Oct 20 11:49:56 thinkpad-x1-yoga-g2 iwd[362]: [DHCPv4] dhcp_client_t1_expired:619 Entering state: DHCP_STATE_RENEWING
Oct 20 00:44:28 thinkpad-x1-yoga-g2 iwd[362]: [DHCPv4] dhcp_client_rx_message:933 T1 expiring in 39927859 ms
Oct 20 00:44:28 thinkpad-x1-yoga-g2 iwd[362]: WARNING: src/resolve.c:resolve_systemd_set_domains() condition !systemd_state.is_ready failed
Oct 20 00:44:28 thinkpad-x1-yoga-g2 iwd[362]: WARNING: src/resolve.c:resolve_systemd_set_dns() condition !systemd_state.is_ready failed
Oct 20 00:44:28 thinkpad-x1-yoga-g2 iwd[362]: [DHCPv4] dhcp_client_rx_message:900 Entering state: DHCP_STATE_BOUND
Oct 20 00:44:28 thinkpad-x1-yoga-g2 iwd[362]: [DHCPv4] dhcp_client_t1_expired:619 Entering state: DHCP_STATE_RENEWING
Oct 19 12:44:39 thinkpad-x1-yoga-g2 iwd[362]: WARNING: src/resolve.c:resolve_systemd_set_domains() condition !systemd_state.is_ready failed
Oct 19 12:44:39 thinkpad-x1-yoga-g2 iwd[362]: WARNING: src/resolve.c:resolve_systemd_set_dns() condition !systemd_state.is_ready failed
Oct 19 12:44:29 thinkpad-x1-yoga-g2 iwd[362]: [DHCPv4] dhcp_client_rx_message:933 T1 expiring in 43199058 ms
Oct 19 12:44:29 thinkpad-x1-yoga-g2 iwd[362]: WARNING: src/resolve.c:resolve_systemd_set_domains() condition !systemd_state.is_ready failed
Oct 19 12:44:29 thinkpad-x1-yoga-g2 iwd[362]: WARNING: src/resolve.c:resolve_systemd_set_dns() condition !systemd_state.is_ready failed

I didn't think much of it until it started happening regularly last week.

Actually, come to think of it, I did switch my router from IPv4 to IPv6 on the 24th right around when this started. Could that be the culprit?

Offline

#6 2024-01-30 23:20:08

seth
Member
Registered: 2012-09-03
Posts: 51,332

Re: [SOLVED] Log spam from iwd

Those are for the re-lease (ie. shows up when fetching a new IP) and itr, yes, could very much be the IPv switch - do you still get any IPv4 at all?

Offline

#7 2024-01-30 23:26:42

Altay_H
Member
Registered: 2009-01-31
Posts: 40

Re: [SOLVED] Log spam from iwd

seth wrote:

do you still get any IPv4 at all?

Yes, I have (and use) a new IPv4 address after the switch.

Offline

#8 2024-01-31 08:34:40

seth
Member
Registered: 2012-09-03
Posts: 51,332

Re: [SOLVED] Log spam from iwd

Not in journalctl. It's pretty much just these warnings back-to-back.

Since they're apart, are you filtering the journal (eg. for iwd)?
Don't - the relevant messages might come from kernel or some network related userspace process.
Did you try to revert the router settings?

Offline

#9 2024-02-01 14:54:32

Altay_H
Member
Registered: 2009-01-31
Posts: 40

Re: [SOLVED] Log spam from iwd

seth wrote:

Since they're apart, are you filtering the journal (eg. for iwd)?

No, there's nothing from the kernel or other processes between these messages for the most part. Hence my post about log spam.

seth wrote:

Did you try to revert the router settings?

Yes, I switched it back to IPv4 last night and the log spam stopped.

Offline

Board footer

Powered by FluxBB