I tried to update NS8 and got this error:
What can I do to fix it?
Hi Fausp,
The message indicates that the core detected an update error from the “module instance loki1.”
You can find more information on the Logs page. Check the app log for loki1. If that doesn’t help, and your journal hasn’t been rotated yet, you can alternatively run this command:
journalctl -t agent@loki1
To fetch more records, use:
journalctl _UID=$(id -u loki1)
Hi davidep,
-- Boot 31fac6b247e2405baef9240e57c14951 --
Sep 12 22:03:31 apps systemd[968]: Queued start job for default target default.target.
Sep 12 22:03:32 apps dbus-daemon[1467]: [session uid=1003 pid=1467] Successfully activated service 'org.freedesktop.systemd1'
Sep 12 22:03:31 apps systemd[968]: Created slice app.slice - User Application Slice.
Sep 12 22:03:31 apps systemd[968]: Reached target paths.target - Paths.
Sep 12 22:03:31 apps systemd[968]: Reached target timers.target - Timers.
Sep 12 22:03:34 apps podman[1307]: 1e7fa00d5a4a96de0849b179e5bb8247d8998bed1cb7638d753f703df0b9cb46
Sep 12 22:03:31 apps systemd[968]: Starting dbus.socket - D-Bus User Message Bus Socket...
Sep 12 22:03:31 apps systemd[968]: Listening on dirmngr.socket - GnuPG network certificate management daemon.
Sep 12 22:03:34 apps podman[1492]: 1e7fa00d5a4a96de0849b179e5bb8247d8998bed1cb7638d753f703df0b9cb46
Sep 12 22:03:31 apps systemd[968]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers).
Sep 12 22:03:31 apps systemd[968]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted).
Sep 12 22:03:31 apps systemd[968]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation).
Sep 12 22:03:31 apps systemd[968]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache.
Sep 12 22:03:31 apps systemd[968]: Listening on dbus.socket - D-Bus User Message Bus Socket.
Sep 12 22:03:34 apps podman[1664]: 54182e99b55747e3ede9dc5033504cc122124bf363d714d417d88de43c1a947d
Sep 12 22:03:31 apps systemd[968]: Reached target sockets.target - Sockets.
Sep 12 22:03:31 apps systemd[968]: Reached target basic.target - Basic System.
Sep 12 22:03:31 apps systemd[968]: Started agent.service - Rootless module/loki1 agent.
Sep 12 22:03:31 apps systemd[968]: Starting loki.service - Loki pod service...
Sep 12 22:03:32 apps podman[1307]: 2024-09-12 22:03:32.041477491 +0200 CEST m=+0.214788966 system refresh
Sep 12 22:03:32 apps systemd[968]: Created slice session.slice - User Core Session Slice.
Sep 12 22:03:32 apps systemd[968]: Starting dbus.service - D-Bus User Message Bus...
Sep 12 22:03:32 apps systemd[968]: Started dbus.service - D-Bus User Message Bus.
Sep 12 22:03:32 apps systemd[968]: Created slice user.slice - Slice /user.
Sep 12 22:03:32 apps systemd[968]: Created slice user-libpod_pod_1e7fa00d5a4a96de0849b179e5bb8247d8998bed1cb7638d753f703df0b9cb46.slice - cgroup user-libpod_pod_1e7fa00d5a4>
Sep 12 22:03:32 apps podman[1307]:
Sep 12 22:03:32 apps podman[1307]: 2024-09-12 22:03:32.283739748 +0200 CEST m=+0.457051204 container create d47020dd7b38e58f86c91851c1fe85dd14a0fb1a5cf1a0fdfb5c5c88deff59c0>
Sep 12 22:03:32 apps podman[1307]: 2024-09-12 22:03:32.285387254 +0200 CEST m=+0.458698693 pod create 1e7fa00d5a4a96de0849b179e5bb8247d8998bed1cb7638d753f703df0b9cb46 (imag>
Sep 12 22:03:32 apps systemd[968]: Started podman-pause-5b221390.scope.
Sep 12 22:03:32 apps systemd[968]: Started libpod-d47020dd7b38e58f86c91851c1fe85dd14a0fb1a5cf1a0fdfb5c5c88deff59c0.scope - libcrun container.
Sep 12 22:03:32 apps podman[1492]: 2024-09-12 22:03:32.82229407 +0200 CEST m=+0.493177379 container init d47020dd7b38e58f86c91851c1fe85dd14a0fb1a5cf1a0fdfb5c5c88deff59c0 (i>
Sep 12 22:03:32 apps podman[1492]: 2024-09-12 22:03:32.834657262 +0200 CEST m=+0.505540537 container start d47020dd7b38e58f86c91851c1fe85dd14a0fb1a5cf1a0fdfb5c5c88deff59c0 >
Sep 12 22:03:32 apps podman[1492]: 2024-09-12 22:03:32.834768161 +0200 CEST m=+0.505651462 pod start 1e7fa00d5a4a96de0849b179e5bb8247d8998bed1cb7638d753f703df0b9cb46 (image>
Sep 12 22:03:32 apps systemd[968]: Started loki.service - Loki pod service.
Sep 12 22:03:32 apps systemd[968]: Reached target default.target - Main User Target.
Sep 12 22:03:32 apps systemd[968]: Starting loki-server.service - Loki server...
Sep 12 22:03:32 apps systemd[968]: Starting traefik.service - Loki frontend HTTP proxy...
Sep 12 22:03:33 apps podman[1664]: 2024-09-12 22:03:32.923317913 +0200 CEST m=+0.061251280 image pull docker.io/grafana/loki:2.2.1
Sep 12 22:03:34 apps podman[1664]:
Sep 12 22:03:34 apps podman[1664]: 2024-09-12 22:03:34.676994914 +0200 CEST m=+1.814928274 container create 54182e99b55747e3ede9dc5033504cc122124bf363d714d417d88de43c1a947d>
Sep 12 22:03:34 apps podman[1730]: 2024-09-12 22:03:34.632024232 +0200 CEST m=+1.656261941 image pull docker.io/traefik:v2.4
Sep 12 22:03:34 apps systemd[968]: Started libpod-54182e99b55747e3ede9dc5033504cc122124bf363d714d417d88de43c1a947d.scope - libcrun container.
Sep 12 22:03:34 apps podman[1664]: 2024-09-12 22:03:34.811374048 +0200 CEST m=+1.949307432 container init 54182e99b55747e3ede9dc5033504cc122124bf363d714d417d88de43c1a947d (>
Sep 12 22:03:34 apps podman[1664]: 2024-09-12 22:03:34.932769696 +0200 CEST m=+2.070703040 container start 54182e99b55747e3ede9dc5033504cc122124bf363d714d417d88de43c1a947d >
Sep 12 22:03:35 apps loki-server[1893]: level=error ts=2024-09-12T20:03:35.15017624Z caller=mapper.go:42 msg="unable to read rules directory" path=/loki/rules-temp err="ope>
Sep 12 22:03:37 apps podman[1730]:
Sep 12 22:03:37 apps systemd[968]: Started loki-server.service - Loki server.
Sep 12 22:03:37 apps podman[1730]: 2024-09-12 22:03:37.700825908 +0200 CEST m=+4.725063553 container create 56f0f88b61aca691b348dd614baa75b304597f88db681da566d237f76348208a>
Sep 12 22:03:37 apps systemd[968]: Started libpod-56f0f88b61aca691b348dd614baa75b304597f88db681da566d237f76348208a.scope - libcrun container.
Sep 12 22:03:37 apps podman[1730]: 2024-09-12 22:03:37.826360231 +0200 CEST m=+4.850597863 container init 56f0f88b61aca691b348dd614baa75b304597f88db681da566d237f76348208a (>
Sep 12 22:03:37 apps podman[1730]: 2024-09-12 22:03:37.836845013 +0200 CEST m=+4.861082655 container start 56f0f88b61aca691b348dd614baa75b304597f88db681da566d237f76348208a >
Sep 12 22:03:37 apps podman[1730]: 56f0f88b61aca691b348dd614baa75b304597f88db681da566d237f76348208a
Sep 12 22:03:37 apps systemd[968]: Started traefik.service - Loki frontend HTTP proxy.
Sep 12 22:03:37 apps systemd[968]: Startup finished in 6.623s.
Sep 12 22:03:38 apps traefik[2157]: time="2024-09-12T20:03:38Z" level=info msg="Configuration loaded from flags."
Sep 12 22:04:53 apps agent@loki1[1092]: Signal "user defined signal 1" caught: shutdown started.
Sep 12 22:04:53 apps systemd[968]: agent.service: Scheduled restart job, restart counter is at 1.
Sep 12 22:04:53 apps systemd[968]: Stopped agent.service - Rootless module/loki1 agent.
Sep 12 22:04:53 apps systemd[968]: Started agent.service - Rootless module/loki1 agent.
Sep 12 22:04:53 apps agent@loki1[5882]: redis: 2024/09/12 22:04:53 pubsub.go:159: redis: discarding bad PubSub connection: EOF
Sep 12 22:05:05 apps agent@loki1[5882]: task/module/loki1/9e0b73fa-adc4-4ab5-8bf0-dcb89c189ddf: update-module/05pullimages is starting
Sep 12 22:05:05 apps agent@loki1[5882]: Signal "user defined signal 1" caught: shutdown started.
Sep 12 22:05:05 apps agent@loki1[5882]: Traceback (most recent call last):
Sep 12 22:05:05 apps agent@loki1[5882]: File "/usr/local/agent/actions/update-module/05pullimages", line 23, in <module>
Sep 12 22:05:05 apps agent@loki1[5882]: import agent
Sep 12 22:05:05 apps agent@loki1[5882]: File "/usr/local/agent/pypkg/agent/__init__.py", line 21, in <module>
Sep 12 22:05:05 apps agent@loki1[5882]: import redis
Sep 12 22:05:05 apps agent@loki1[5882]: ModuleNotFoundError: No module named 'redis'
Sep 12 22:05:05 apps agent@loki1[5882]: task/module/loki1/9e0b73fa-adc4-4ab5-8bf0-dcb89c189ddf: action "update-module" status is "aborted" (1) at step 05pullimages
Sep 12 22:05:05 apps systemd[968]: agent.service: Scheduled restart job, restart counter is at 2.
Sep 12 22:05:05 apps systemd[968]: Stopped agent.service - Rootless module/loki1 agent.
Sep 12 22:05:05 apps systemd[968]: Started agent.service - Rootless module/loki1 agent.
Sep 12 22:05:05 apps agent@loki1[7032]: redis: 2024/09/12 22:05:05 pubsub.go:159: redis: discarding bad PubSub connection: EOF
Sep 12 22:05:13 apps agent@loki1[7032]: task/module/loki1/aee01fa0-b046-4481-9ac7-c00153e22171: update-module/05pullimages is starting
Sep 12 22:05:13 apps agent@loki1[7032]: Traceback (most recent call last):
Sep 12 22:05:13 apps agent@loki1[7032]: File "/usr/local/agent/actions/update-module/05pullimages", line 23, in <module>
Sep 12 22:05:13 apps agent@loki1[7032]: import agent
Sep 12 22:05:13 apps agent@loki1[7032]: File "/usr/local/agent/pypkg/agent/__init__.py", line 21, in <module>
Sep 12 22:05:13 apps agent@loki1[7032]: import redis
Sep 12 22:05:13 apps agent@loki1[7032]: ModuleNotFoundError: No module named 'redis'
Sep 12 22:05:13 apps agent@loki1[7032]: task/module/loki1/aee01fa0-b046-4481-9ac7-c00153e22171: action "update-module" status is "aborted" (1) at step 05pullimages
Sep 12 22:08:08 apps agent@loki1[7032]: Signal "user defined signal 1" caught: shutdown started.
Sep 12 22:08:08 apps systemd[968]: agent.service: Scheduled restart job, restart counter is at 3.
Sep 12 22:08:08 apps systemd[968]: Stopped agent.service - Rootless module/loki1 agent.
Sep 12 22:08:08 apps systemd[968]: Started agent.service - Rootless module/loki1 agent.
Sep 12 22:08:08 apps agent@loki1[18772]: redis: 2024/09/12 22:08:08 pubsub.go:159: redis: discarding bad PubSub connection: EOF
Sep 12 22:08:17 apps agent@loki1[18772]: task/module/loki1/61b85ba4-e90a-42a3-a5f0-52e0c9e994b1: update-module/05pullimages is starting
Sep 12 22:08:17 apps agent@loki1[18772]: Traceback (most recent call last):
Sep 12 22:08:17 apps agent@loki1[18772]: File "/usr/local/agent/actions/update-module/05pullimages", line 23, in <module>
Sep 12 22:08:17 apps agent@loki1[18772]: import agent
Sep 12 22:08:17 apps agent@loki1[18772]: File "/usr/local/agent/pypkg/agent/__init__.py", line 21, in <module>
Sep 12 22:08:17 apps agent@loki1[18772]: import redis
Sep 12 22:08:17 apps agent@loki1[18772]: ModuleNotFoundError: No module named 'redis'
Sep 12 22:08:17 apps agent@loki1[18772]: task/module/loki1/61b85ba4-e90a-42a3-a5f0-52e0c9e994b1: action "update-module" status is "aborted" (1) at step 05pullimages
Sep 12 22:15:33 apps agent@loki1[18772]: Signal "user defined signal 1" caught: shutdown started.
Sep 12 22:15:33 apps systemd[968]: agent.service: Scheduled restart job, restart counter is at 4.
Sep 12 22:15:33 apps systemd[968]: Stopped agent.service - Rootless module/loki1 agent.
Sep 12 22:15:33 apps systemd[968]: Started agent.service - Rootless module/loki1 agent.
Sep 12 22:15:42 apps agent@loki1[46675]: task/module/loki1/a5283322-f19c-41ae-8169-473d08617d3c: update-module/05pullimages is starting
Sep 12 22:15:42 apps agent@loki1[46675]: Traceback (most recent call last):
Sep 12 22:15:42 apps agent@loki1[46675]: File "/usr/local/agent/actions/update-module/05pullimages", line 23, in <module>
Sep 12 22:15:42 apps agent@loki1[46675]: import agent
Sep 12 22:15:42 apps agent@loki1[46675]: File "/usr/local/agent/pypkg/agent/__init__.py", line 21, in <module>
Sep 12 22:15:42 apps agent@loki1[46675]: import redis
Sep 12 22:15:42 apps agent@loki1[46675]: ModuleNotFoundError: No module named 'redis'
Sep 12 22:15:42 apps agent@loki1[46675]: task/module/loki1/a5283322-f19c-41ae-8169-473d08617d3c: action "update-module" status is "aborted" (1) at step 05pullimages
lines 461-507/507 (END)
There’s something strange here:
Sep 12 22:05:05 apps agent@loki1[5882]: ModuleNotFoundError: No module named 'redis'
It looks like Python can’t find the ‘redis’ package. Try running this command to check if the error was temporary:
runagent -m loki1 redis-exec EXISTS module/loki1/environment
Output should be 1…
Any suggestions what I can do to fix it?
From your screenshots, it looks like there’s a Python 3 misconfiguration. I’m not sure why this happened. Let’s try running a few commands as root. I’m using Rocky Linux, but your output should be similar:
[root@leader ~]# readlink /usr/local/agent/pyenv/bin/python3
python3.11
[root@leader ~]# readlink /usr/local/agent/pyenv/bin/python3.11
/usr/bin/python3.11
[root@leader ~]# ls -l /usr/bin/python3.11
-rwxr-xr-x. 1 root root 15632 Sep 3 21:28 /usr/bin/python3.11
[root@leader ~]# /usr/local/agent/pyenv/bin/python3 -c 'import redis, agent' && echo ok
ok
[root@leader ~]# runagent python3 -c 'import redis' && echo ok
ok
Interesting, I expected an error similar to ‘Defekter Interpreter’ or ‘Permission denied’ like we saw three days ago!
Do you get a different result if you run the following command today?
runagent -m loki1 redis-exec EXISTS module/loki1/environment
And also
runagent -m loki1 python3 -c 'import redis' && echo ok
Let’s check runagent permissions:
stat /usr/local/bin/runagent
Repeat also for parent dirs:
stat /usr/local/bin
stat /usr/local
stat /usr
If possible, avoid screenshots: paste plain text instead.
root@apps:/home/support# stat /usr/local/bin/runagent
Datei: /usr/local/bin/runagent
Größe: 3694 Blöcke: 8 EA Block: 4096 reguläre Datei
Gerät: 8/1 Inode: 8521945 Verknüpfungen: 1
Zugriff: (0755/-rwxr-xr-x) Uid: ( 0/ root) Gid: ( 0/ root)
Zugriff: 2024-09-15 21:55:19.674648167 +0200
Modifiziert: 2024-09-12 09:52:02.000000000 +0200
Geändert: 2024-09-12 21:55:11.915004126 +0200
Geburt: 2024-09-12 21:55:11.915004126 +0200
root@apps:/home/support#
root@apps:/home/support#
root@apps:/home/support#
root@apps:/home/support# stat /usr/local/bin
Datei: /usr/local/bin
Größe: 4096 Blöcke: 8 EA Block: 4096 Verzeichnis
Gerät: 8/1 Inode: 8521086 Verknüpfungen: 2
Zugriff: (0755/drwxr-xr-x) Uid: ( 0/ root) Gid: ( 0/ root)
Zugriff: 2024-09-16 02:10:41.873143565 +0200
Modifiziert: 2024-09-12 09:54:21.000000000 +0200
Geändert: 2024-09-12 21:55:11.915004126 +0200
Geburt: 2024-06-27 19:51:14.939603000 +0200
root@apps:/home/support#
root@apps:/home/support#
root@apps:/home/support#
root@apps:/home/support# stat /usr/local
Datei: /usr/local
Größe: 4096 Blöcke: 8 EA Block: 4096 Verzeichnis
Gerät: 8/1 Inode: 8521082 Verknüpfungen: 11
Zugriff: (0755/drwxr-xr-x) Uid: ( 0/ root) Gid: ( 0/ root)
Zugriff: 2024-07-08 14:44:19.295295817 +0200
Modifiziert: 2024-09-12 09:52:02.000000000 +0200
Geändert: 2024-09-12 21:55:11.915004126 +0200
Geburt: 2024-06-27 19:51:14.935603000 +0200
root@apps:/home/support#
root@apps:/home/support#
root@apps:/home/support#
root@apps:/home/support# stat /usr
Datei: /usr
Größe: 4096 Blöcke: 8 EA Block: 4096 Verzeichnis
Gerät: 8/1 Inode: 8519681 Verknüpfungen: 12
Zugriff: (0755/drwxr-xr-x) Uid: ( 0/ root) Gid: ( 0/ root)
Zugriff: 2024-09-16 11:41:38.405927333 +0200
Modifiziert: 2024-09-12 09:52:02.000000000 +0200
Geändert: 2024-09-12 21:55:11.915004126 +0200
Geburt: 2024-06-27 19:51:04.423603000 +0200
The filesystem permissions for runagent seem correct.
Did you become root using sudo? If you know the root password, try running the same commands directly from the system console by logging in as root.
Yes, I did it with root permissions - #
If you know the root password, do not use sudo. Log in as root from the system console and try running the same commands. Do you get the same result?
Sorry, I was asking you to run these commands again in a root shell, obtained directly from password login (not by switching to root with sudo from another account).
runagent -m loki1 python3 -c 'import redis' && echo ok
runagent -m loki1 redis-exec EXISTS module/loki1/environment
I want to rule out any possible environment manipulations.
Alright, thanks. Let’s do something similar to check the Python 3 path. Please run the following command and paste here the output as well:
stat /usr/local/agent/pyenv/bin/python3.11 /usr/local/agent/pyenv/bin/ /usr/local/agent/pyenv/ /usr/local/agent/
