No sound with mopid-musicbox

Hello

I have small but delicate problem, mopidy-musicbox does play a local file but makes no sound. I have tried aplay /usr/share/sounds/alsa/Front_Center.wav and gst-launch-1.0 audiotestsrc ! audioresample ! autoaudiosink
with success , I have sound, but when I pres play in mopidy-musicbox I have no sound.
I’m running mopidy as service.

config and installed deps below

type or paste code here
  • [Effective config
[core]
cache_dir = /var/cache/mopidy
config_dir = /etc/mopidy
data_dir = /var/lib/mopidy
max_tracklist_length = 10000
restore_state = false

[logging]
verbosity = 4
format = %(levelname)-8s [%(threadName)s] %(name)s %(message)s
color = false
config_file = 

[audio]
mixer = software
mixer_volume = 75
output = autoaudiosink
buffer_time = 

[proxy]
scheme = 
hostname = 
port = 
username = 
password = 

[musicbox_webclient]
enabled = true
musicbox = true
websocket_host = 
websocket_port = 
on_track_click = PLAY_ALL

[file]
enabled = true
media_dirs = 
  /mnt|Mounts
excluded_file_extensions = 
  .directory
  .html
  .jpeg
  .jpg
  .log
  .nfo
  .pdf
  .png
  .txt
  .zip
show_dotfiles = false
follow_symlinks = false
metadata_timeout = 1000

[http]
enabled = true
hostname = xxx.xxx.xx.xxx
port = 6680
zeroconf = xxx.xxx.xx.xxx
allowed_origins = 
csrf_protection = true
default_app = mopidy

[m3u]
enabled = true
base_dir = 
default_encoding = latin-1
default_extension = .m3u8
playlists_dir = /mnt

[softwaremixer]
enabled = true

[stream]
enabled = true
protocols = 
  http
  https
  mms
  rtmp
  rtmps
  rtsp
metadata_blacklist = 
timeout = 5000

Platform: Linux-6.6.20+rpt-rpi-v8-aarch64-with-glibc2.36
Python: CPython 3.11.2 from /usr/lib/python3.11
Mopidy: 3.4.2 from /usr/lib/python3/dist-packages
Mopidy-MusicBox-Webclient: 3.1.0 from /usr/local/lib/python3.11/dist-packages
  Mopidy: 3.4.2 from /usr/lib/python3/dist-packages
  Pykka: 3.1.1 from /usr/lib/python3/dist-packages
  setuptools: 66.1.1 from /usr/lib/python3/dist-packages
GStreamer: 1.22.0.0 from /usr/lib/python3/dist-packages/gi
  Detailed information: 
    Python wrapper: python-gi 3.42.2
    Relevant elements:
      Found:
        uridecodebin
        souphttpsrc
        appsrc
        alsasink
        osssink
        oss4sink
        pulsesink
        id3demux
        id3v2mux
        lamemp3enc
        mpegaudioparse
        mpg123audiodec
        vorbisdec
        vorbisenc
        vorbisparse
        oggdemux
        oggmux
        oggparse
        flacdec
        flacparse
        shout2send

It may also be useful to share a Mopidy debug log.

and a debug log with verbosity level 4

Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.seek","params":{"time_position":0},"jsonrpc":"2.0","id":113}'
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [Audio-2 (_actor_loop)] mopidy.audio.gst Sending flushing seek: position=0
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [Dummy-12] mopidy.audio.gst Got SEGMENT pad event: rate=1.0 format=time start=0 stop=18446744073709551615 position=0
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [Dummy-12] mopidy.audio.actor Audio event: position_changed(position=0)
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [Dummy-12] mopidy.listener Sending position_changed to AudioListener: {'position': 0}
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 113, "result": true}'
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Triggering seeked event
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_PAUSED new=GST_STATE_PAUSED pending=GST_STATE_PAUSED
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending seeked to CoreListener: {'time_position': 0}
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_PAUSED new=GST_STATE_PAUSED pending=GST_STATE_VOID_PENDING
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.actor Audio event: state_changed(old_state=paused, new_state=paused, target_state=None)
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.listener Sending state_changed to AudioListener: {'old_state': 'paused', 'new_state': 'paused', 'target_state': None}
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.gst Got ASYNC_DONE bus message.
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.play","jsonrpc":"2.0","id":114}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [Audio-2 (_actor_loop)] mopidy.audio.gst Changing state to GST_STATE_PLAYING: result=GST_STATE_CHANGE_SUCCESS
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Changing state: paused -> playing
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Triggering playback state change event
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending playback_state_changed to CoreListener: {'old_state': 'paused', 'new_state': 'playing'}
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Triggering track playback resumed event
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_PAUSED new=GST_STATE_PLAYING pending=GST_STATE_VOID_PENDING
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.actor Audio event: state_changed(old_state=paused, new_state=playing, target_state=None)
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.listener Sending state_changed to AudioListener: {'old_state': 'paused', 'new_state': 'playing', 'target_state': None}
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending track_playback_resumed to CoreListener: {'tl_track': TlTrack(tlid=2, track=Track(bitrate=1411200, length=200000, name='fanfaredoor1.wav', uri='file:///mnt/fanfaredoor1.wav')), 'time_position': 4}
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 114, "result": null}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":115}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 115, "result": 16}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":116}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 116, "result": 19}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":117}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 117, "result": 40}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":118}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 118, "result": 47}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":119}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 119, "result": 50}'
Apr 08 17:04:27 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":120}'
Apr 08 17:04:27 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 120, "result": 333}'
Apr 08 17:04:27 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":121}'
Apr 08 17:04:27 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 121, "result": 854}'
Apr 08 17:04:28 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":122}'
Apr 08 17:04:28 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 122, "result": 1888}'
Apr 08 17:04:30 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":123}'
Apr 08 17:04:30 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 123, "result": 3920}'
Apr 08 17:04:34 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":124}'
Apr 08 17:04:34 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 124, "result": 7958}'
Apr 08 17:04:35 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.mixer.set_volume","params":{"volume":51},"jsonrpc":"2.0","id":125}'
Apr 08 17:04:35 MMclient mopidy[691]: DEBUG    [SoftwareMixer-1 (_actor_loop)] mopidy.mixer Mixer event: volume_changed(volume=51)
Apr 08 17:04:35 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 125, "result": true}'
Apr 08 17:04:35 MMclient mopidy[691]: DEBUG    [SoftwareMixer-1 (_actor_loop)] mopidy.listener Sending volume_changed to MixerListener: {'volume': 51}
Apr 08 17:04:35 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending volume_changed to CoreListener: {'volume': 51}
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.mixer.set_volume","params":{"volume":83},"jsonrpc":"2.0","id":126}'
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 126, "result": true}'
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG    [SoftwareMixer-1 (_actor_loop)] mopidy.mixer Mixer event: volume_changed(volume=83)
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG    [SoftwareMixer-1 (_actor_loop)] mopidy.listener Sending volume_changed to MixerListener: {'volume': 83}
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending volume_changed to CoreListener: {'volume': 83}
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.mixer.set_volume","params":{"volume":83},"jsonrpc":"2.0","id":127}'
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 127, "result": true}'
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG    [SoftwareMixer-1 (_actor_loop)] mopidy.mixer Mixer event: volume_changed(volume=83)
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG    [SoftwareMixer-1 (_actor_loop)] mopidy.listener Sending volume_changed to MixerListener: {'volume': 83}
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending volume_changed to CoreListener: {'volume': 83}
Apr 08 17:04:42 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":128}'
Apr 08 17:04:42 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 128, "result": 15992}'
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.pause","jsonrpc":"2.0","id":129}'
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG    [Audio-2 (_actor_loop)] mopidy.audio.gst Changing state to GST_STATE_PAUSED: result=GST_STATE_CHANGE_SUCCESS
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Changing state: playing -> paused
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Triggering playback state change event
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending playback_state_changed to CoreListener: {'old_state': 'playing', 'new_state': 'paused'}
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Triggering track playback paused event
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending track_playback_paused to CoreListener: {'tl_track': TlTrack(tlid=2, track=Track(bitrate=1411200, length=200000, name='fanfaredoor1.wav', uri='file:///mnt/fanfaredoor1.wav')), 'time_position': 27789}
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 129, "result": null}'
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_PLAYING new=GST_STATE_PAUSED pending=GST_STATE_VOID_PENDING
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.actor Audio event: state_changed(old_state=playing, new_state=paused, target_state=None)
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.listener Sending state_changed to AudioListener: {'old_state': 'playing', 'new_state': 'paused', 'target_state': None}
Apr 08 17:05:04 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.tracklist.index","jsonrpc":"2.0","id":130}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 130, "result": 0}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.tracklist.add","params":{"at_position":1,"uris":["file:///mnt/fanfaredoor1.wav"]},"jsonrpc":"2.0","id":131}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [FileBackend-3 (_actor_loop)] mopidy.file.library Looking up file URI: file:///mnt/fanfaredoor1.wav
Apr 08 17:05:11 MMclient mopidy[691]: TRACE    [FileBackend-3 (_actor_loop)] mopidy.audio.scan element decodebin7: have-audio;
Apr 08 17:05:11 MMclient mopidy[691]: TRACE    [FileBackend-3 (_actor_loop)] mopidy.audio.scan element fakesink3: GstMessageTag, taglist=(taglist)"taglist\,\ container-format\=\(string\)WAV\,...
Apr 08 17:05:11 MMclient mopidy[691]: TRACE    [FileBackend-3 (_actor_loop)] mopidy.audio.scan element pipeline5: GstMessageAsyncDone, running-time=(guint64)18446744073709551615;
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.tracklist Triggering event: tracklist_changed()
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending tracklist_changed to CoreListener: {}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 131, "result": [{"__model__": "TlTrack", "tlid": 3, "track": {"__model__": "Track", "uri": "file:///mnt/fanfaredoor1.wav", "name": "fanfaredoor1.wav", "length": 200000, "bitrate": 1411200}}]}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.stop","jsonrpc":"2.0","id":132}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Audio-2 (_actor_loop)] mopidy.audio.gst Changing state to GST_STATE_NULL: result=GST_STATE_CHANGE_SUCCESS
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Changing state: paused -> stopped
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Triggering playback state change event
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending playback_state_changed to CoreListener: {'old_state': 'paused', 'new_state': 'stopped'}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 132, "result": null}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.tracklist.get_tl_tracks","jsonrpc":"2.0","id":133}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 133, "result": [{"__model__": "TlTrack", "tlid": 2, "track": {"__model__": "Track", "uri": "file:///mnt/fanfaredoor1.wav", "name": "fanfaredoor1.wav", "length": 200000, "bitrate": 1411200}}, {"__model__": "TlTrack", "tlid": 3, "track": {"__model__": "Track", "uri": "file:///mnt/fanfaredoor1.wav", "name": "fanfaredoor1.wav", "length": 200000, "bitrate": 1411200}}]}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.play","params":{"tlid":3},"jsonrpc":"2.0","id":134}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Audio-2 (_actor_loop)] mopidy.audio.actor Position query failed
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Audio-2 (_actor_loop)] mopidy.audio.gst Changing state to GST_STATE_READY: result=GST_STATE_CHANGE_SUCCESS
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_NULL new=GST_STATE_READY pending=GST_STATE_VOID_PENDING
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Audio-2 (_actor_loop)] mopidy.audio.actor Flags: 2
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [SoftwareMixer-1 (_actor_loop)] mopidy.mixer Mixer event: volume_changed(volume=83)
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [SoftwareMixer-1 (_actor_loop)] mopidy.listener Sending volume_changed to MixerListener: {'volume': 83}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Audio-2 (_actor_loop)] mopidy.audio.gst Got source-setup signal: element=GstFileSrc
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Audio-2 (_actor_loop)] mopidy.audio.actor Running source-setup callback
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Audio-2 (_actor_loop)] mopidy.audio.gst Changing state to GST_STATE_PLAYING: result=GST_STATE_CHANGE_ASYNC
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending volume_changed to CoreListener: {'volume': 83}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 134, "result": null}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.library.get_images","params":{"uris":[]},"jsonrpc":"2.0","id":135}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 135, "result": {}}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_current_tl_track","jsonrpc":"2.0","id":136}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 136, "result": {"__model__": "TlTrack", "tlid": 2, "track": {"__model__": "Track", "uri": "file:///mnt/fanfaredoor1.wav", "name": "fanfaredoor1.wav", "length": 200000, "bitrate": 1411200}}}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_stream_title","jsonrpc":"2.0","id":137}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Dummy-12] mopidy.audio.gst Got SEGMENT pad event: rate=1.0 format=time start=0 stop=18446744073709551615 position=0
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 137, "result": null}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Dummy-12] mopidy.audio.actor Audio event: position_changed(position=0)
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.gst Got STREAM_START bus message
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Dummy-12] mopidy.listener Sending position_changed to AudioListener: {'position': 0}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.actor Audio event: stream_changed(uri='file:///mnt/fanfaredoor1.wav')
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.listener Sending stream_changed to AudioListener: {'uri': 'file:///mnt/fanfaredoor1.wav'}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Triggering track playback ended event
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending track_playback_ended to CoreListener: {'tl_track': TlTrack(tlid=2, track=Track(bitrate=1411200, length=200000, name='fanfaredoor1.wav', uri='file:///mnt/fanfaredoor1.wav')), 'time_position': 0}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Changing state: stopped -> playing
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Triggering playback state change event
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending playback_state_changed to CoreListener: {'old_state': 'stopped', 'new_state': 'playing'}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Triggering track playback started event
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending track_playback_started to CoreListener: {'tl_track': TlTrack(tlid=3, track=Track(bitrate=1411200, length=200000, name='fanfaredoor1.wav', uri='file:///mnt/fanfaredoor1.wav'))}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.gst Got TAG bus message: tags={'container-format': ['WAV'], 'bitrate': [1411200], 'audio-codec': ['Uncompressed 16-bit PCM audio'], 'midi-base-note': [60]}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.actor Audio event: tags_changed(tags=['container-format', 'bitrate', 'audio-codec', 'midi-base-note'])
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.listener Sending tags_changed to AudioListener: {'tags': ['container-format', 'bitrate', 'audio-codec', 'midi-base-note']}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_READY new=GST_STATE_PAUSED pending=GST_STATE_PLAYING
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.gst Got ASYNC_DONE bus message.
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":138}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 138, "result": 20}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_PAUSED new=GST_STATE_PLAYING pending=GST_STATE_VOID_PENDING
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.actor Audio event: state_changed(old_state=paused, new_state=playing, target_state=None)
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.listener Sending state_changed to AudioListener: {'old_state': 'paused', 'new_state': 'playing', 'target_state': None}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.library.get_images","params":{"uris":["file:///mnt/fanfaredoor1.wav"]},"jsonrpc":"2.0","id":139}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 139, "result": {"file:///mnt/fanfaredoor1.wav": []}}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":140}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 140, "result": 40}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":141}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 141, "result": 51}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.library.lookup","params":{"uris":["file:///mnt/fanfaredoor1.wav"]},"jsonrpc":"2.0","id":142}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [FileBackend-3 (_actor_loop)] mopidy.file.library Looking up file URI: file:///mnt/fanfaredoor1.wav
Apr 08 17:05:11 MMclient mopidy[691]: TRACE    [FileBackend-3 (_actor_loop)] mopidy.audio.scan element decodebin9: have-audio;
Apr 08 17:05:11 MMclient mopidy[691]: TRACE    [FileBackend-3 (_actor_loop)] mopidy.audio.scan element fakesink4: GstMessageTag, taglist=(taglist)"taglist\,\ container-format\=\(string\)WAV\,...
Apr 08 17:05:11 MMclient mopidy[691]: TRACE    [FileBackend-3 (_actor_loop)] mopidy.audio.scan element pipeline6: GstMessageAsyncDone, running-time=(guint64)18446744073709551615;
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 142, "result": {"file:///mnt/fanfaredoor1.wav": [{"__model__": "Track", "uri": "file:///mnt/fanfaredoor1.wav", "name": "fanfaredoor1.wav", "length": 200000, "bitrate": 1411200}]}}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":143}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 143, "result": 329}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":144}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 144, "result": 849}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":145}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 145, "result": 1882}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":146}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 146, "result": 4136}'
Apr 08 17:05:12 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":147}'
Apr 08 17:05:12 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 147, "result": 8170}'
Apr 08 17:05:20 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":148}'
Apr 08 17:05:20 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 148, "result": 16209}'
Apr 08 17:05:27 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.pause","jsonrpc":"2.0","id":149}'
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG    [Audio-2 (_actor_loop)] mopidy.audio.gst Changing state to GST_STATE_PAUSED: result=GST_STATE_CHANGE_SUCCESS
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Changing state: playing -> paused
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Triggering playback state change event
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending playback_state_changed to CoreListener: {'old_state': 'playing', 'new_state': 'paused'}
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.core.playback Triggering track playback paused event
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG    [Core-6 (_actor_loop)] mopidy.listener Sending track_playback_paused to CoreListener: {'tl_track': TlTrack(tlid=3, track=Track(bitrate=1411200, length=200000, name='fanfaredoor1.wav', uri='file:///mnt/fanfaredoor1.wav')), 'time_position': 23103}
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG    [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 149, "result": null}'
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_PLAYING new=GST_STATE_PAUSED pending=GST_STATE_VOID_PENDING
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.audio.actor Audio event: state_changed(old_state=playing, new_state=paused, target_state=None)
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG    [MainThread] mopidy.listener Sending state_changed to AudioListener: {'old_state': 'playing', 'new_state': 'paused', 'target_state': None}



Thanks for all the debug info. There must be a difference between the audio sink used when running as your user (where the shell commands worked) and when running as a service. Is this a Pulseaudio system or something else?

hello!

this system is a client for magicmirror, raspbian OS lite, chromium in kiosk mode and a screen connected with hdmi, I will make a checkup in whitch user is doing what.
No there is no pulseaudio only alsa, I tried to change to alsasink instead of autoaudiosink in my mopidy config, but that did no diffrence.

Yes, last time I checked the lite image was still alsa only. Which makes life much simpler.

Could it be you have multiple soundcards present and your default soundcard is different depending on the user? That’s covered in step 5 at Raspberry Pi — Mopidy 3.4.2 documentation

I got this USB-speaker connected to my rpi, and its that one who worked while I was running the soundcheck terminal commands
souncard

and my asound.conf look like this, too me it seems alright

pcm.!default {
  type asym
  playback.pcm {
    type plug
    slave.pcm "output"
  }
  capture.pcm {
    type plug
    slave.pcm "input"
  }
}

pcm.output {
  type hw
  card 2
}

ctl.!default {
  type hw
  card 2

Yes, it does look OK. The Mopidy log looks OK too, my best theory is that the audio is still going to the wrong device. You can try this in your /etc/mopidy/mopidy.conf

[audio]
output = alsasink device=hw:2

And that will be directly comparable to

gst-launch-1.0 audiotestsrc ! audioresample ! alsasink device=hw:2

in your console.

and there You solved it Kingostick, thanks alot !!

This topic was automatically closed 3 days after the last reply. New replies are no longer allowed.