Fluidd can't reach Moonraker #11

Okywan · 2022-02-25T21:23:19Z

When starting the stack without the -d option, this is the log:

Attaching to fluidd, klipper, moonraker, traefik, ustreamer
ustreamer | -- INFO [10493.930 main] -- Using internal blank placeholder
ustreamer | -- INFO [10493.931 main] -- Listening HTTP on [0.0.0.0]:8080
ustreamer | -- INFO [10493.931 http] -- Starting HTTP eventloop ...
ustreamer | -- INFO [10493.932 stream] -- Using V4L2 device: /dev/webcam
ustreamer | -- INFO [10493.932 stream] -- Using desired FPS: 30
ustreamer | ================================================================================
traefik | time="2022-02-25T21:00:24Z" level=info msg="Configuration loaded from flags."
ustreamer | -- INFO [10494.020 stream] -- Device fd=8 opened
ustreamer | -- INFO [10494.021 stream] -- Using input channel: 0
ustreamer | -- ERROR [10494.022 stream] -- Requested resolution=1280x960 is unavailable
ustreamer | -- INFO [10494.022 stream] -- Using resolution: 1280x720
ustreamer | -- INFO [10494.023 stream] -- Using pixelformat: MJPEG
ustreamer | -- INFO [10494.024 stream] -- Using HW FPS: 30
ustreamer | -- ERROR [10494.024 stream] -- Device does not support setting of HW encoding quality parameters
ustreamer | -- INFO [10494.024 stream] -- Using IO method: MMAP
ustreamer | -- INFO [10494.037 stream] -- Requested 5 device buffers, got 5
ustreamer | -- INFO [10494.270 stream] -- Capturing started
ustreamer | -- INFO [10494.270 stream] -- Switching to HW encoder: the input is (M)JPEG ...
ustreamer | -- INFO [10494.270 stream] -- Using JPEG quality: encoder default
ustreamer | -- INFO [10494.270 stream] -- Creating pool JPEG with 1 workers ...
ustreamer | -- INFO [10494.270 stream] -- Capturing ...
moonraker | Traceback (most recent call last):
moonraker | File "/opt/moonraker/moonraker/moonraker.py", line 16, in
moonraker | import logging
moonraker | File "/usr/local/lib/python3.10/logging/init.py", line 57, in
moonraker | _startTime = time.time()
moonraker | PermissionError: [Errno 1] Operation not permitted
moonraker exited with code 1
fluidd | /docker-entrypoint.sh: /docker-entrypoint.d/ is not empty, will attempt to perform configuration
fluidd | /docker-entrypoint.sh: Looking for shell scripts in /docker-entrypoint.d/
fluidd | /docker-entrypoint.sh: Launching /docker-entrypoint.d/10-listen-on-ipv6-by-default.sh
fluidd | 10-listen-on-ipv6-by-default.sh: info: Getting the checksum of /etc/nginx/conf.d/default.conf
fluidd | 10-listen-on-ipv6-by-default.sh: info: /etc/nginx/conf.d/default.conf differs from the packaged version
fluidd | /docker-entrypoint.sh: Launching /docker-entrypoint.d/20-envsubst-on-templates.sh
fluidd | /docker-entrypoint.sh: Launching /docker-entrypoint.d/30-tune-worker-processes.sh
fluidd | /docker-entrypoint.sh: Configuration complete; ready for start up
fluidd | 2071/07/11 08:16:40 [notice] 1#1: using the "epoll" event method
fluidd | 2071/07/11 08:16:40 [notice] 1#1: nginx/1.21.1
fluidd | 2071/07/11 08:16:40 [notice] 1#1: built by gcc 10.3.1 20210424 (Alpine 10.3.1_git20210424)
fluidd | 2071/07/11 08:16:40 [notice] 1#1: OS: Linux 5.10.63-v7l+
fluidd | 2071/07/11 08:16:40 [notice] 1#1: getrlimit(RLIMIT_NOFILE): 1048576:1048576
fluidd | 2071/07/11 08:16:40 [notice] 1#1: start worker processes
fluidd | 2071/07/11 08:16:40 [notice] 1#1: start worker process 31
fluidd | 2071/07/11 08:16:40 [notice] 1#1: start worker process 32
fluidd | 2071/07/11 08:16:40 [notice] 1#1: start worker process 33
fluidd | 2071/07/11 08:16:40 [notice] 1#1: start worker process 34
moonraker | Traceback (most recent call last):
moonraker | File "/opt/moonraker/moonraker/moonraker.py", line 16, in
moonraker | import logging
moonraker | File "/usr/local/lib/python3.10/logging/init.py", line 57, in
moonraker | _startTime = time.time()
moonraker | PermissionError: [Errno 1] Operation not permitted
moonraker exited with code 1
traefik | time="2022-02-25T21:00:27Z" level=error msg="service "moonraker" error: unable to find the IP address for the container "/moonraker": the server is ignored" providerName=docker container=moonraker-prind-3c4940dd2b1c9573739041869997c142031cd9277d8ebf8cecc9c42032914062
moonraker | Traceback (most recent call last):
moonraker | File "/opt/moonraker/moonraker/moonraker.py", line 16, in
moonraker | import logging
moonraker | File "/usr/local/lib/python3.10/logging/init.py", line 57, in
moonraker | _startTime = time.time()

These last 7 lines are then repeated over and over again.

mkuf · 2022-02-25T21:38:19Z

Hi there,

The provided Log implies that moonraker can not create its logfile.

moonraker | Traceback (most recent call last):
moonraker | File "/opt/moonraker/moonraker/moonraker.py", line 16, in
moonraker | import logging
moonraker | File "/usr/local/lib/python3.10/logging/init.py", line 57, in
moonraker | _startTime = time.time()
moonraker | PermissionError: [Errno 1] Operation not permitted

Did you modify the docker-compose.yaml in regards to the log volume?
Please share your docker-compose.yaml and your moonraker.cfg file.

-Markus

Okywan · 2022-02-25T21:44:00Z

Only modified what is on the guide.

files on #11 (comment)

mkuf · 2022-02-25T21:47:40Z

Please upload the configs as files to your reply.
Pasting them into the reply field makes them unreadable.

Okywan · 2022-02-25T21:50:18Z

Please upload the configs as files to your reply. Pasting them into the reply field makes them unreadable.

Changed their extensions as otherwise it wouldn't let me upload them.
moonraker.txt
docker-compose.txt
d

mkuf · 2022-02-25T22:20:34Z

Thanks, your Configs seem to be allright.
Stop your stack, remove the log volume and partially start your stack again.
The last command attaches to moonraker so you can read its logs.

docker compose --profile <profilename> down
docker volume rm prind_log
docker compose --profile <profilename> up -d klipper
docker compose --profile <profilename> up moonraker

Okywan · 2022-02-25T22:23:36Z

Identical result:

pi@raspberrypi:/Klipper/prind$ docker volume rm prind_log
prind_log
pi@raspberrypi:/Klipper/prind$ docker compose --profile fluidd up -d klipper
[+] Running 3/3
⠿ Network prind_default Created 0.4s
⠿ Volume "prind_log" Created 0.0s
⠿ Container klipper Started 1.4s
pi@raspberrypi:~/Klipper/prind$ docker compose --profile fluidd up moonraker
[+] Running 3/3
⠿ Container traefik Created 0.2s
⠿ Container klipper Running 0.0s
⠿ Container moonraker Created 0.2s
Attaching to moonraker
moonraker | Traceback (most recent call last):
moonraker | File "/opt/moonraker/moonraker/moonraker.py", line 16, in
moonraker | import logging
moonraker | File "/usr/local/lib/python3.10/logging/init.py", line 57, in
moonraker | _startTime = time.time()
moonraker | PermissionError: [Errno 1] Operation not permitted
moonraker exited with code 1
moonraker | Traceback (most recent call last):
moonraker | File "/opt/moonraker/moonraker/moonraker.py", line 16, in
moonraker | import logging
moonraker | File "/usr/local/lib/python3.10/logging/init.py", line 57, in
moonraker | _startTime = time.time()
moonraker | PermissionError: [Errno 1] Operation not permitted
moonraker exited with code 1
moonraker | Traceback (most recent call last):
moonraker | File "/opt/moonraker/moonraker/moonraker.py", line 16, in
moonraker | import logging
moonraker | File "/usr/local/lib/python3.10/logging/init.py", line 57, in
moonraker | _startTime = time.time()
moonraker | PermissionError: [Errno 1] Operation not permitted
moonraker exited with code 1
moonraker | Traceback (most recent call last):
moonraker | File "/opt/moonraker/moonraker/moonraker.py", line 16, in
moonraker | import logging
moonraker | File "/usr/local/lib/python3.10/logging/init.py", line 57, in
moonraker | _startTime = time.time()
moonraker | PermissionError: [Errno 1] Operation not permitted
moonraker exited with code 1
^CGracefully stopping... (press Ctrl+C again to force)
[+] Running 1/1
⠿ Container moonraker Stopped

mkuf · 2022-02-25T22:36:27Z

It does not seem to be the logging volume that is causing the issues.
The only other possible cause I can think of, would be that the config directory is not writable by the user that is used within the container.

Please execute the following commands from within your prind directory.

ls -an .
ls -an config/

Okywan · 2022-02-25T22:52:03Z

pi@raspberrypi:/Klipper/prind$ ls -an .
total 84
drwxr-xr-x 7 1000 1000 4096 feb 25 22:35 .
drwxr-xr-x 4 1000 1000 4096 feb 25 22:15 ..
drwxr-xr-x 2 1000 1000 4096 feb 23 22:09 config
drwxr-xr-x 7 1000 1000 4096 feb 23 22:09 docker
-rw-r--r-- 1 1000 1000 4223 feb 23 22:12 docker-compose.yaml
drwxr-xr-x 8 1000 1000 4096 feb 23 22:09 .git
drwxr-xr-x 3 1000 1000 4096 feb 23 22:09 .github
-rw-r--r-- 1 1000 1000 25 feb 23 22:09 .gitignore
-rw-r--r-- 1 1000 1000 35149 feb 23 22:09 LICENSE
-rw-r--r-- 1 1000 1000 7492 feb 23 22:09 README.md
drwxr-xr-x 2 1000 1000 4096 feb 23 22:09 scripts
pi@raspberrypi:/Klipper/prind$ ls -an config/
total 20
drwxr-xr-x 2 1000 1000 4096 feb 23 22:09 .
drwxr-xr-x 7 1000 1000 4096 feb 25 22:35 ..
-rw-r--r-- 1 1000 1000 1256 feb 23 22:09 build.config
-rw-r--r-- 1 1000 1000 271 feb 23 22:09 moonraker.cfg
-rw-r--r-- 1 1000 1000 4035 feb 25 23:07 printer.cfg

I have noticed I cannot cd to the log volume location:
pi@raspberrypi:~/Klipper/prind$ docker volume inspect prind_log

[
{
"CreatedAt": "2022-02-25T23:22:17+01:00",
"Driver": "local",
"Labels": {
"com.docker.compose.project": "prind",
"com.docker.compose.version": "2.2.3",
"com.docker.compose.volume": "log"
},
"Mountpoint": "/var/lib/docker/volumes/prind_log/_data",
"Name": "prind_log",
"Options": {
"device": "tmpfs",
"type": "tmpfs"
},
"Scope": "local"
}
]
pi@raspberrypi:~/Klipper/prind$ cd /var/lib/docker/volumes/prind_log/_data
-bash: cd: /var/lib/docker/volumes/prind_log/_data: Permiso denegado

Which means permission denied. Is this normal under debian raspberry pi?

mkuf · 2022-02-25T23:15:09Z

The permissions seem to be ok. While developing this stack, I ran into an issue where I had to chown the config directory to uid/gid 1000, otherwise moonraker would not start.
From your output this already seems to be the case.

It is normal that the user pi cannot access these directories, as they belong to root

Could you try starting the stack as user root instead of pi?

Okywan · 2022-02-25T23:24:35Z

Did start it as root, had to move compose to /usr/local/lib/docker/cli-plugins, but the outcome is the same:

root@raspberrypi:/home/pi/Klipper/prind# [+] Running 5/5
⠿ Container traefik Running ⠿ Container ustreamer Created ⠿ Container klipper Running ⠿ Container moonraker Created ⠿ Container fluidd Created Attaching to fluidd, klipper, ustreamer | -- INFO [4335.168 ustreamer | -- INFO [4335.169 ustreamer | -- INFO [4335.169 ustreamer | -- INFO [4335.169 ustreamer | -- INFO [4335.169 ustreamer | ================== ustreamer | -- INFO [4335.254 ustreamer | -- INFO [4335.254 ustreamer | -- ERROR [4335.255 ustreamer | -- INFO [4335.256 ustreamer | -- INFO [4335.256 ustreamer | -- INFO [4335.256 ustreamer | -- ERROR [4335.256 ustreamer | -- INFO [4335.256 ustreamer | -- INFO [4335.268 ustreamer | -- INFO [4335.494 ustreamer | -- INFO [4335.495 ustreamer | -- INFO [4335.495 ustreamer | -- INFO [4335.495 ustreamer | -- INFO [4335.495 moonraker | Traceback moonraker | File "/opt/moonr moonraker | import logging
moonraker | File "/usr/local moonraker | _startTime moonraker | PermissionError: moonraker exited with code 1 docker compose --profile fluidd up
0.0s
0.3s
0.0s
0.0s
0.3s
moonraker, traefik, ustreamer
main] -- Using internal blank placeholder
main] -- Listening HTTP on [0.0.0.0]:8080
stream] -- Using V4L2 device: /dev/webcam
stream] -- Using desired FPS: 30
http] -- Starting HTTP eventloop ...
==============================================================
stream] -- Device fd=8 opened
stream] -- Using input channel: 0
stream] -- Requested resolution=1280x960 is unavailable
stream] -- Using resolution: 1280x720
stream] -- Using pixelformat: MJPEG
stream] -- Using HW FPS: 30
stream] -- Device does not support setting of HW encoding quality parameters
stream] -- Using IO method: MMAP
stream] -- Requested 5 device buffers, got 5
stream] -- Capturing started
stream] -- Switching to HW encoder: the input is (M)JPEG ...
stream] -- Using JPEG quality: encoder default
stream] -- Creating pool JPEG with 1 workers ...
stream] -- Capturing ...
(most recent call last):
aker/moonraker/moonraker.py", line 16, in
/lib/python3.10/logging/init.py", line 57, in
= time.time()
[Errno 1] Operation not permitted

mkuf · 2022-02-25T23:35:29Z

We'll have to look inside the Container to check for permissions.
As the moonraker container is restarting, we'll use klipper instead.

docker exec -it klipper ls -na /opt

Okywan · 2022-02-25T23:42:04Z

pi@raspberrypi:~/Klipper/prind$ docker exec -it klipper ls -na /opt
total 24
drwxr-xr-x 1 0 0 4096 Feb 25 22:22 .
drwxr-xr-x 1 0 0 4096 Feb 25 22:22 ..
drwxr-xr-x 2 1000 1000 4096 Feb 23 21:09 cfg
drwxr-xr-x 2 1000 1000 4096 Feb 25 02:55 gcode
drwxr-xr-x 1 1000 1000 4096 Feb 23 02:34 klipper
drwxrwxrwt 2 0 0 60 Feb 25 23:41 log
drwxrwxrwt 2 0 0 80 Feb 25 23:41 run
drwxr-xr-x 1 1000 1000 4096 Feb 23 02:34 venv

Might correlate with #11

Okywan · 2022-02-26T00:03:27Z

Hm, did a full upgrade of my install by switching to bullseye repo (was on buster) and doing apt upgrade. Stack starts ok now and im looking at the fluidd web!

Think might be related with this: docker-library/python#674

mkuf · 2022-02-26T00:05:16Z

I just pushed a change for Klipper and Moonraker images and rebuilt the most recent images. (8055c18)
Stop your stack, prune all images and explicitly set die Tags for klipper and moonraker in docker-compose.yaml

mkuf/klipper:7c964e5
mkuf/moonraker:ed20223

docker compose --profile fluidd down
docker image prune -af
docker compose --profile fluidd up -d klipper
docker compose --profile fluidd up moonraker

mkuf · 2022-02-26T00:11:40Z

Think might be related with this: docker-library/python#674

Great find.
Timing-wise we now can't quite pin down wich change fixed this issue.
Imho it is more likely that your change fixed the issue, as logs were working before on other installs.

mkuf added a commit that referenced this issue Feb 25, 2022

klipper|moonraker: explicitly create log directory

8055c18

Might correlate with #11

mkuf closed this as completed Feb 26, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fluidd can't reach Moonraker #11

Fluidd can't reach Moonraker #11

Okywan commented Feb 25, 2022

mkuf commented Feb 25, 2022

Okywan commented Feb 25, 2022 •

edited

Loading

mkuf commented Feb 25, 2022

Okywan commented Feb 25, 2022

mkuf commented Feb 25, 2022

Okywan commented Feb 25, 2022

mkuf commented Feb 25, 2022 •

edited

Loading

Okywan commented Feb 25, 2022

mkuf commented Feb 25, 2022

Okywan commented Feb 25, 2022

mkuf commented Feb 25, 2022

Okywan commented Feb 25, 2022

Okywan commented Feb 26, 2022 •

edited

Loading

mkuf commented Feb 26, 2022

mkuf commented Feb 26, 2022 •

edited

Loading

Fluidd can't reach Moonraker #11

Fluidd can't reach Moonraker #11

Comments

Okywan commented Feb 25, 2022

mkuf commented Feb 25, 2022

Okywan commented Feb 25, 2022 • edited Loading

mkuf commented Feb 25, 2022

Okywan commented Feb 25, 2022

mkuf commented Feb 25, 2022

Okywan commented Feb 25, 2022

mkuf commented Feb 25, 2022 • edited Loading

Okywan commented Feb 25, 2022

mkuf commented Feb 25, 2022

Okywan commented Feb 25, 2022

mkuf commented Feb 25, 2022

Okywan commented Feb 25, 2022

Okywan commented Feb 26, 2022 • edited Loading

mkuf commented Feb 26, 2022

mkuf commented Feb 26, 2022 • edited Loading

Okywan commented Feb 25, 2022 •

edited

Loading

mkuf commented Feb 25, 2022 •

edited

Loading

Okywan commented Feb 26, 2022 •

edited

Loading

mkuf commented Feb 26, 2022 •

edited

Loading