hifiberry / hifiberry-os

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

alpha8 cannot start snapcast extension #548

Open alexanderhaensch opened 1 month ago

alexanderhaensch commented 1 month ago

DO NOT remove the blocks below, but fill these with the requested data. Incomplete bug reports will be ignored!

Describe the bug After enabling the snapcast extension, the extension gets build from the docker-compose.yml, but fails at some point. I was getting an out of memory situation, but now is showing a build error

HiFiBerryOS version 20240523

HiFiBerry sound card Amp100 + DSP

To Reproduce Steps to reproduce the behavior:

  1. Extensions
  2. enable Snapcast

Expected behavior Snapcast working

Screenshots Screenshot_20240526_092839

Browser (if applicable)

Additional context May 26 07:19:07 hifiberry-wohnzimmer node[909]: INFO:root:Starting snapcast May 26 07:19:07 hifiberry-wohnzimmer node[909]: ERROR:root:Failed to start Docker containers for extension snapcast May 26 07:19:07 hifiberry-wohnzimmer node[909]: Error executing command: Command failed: /opt/hifiberry/bin/extensions start snapcast May 26 07:19:07 hifiberry-wohnzimmer node[909]: INFO:root:Starting snapcast May 26 07:19:07 hifiberry-wohnzimmer node[909]: ERROR:root:Failed to start Docker containers for extension snapcast May 26 07:19:07 hifiberry-wohnzimmer node[909]: Stdout: #0 building with "default" instance using docker driver May 26 07:19:07 hifiberry-wohnzimmer node[909]: #1 [snapcast internal] load .dockerignore May 26 07:19:07 hifiberry-wohnzimmer node[909]: #1 transferring context: 2B done May 26 07:19:07 hifiberry-wohnzimmer node[909]: #1 DONE 0.0s May 26 07:19:07 hifiberry-wohnzimmer node[909]: #2 [snapcast internal] load build definition from Dockerfile May 26 07:19:07 hifiberry-wohnzimmer node[909]: #2 transferring dockerfile: 1.60kB done May 26 07:19:07 hifiberry-wohnzimmer node[909]: #2 DONE 0.0s May 26 07:19:07 hifiberry-wohnzimmer node[909]: #3 [snapcast internal] load metadata for docker.io/library/alpine:latest May 26 07:19:07 hifiberry-wohnzimmer node[909]: #3 DONE 0.5s May 26 07:19:07 hifiberry-wohnzimmer node[909]: #4 [snapcast builder 1/9] FROM docker.io/library/alpine:latest@sha256:77726ef6b57ddf65bb551896826ec38bc3e53f75cdde31354fbffb4f25238ebd May 26 07:19:07 hifiberry-wohnzimmer node[909]: #4 DONE 0.0s May 26 07:19:07 hifiberry-wohnzimmer node[909]: #5 [snapcast stage-1 2/5] RUN apk update && apk add --no-cache dbus glib gobject-introspection py3-gobject3 py3-gobject3-dev python3 May 26 07:19:07 hifiberry-wohnzimmer node[909]: #5 CACHED May 26 07:19:07 hifiberry-wohnzimmer node[909]: #6 [snapcast builder 2/9] RUN apk update && apk add --no-cache build-base autoconf automake git cmake alsa-lib-dev libvorbis-dev opus-dev flac-dev soxr-dev pkgconf boost-dev alsa-lib-dev dbus-dev glib-dev cairo cairo-dev gobject-introspection-dev python3 py3-pip May 26 07:19:07 hifiberry-wohnzimmer node[909]: #6 CACHED May 26 07:19:07 hifiberry-wohnzimmer node[909]: #7 [snapcast builder 8/9] RUN cd / && git clone https://github.com/hifiberry/snapcastmpris && cd snapcastmpris && pip install --no-cache-dir --verbose --break-system-packages -r requirements.txt May 26 07:19:07 hifiberry-wohnzimmer node[909]: #7 CACHED May 26 07:19:07 hifiberry-wohnzimmer node[909]: #8 [snapcast builder 3/9] RUN apk add --no-cache dbus May 26 07:19:07 hifiberry-wohnzimmer node[909]: #8 CACHED May 26 07:19:07 hifiberry-wohnzimmer node[909]: #9 [snapcast builder 4/9] RUN git clone https://github.com/badaix/snapcast /snapcast May 26 07:19:07 hifiberry-wohnzimmer node[909]: #9 CACHED May 26 07:19:07 hifiberry-wohnzimmer node[909]: #10 [snapcast builder 5/9] WORKDIR /snapcast May 26 07:19:07 hifiberry-wohnzimmer node[909]: #10 CACHED May 26 07:19:07 hifiberry-wohnzimmer node[909]: #11 [snapcast builder 6/9] RUN cmake . && make May 26 07:19:07 hifiberry-wohnzimmer node[909]: #11 CACHED May 26 07:19:07 hifiberry-wohnzimmer node[909]: #12 [snapcast builder 7/9] RUN apk add --no-cache python3-dev May 26 07:19:07 hifiberry-wohnzimmer node[909]: #12 CACHED May 26 07:19:07 hifiberry-wohnzimmer node[909]: #13 [snapcast builder 9/9] RUN find / -name site-packages May 26 07:19:07 hifiberry-wohnzimmer node[909]: #13 CACHED May 26 07:19:07 hifiberry-wohnzimmer node[909]: #14 [snapcast stage-1 3/5] COPY --from=builder /usr/lib/python3.11/site-packages /usr/lib/python3.11/site-packages May 26 07:19:07 hifiberry-wohnzimmer node[909]: #14 ERROR: failed to calculate checksum of ref 61758087-3473-4182-9cea-8f1c22695a6d::t5n3qrcyfpq0rx8vrkintyvky: "/usr/lib/python3.11/site-packages": not found May 26 07:19:07 hifiberry-wohnzimmer node[909]: ------ May 26 07:19:07 hifiberry-wohnzimmer node[909]: > [snapcast stage-1 3/5] COPY --from=builder /usr/lib/python3.11/site-packages /usr/lib/python3.11/site-packages: May 26 07:19:07 hifiberry-wohnzimmer node[909]: ------ May 26 07:19:07 hifiberry-wohnzimmer node[909]: failed to solve: failed to compute cache key: failed to calculate checksum of ref 61758087-3473-4182-9cea-8f1c22695a6d::t5n3qrcyfpq0rx8vrkintyvky: "/usr/lib/python3.11/site-packages": not found May 26 07:19:07 hifiberry-wohnzimmer node[909]: Stderr: INFO:root:Starting snapcast May 26 07:19:07 hifiberry-wohnzimmer node[909]: ERROR:root:Failed to start Docker containers for extension snapcast May 26 07:19:07 hifiberry-wohnzimmer node[909]: error May 26 07:19:07 hifiberry-wohnzimmer node[909]: done

alexanderhaensch commented 1 month ago

The problem is that alpine released a new version. Using alpine 3.19.1 works for building, but then this happens in the docker container:

Traceback (most recent call last):
  File "/snapcastmpris/snapcastmpris.py", line 38, in <module>
    from SnapcastWrapper import SnapcastWrapper
  File "/snapcastmpris/SnapcastWrapper.py", line 7, in <module>
    from zeroconf import Zeroconf, IPVersion
ModuleNotFoundError: No module named 'zeroconf'

So i am out of ideas.

hifiberry commented 1 month ago

I've pushed a new version 0.28.0 of the extension. Try this. You should be able to update via the Extension screen

alexanderhaensch commented 1 month ago

Yes the Docker image from the registry starts up. I was not finding the update button, because the "button" it is not showing a mouseover.. but finally i found out that i can click it.

now the docker logs show:

ERROR: root - Failed to obtain snapserver address through zeroconf!
CRITICAL: root - Snapcast cannot be launched: failed to obtain snapcast server address.
INFO: root - can't read /etc/snapcastmpris.conf, using default configurations

I think i have to add an snapcastmpris.conf in the right place?

alexanderhaensch commented 1 month ago

i had to remove the folder /etc/snapcastmpris.conf

and created a /etc/snapcastmpris.conf with the content:

server = 192.168.xxx.yyy

now it looks good.

alexanderhaensch commented 1 month ago

new error:


Traceback (most recent call last):
  File "/snapcastmpris/snapcastmpris.py", line 184, in <module>
    snapcast_wrapper = SnapcastWrapper(glib_main_loop, server_address, sync_volume=volume_sync_enabled, alsa_mixer=args.mixer)
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/snapcastmpris/SnapcastWrapper.py", line 59, in __init__
    import alsaaudio as alsa
ImportError: Error loading shared library libasound.so.2: No such file or directory (needed by /usr/lib/python3.11/site-packages/alsaaudio.cpython-311-aarch64-linux-musl.so)
alexanderhaensch commented 1 month ago

I had to update the Dockerfile and add

alsa-lib \
opus \
libvorbis \
libflac \
soxr \
alsa-utils \

to the final container

FROM alpine:3.19 AS builder

# Install required build dependencies
RUN apk update && apk add --no-cache \
    build-base \
    autoconf \
    automake \
    git \
    cmake \
    alsa-lib-dev \
    libvorbis-dev \
    opus-dev \
    flac-dev \
    soxr-dev \
    pkgconf \
    boost-dev \
    alsa-lib \
    dbus-dev \
    glib-dev \
    cairo \
    cairo-dev \
    gobject-introspection-dev \
    python3 \
    py3-pip

RUN apk add --no-cache dbus

# Clone Snapcast repository and build it
RUN git clone https://github.com/badaix/snapcast /snapcast

# Build Snapcast
WORKDIR /snapcast
RUN cmake . \
    && make

RUN apk add --no-cache python3-dev

# Build snapcastmpris
RUN cd / && \
    git clone https://github.com/hifiberry/snapcastmpris &&  \
    cd snapcastmpris && \
    pip install --no-cache-dir --verbose  --break-system-packages -r requirements.txt

RUN find / -name site-packages

# Final stage: create the minimal runtime container
FROM alpine:3.19

RUN apk update && apk add --no-cache \
    dbus \
    glib \
## new
    alsa-lib \
    opus \
    libvorbis \
    libflac \
    soxr \
    alsa-utils \
## end new
    gobject-introspection \
    py3-gobject3 \
    py3-gobject3-dev \
    python3 && \
    addgroup -S snapcast -g 2001 && \
    adduser -S -D -H -G snapcast -u 2002 snapcast && \
    rm -rf /var/cache/apk/*

# Copy python from builder image
COPY --from=builder /usr/lib/python3.11/site-packages /usr/lib/python3.11/site-packages
COPY --from=builder /snapcastmpris /snapcastmpris

# Copy built Snapcast binary from builder stage
COPY --from=builder /snapcast/bin/snapclient /usr/local/bin/snapclient

# Expose Snapcast port
EXPOSE 1704

USER snapcast

# Run Snapcast server
CMD ["/usr/bin/python3" , "/snapcastmpris/snapcastmpris.py", "-m", "$CURRENT_MIXER_CONTROL"]

If i manually run snapclient in the container it works :)

But running via the snapcastmpris is not playing sound.

 ✔ Container snapcast  Recreated                                                                                                                                             0.2s 
Attaching to snapcast
snapcast  | DEBUG: root - enabled verbose logging via argv
snapcast  | INFO: root - read /etc/snapcastmpris.conf
snapcast  | DEBUG: root - alsa mixer set via config to Softvol
snapcast  | DEBUG: root - volume sync flag set via config to True
snapcast  | INFO: root - name on DBus aqcuired
snapcast  | DEBUG: asyncio - Using selector: EpollSelector
snapcast  | DEBUG: root - None
snapcast  | WARNING: root - Failed to obtain snapserver streaming port through zeroconf!
snapcast  | INFO: root - starting Snapclient
snapcast  | INFO: root - snapclient now running in background
snapcast  | DEBUG: root - Initializing SnapcastRpcWrapper
snapcast  | INFO: root - Finding MAC address of active interface to use as snapclient id
snapcast  | INFO: root - Status for interface eth0: up
snapcast  | INFO: root - MAC address for interface eth0: 02:42:ac:18:00:02
snapcast  | INFO: root - Single MAC address: 02:42:ac:18:00:02
snapcast  | DEBUG: root - Sending JsonRPC call to Snapserver at 192.168.xxx.yyy
snapcast  | DEBUG: urllib3.connectionpool - Starting new HTTP connection (1): 192.168.xxx.yyy:1780
snapcast  | DEBUG: urllib3.connectionpool - http://192.168.xxx.yyy:1780 "POST /jsonrpc HTTP/1.1" 200 65
snapcast  | DEBUG: root - JsonRCP response: {"id":0,"jsonrpc":"2.0","result":{"major":2,"minor":0,"patch":0}}
snapcast  | INFO: root - Snapserver RPC version is 2.0.2
snapcast  | DEBUG: root - Initialized SnapcastRpcWrapper
snapcast  | INFO: root - Started SnapcastRpcWebsocketWrapper loop
snapcast  | INFO: root - snapcast process is already running
snapcast  | DEBUG: root - Updated property: Metadata = dbus.Dictionary({'xesam:url': 'snapcast://192.168.xxx.yyy/', 'xesam:title': ''}, signature=dbus.Signature('sv'))
snapcast  | DEBUG: root - Updated property: PlaybackStatus = Paused
snapcast  | INFO: root - ALSA <-> Snapcast volume synchronisation is enabled
snapcast  | INFO: root - SnapcastWrapper ALSA volume poll thread started
snapcast  | INFO: root - Snapcast wrapper thread started
snapcast  | WARNING: root - snapclient died
snapcast  | INFO: websocket - Websocket connected
snapcast  | DEBUG: root - Snapcast RPC websocket message received
snapcast  | DEBUG: root - {"jsonrpc":"2.0","method":"Stream.OnUpdate","params":{"id":"Radio","stream":{"id":"Radio","properties":{"canControl":false,"canGoNext":false,"canGoPrevious":false,"canPause":false,"canPlay":false,"canSeek":false},"status":"playing","uri":{"fragment":"","host":"","path":"/tmp/snapfifo","query":{"chunk_ms":"20","codec":"opus","mode":"read","name":"Radio","sampleformat":"48000:16:2"},"raw":"pipe:////tmp/snapfifo?chunk_ms=20&codec=opus&mode=read&name=Radio&sampleformat=48000:16:2","scheme":"pipe"}}}}
snapcast  | INFO: root - Snapclient stream started
snapcast  | DEBUG: root - Updated property: Metadata = dbus.Dictionary({'xesam:url': 'snapcast://192.168.xxx.yyy/', 'xesam:title': ''}, signature=dbus.Signature('sv'))
snapcast  | INFO: root - pausing other players
snapcast  | ERROR: websocket - error from callback <bound method SnapcastRpcWebsocketWrapper.on_ws_message of <SnapcastRpcWebsocketWrapper.SnapcastRpcWebsocketWrapper object at 0x7f9d8f0b90>>: [Errno 2] No such file or directory: '/opt/hifiberry/bin/pause-all'
snapcast  | ERROR: root - Snapcast RPC websocket error
snapcast  | ERROR: root - [Errno 2] No such file or directory: '/opt/hifiberry/bin/pause-all'
snapcast  | INFO: root - main loop started
snapcast  | DEBUG: root - Snapcast RPC websocket message received
snapcast  | DEBUG: root - {"jsonrpc":"2.0","method":"Stream.OnUpdate","params":{"id":"Radio","stream":{"id":"Radio","properties":{"canControl":false,"canGoNext":false,"canGoPrevious":false,"canPause":false,"canPlay":false,"canSeek":false},"status":"idle","uri":{"fragment":"","host":"","path":"/tmp/snapfifo","query":{"chunk_ms":"20","codec":"opus","mode":"read","name":"Radio","sampleformat":"48000:16:2"},"raw":"pipe:////tmp/snapfifo?chunk_ms=20&codec=opus&mode=read&name=Radio&sampleformat=48000:16:2","scheme":"pipe"}}}}
snapcast  | INFO: root - Snapclient stream idle
snapcast  | INFO: root - Muting snapclient
snapcast  | DEBUG: root - Setting snapclient mute to True
snapcast  | DEBUG: root - Sending JsonRPC call to Snapserver at 192.168.xxx.yyy
snapcast  | DEBUG: urllib3.connectionpool - Starting new HTTP connection (1): 192.168.xxx.yyy:1780
snapcast  | DEBUG: urllib3.connectionpool - http://192.168.xxx.yyy:1780 "POST /jsonrpc HTTP/1.1" 200 71
snapcast  | DEBUG: root - JsonRCP response: {"id":2,"jsonrpc":"2.0","result":{"volume":{"muted":true,"percent":6}}}
snapcast  | DEBUG: root - Updated property: Metadata = dbus.Dictionary({'xesam:url': 'snapcast://192.168.xxx.yyy/', 'xesam:title': ''}, signature=dbus.Signature('sv'))
snapcast  | DEBUG: root - Updated property: PlaybackStatus = Paused
snapcast  | DEBUG: root - Snapcast RPC websocket message received
snapcast  | DEBUG: root - {"jsonrpc":"2.0","method":"Client.OnVolumeChanged","params":{"id":"02:42:ac:18:00:02","volume":{"muted":true,"percent":6}}}
snapcast  | DEBUG: root - Snapclient volume changed to 6
^CGracefully stopping... (press Ctrl+C again to force)

I do not understand how the /opt/hifiberry/bin/pause-all can be executed from inside the container...

snapcast | ERROR: root - [Errno 2] No such file or directory: '/opt/hifiberry/bin/pause-all'

https://github.com/hifiberry/snapcastmpris/blob/d308fae5b8285512dc230cc6b9d94a5cf6c48510/SnapcastWrapper.py#L113