hifiberry / hifiberry-os

Linux distribution optimized for audio playback
MIT License
958 stars 123 forks source link

HBOS 64 Alpha 8: Can't install Extensions #553

Open mrArkwright opened 1 month ago

mrArkwright commented 1 month ago

Describe the bug When trying to install extensions the device just hangs. There is no progress installing the extension and I can't connect to the web UI anymore.

HiFiBerryOS version HBOS 64 Alpha 8 I experienced the same behaviour with Alpha 7

HiFiBerry sound card Digi2 Pro

To Reproduce On a fresh install of HBOS 64 Alpha 8 go to "general" -> "Extension" and install any extension (e.g. Spotifyd).

Expected behavior The Extension gets installed.

Additional context The issue seems to be that docker can't pull images. When running top on the device I'm seeing a docker-compose pull that seems to hang. On further investigation even pulling any docker image doesn't work:

# docker run hello-world
Unable to find image 'hello-world:latest' locally
docker: Error response from daemon: Get "https://registry-1.docker.io/v2/": net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers).
See 'docker run --help'.

The process only returns with the error message after a longer timeout.

logs from docker daemon:

# journalctl -u docker.service
Jan 24 22:48:20 hifiberry systemd[1]: Starting Docker Application Container Engine...
Jan 24 22:48:22 hifiberry dockerd[1086]: time="2024-01-24T22:48:22.599512869Z" level=info msg="Starting up"
Jan 24 22:48:22 hifiberry dockerd[1086]: time="2024-01-24T22:48:22.703313906Z" level=info msg="[graphdriver] trying configured driver: overlay2"
Jan 24 22:48:22 hifiberry dockerd[1086]: time="2024-01-24T22:48:22.744426480Z" level=info msg="Loading containers: start."
Jan 24 22:48:23 hifiberry dockerd[1086]: time="2024-01-24T22:48:23.506669332Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.17.0.0/16. Daemon option --bip can be used to set a preferred IP address"
Jan 24 22:48:23 hifiberry dockerd[1086]: time="2024-01-24T22:48:23.679358183Z" level=info msg="Loading containers: done."
Jan 24 22:48:23 hifiberry dockerd[1086]: time="2024-01-24T22:48:23.911381868Z" level=warning msg="failed to find docker-init: exec: \"docker-init\": executable file not found in $PATH"
Jan 24 22:48:23 hifiberry dockerd[1086]: time="2024-01-24T22:48:23.930844128Z" level=warning msg="WARNING: No memory limit support"
Jan 24 22:48:23 hifiberry dockerd[1086]: time="2024-01-24T22:48:23.930969313Z" level=warning msg="WARNING: No swap limit support"
Jan 24 22:48:23 hifiberry dockerd[1086]: time="2024-01-24T22:48:23.931079739Z" level=info msg="Docker daemon" commit=buildroot graphdriver=overlay2 version=24.0.7
Jan 24 22:48:23 hifiberry dockerd[1086]: time="2024-01-24T22:48:23.934074331Z" level=info msg="Daemon has completed initialization"
Jan 24 22:48:24 hifiberry systemd[1]: Started Docker Application Container Engine.
Jan 24 22:48:24 hifiberry dockerd[1086]: time="2024-01-24T22:48:24.077091276Z" level=info msg="API listen on /run/docker.sock"
May 30 14:42:19 hifiberry dockerd[1086]: time="2024-05-30T14:42:19.580892513Z" level=warning msg="Error getting v2 registry: Get \"https://registry-1.docker.io/v2/\": net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
May 30 14:42:19 hifiberry dockerd[1086]: time="2024-05-30T14:42:19.581102160Z" level=info msg="Attempting next endpoint for pull after error: Get \"https://registry-1.docker.io/v2/\": net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
May 30 14:42:19 hifiberry dockerd[1086]: time="2024-05-30T14:42:19.604863684Z" level=error msg="Handler for POST /v1.43/images/create returned error: Get \"https://registry-1.docker.io/v2/\": net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
May 30 14:51:32 hifiberry dockerd[1086]: time="2024-05-30T14:51:32.365303895Z" level=warning msg="Error getting v2 registry: Get \"https://registry-1.docker.io/v2/\": net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
May 30 14:51:32 hifiberry dockerd[1086]: time="2024-05-30T14:51:32.365493150Z" level=info msg="Attempting next endpoint for pull after error: Get \"https://registry-1.docker.io/v2/\": net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
May 30 14:51:32 hifiberry dockerd[1086]: time="2024-05-30T14:51:32.387241873Z" level=error msg="Handler for POST /v1.43/images/create returned error: Get \"https://registry-1.docker.io/v2/\": net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"

I don't use a proxy or any other redirections in my network. Every other device (including some other raspis) doesn't have problems pulling docker images.

alexanderhaensch commented 1 month ago

are other internet connections working fine?

mrArkwright commented 1 month ago

Yes, internet connection is working fine. I can even reach the very address docker is failing to connect to:

# curl -i https://registry-1.docker.io/v2/
HTTP/1.1 401 Unauthorized
content-type: application/json
docker-distribution-api-version: registry/2.0
www-authenticate: Bearer realm="https://auth.docker.io/token",service="registry.docker.io"
date: Fri, 31 May 2024 09:35:16 GMT
content-length: 87
strict-transport-security: max-age=31536000

{"errors":[{"code":"UNAUTHORIZED","message":"authentication required","detail":null}]}

(getting back a 401 is normal behaviour for that address)

I also just verified that the problem persists regardless of whether I'm using WiFi or ethernet.

mrArkwright commented 1 month ago

I can even pull docker images when running docker-in-docker. Tried by copying an alpine image to the hifiberry raspi via scp (since I can't pull images):

# docker run --privileged --rm -it alpine
/ # apk add docker
fetch https://dl-cdn.alpinelinux.org/alpine/v3.20/main/aarch64/APKINDEX.tar.gz
fetch https://dl-cdn.alpinelinux.org/alpine/v3.20/community/aarch64/APKINDEX.tar.gz
(1/13) Installing ca-certificates (20240226-r0)
(2/13) Installing libseccomp (2.5.5-r1)
(3/13) Installing runc (1.1.12-r3)
(4/13) Installing containerd (1.7.17-r0)
(5/13) Installing libmnl (1.0.5-r2)
(6/13) Installing libnftnl (1.2.6-r0)
(7/13) Installing libxtables (1.8.10-r3)
(8/13) Installing iptables (1.8.10-r3)
(9/13) Installing tini-static (0.19.0-r3)
(10/13) Installing docker-engine (26.1.3-r0)
Executing docker-engine-26.1.3-r0.pre-install
(11/13) Installing docker-cli (26.1.3-r0)
(12/13) Installing docker-cli-buildx (0.14.0-r1)
(13/13) Installing docker (26.1.3-r0)
Executing busybox-1.36.1-r28.trigger
Executing ca-certificates-20240226-r0.trigger
OK: 245 MiB in 27 packages
/ # dockerd > /dev/null 2>&1 &
/ # docker run hello-world
Unable to find image 'hello-world:latest' locally
latest: Pulling from library/hello-world
478afc919002: Pull complete
Digest: sha256:266b191e926f65542fa8daaec01a192c4d292bff79426f47300a046e1bc576fd
Status: Downloaded newer image for hello-world:latest

Hello from Docker!
This message shows that your installation appears to be working correctly.

To generate this message, Docker took the following steps:
 1. The Docker client contacted the Docker daemon.
 2. The Docker daemon pulled the "hello-world" image from the Docker Hub.
    (arm64v8)
 3. The Docker daemon created a new container from that image which runs the
    executable that produces the output you are currently reading.
 4. The Docker daemon streamed that output to the Docker client, which sent it
    to your terminal.

To try something more ambitious, you can run an Ubuntu container with:
 $ docker run -it ubuntu bash

Share images, automate workflows, and more with a free Docker ID:
 https://hub.docker.com/

For more examples and ideas, visit:
 https://docs.docker.com/get-started/
hifiberry commented 1 month ago

Unfortunately, I can't reproduce it here. My best guess is some corrupted installation. Can you try another installation on another SD card?

a10kiloham commented 2 weeks ago

I'm having the same issue in a totally fresh new build. Is there any manual way to install this? Strangely Spotifyd installed fine but shairplay fails.

hifiberry commented 2 weeks ago

If it can't connect to the docker registry for some unknown reason, you can't install it manually :(

a10kiloham commented 2 weeks ago

I've gotten docker to connect by disabling ipv6 on my wifi adapter then manually editing the resolv.conf to actually point to some DNS servers.

hifiberry commented 2 weeks ago

Thanks, the tip about IPv6 helps. We might need to add something to disable IPv6 as it still isn't working reliably in all installations.

a10kiloham commented 2 weeks ago

Looking at my fresh install there seem to be a few other problems. My spotifyd image is crashing now as well with this:

The application panicked (crashed).
Message:  Failed to register dbus player name: D-Bus error: Connection ":1.51528" is not allowed to own the service "org.mpris.MediaPlayer2.spotifyd.instance15" due to security policies in the configuration file (org.freedesktop.DBus.Error.AccessDenied)
Location: src/dbus_mpris.rs:184

Backtrace omitted. Run with RUST_BACKTRACE=1 environment variable to display it.
Run with RUST_BACKTRACE=full to include source snippets.
Setting initial volume to 100
Loading config from "/etc/spotifyd.conf"
No proxy specified
Using alsa volume controller.
Ignoring blacklisted access point ap-gue1.spotify.com:4070
Ignoring blacklisted access point ap-gew4.spotify.com:443
Connecting to AP "ap-gew1.spotify.com:443"
Authenticated as "xxxxxxxxxxx" !
Country: "GB"
Converting with ditherer: tpdf
Using AlsaSink with format: S16
a10kiloham commented 2 weeks ago

For the above this is fixed in a submitted PR for the spotifyd extension - do you mind versioning up and rebuilding it with that patch? https://github.com/hifiberry/extension_spotifyd/pull/5/commits/e358d2d8e08be02df5ab6e2f3fb3f984fd5d0886 Thanks

a10kiloham commented 2 weeks ago

Actually that line should go in the base unit's /etc/dbus-1/system.d/ folder. The reconfigure script would do this but I can't easily see where it's being called from once an image is prebuilt. Is there a natural place it can be called from?

hifiberry commented 2 weeks ago

reconfigure does this every time the extension is started https://github.com/hifiberry/extension_spotifyd/blob/master/reconfigure

a10kiloham commented 2 weeks ago

Weird. It wasn't performing that - what do you mean by restarted per se? In the front end it was showing the extension enabled but there wasn't a restart buttton. I realized by cloning the extension repo and then running it, I could perform that to manually fix. Same with Shairport - i tried installed via front-end but it silently failed and stayed un-checked. Then by manually cloning i was able to get it fully working w/ the right changes to the dbus.

hifiberry commented 2 weeks ago

There is no restart in the GUI. You can use /opt/hifiberry/bin/extensions for this or reboot the system