Skip to content

ffmpeg stream drops out after some time #328

Description

@behesse

v4.0.0-beta.18

Deezer streams seem to drop out after some time. It plays fine for a couple of seconds, then one might notice one or two small stutters, nothing too wild. But after some seconds more it suddenly drops out. I tried to filter the logs to the relevant part:

It seems to be decoding related and more on the "stream consuming" part than on the sendspin stuff.

[2026-08-04T15:08:27.320Z][DEBUG][LoxoneHttp|Processor] [command=audio/2/serviceplay/spotify/bridge-deezer-p0idkf/deezer:playlist:65490170/?q&ZW5mb3JjZVVzZXI9dHJ1ZQ] command received
[2026-08-04T15:08:27.322Z][INFO][Zones|Manager] [hasParentContext=false normalizedTarget=deezer:playlist:65490170 resolvedTarget=deezer:playlist:65490170 station="" type=serviceplay uri=deezer:playlist:65490170 zoneId=2] playContent
[2026-08-04T15:08:27.323Z][DEBUG][Content|Manager] [folderId=playlist:65490170 limit=50 offset=0 service=deezer user=deezer] content cache hit
[2026-08-04T15:08:27.325Z][DEBUG][Zones|Manager] [expandedCount=50 isAppleMusic=false isMusicAssistant=false queueSourcePath=deezer:playlist:65490170 resolvedTarget=deezer:playlist:65490170 zoneId=2] queue build resolved
[2026-08-04T15:08:27.325Z][DEBUG][Zones|Manager] [authority=local items=50 startIndex=0 target=deezer:track:3805356232 zoneId=2] queue rebuilt
[2026-08-04T15:08:27.332Z][DEBUG][Content|Manager] [folderId=playlist:65490170 limit=50 offset=0 service=deezer user=deezer] content cache hit
[2026-08-04T15:08:27.332Z][DEBUG][Content|Manager] [folderId=playlist:65490170 limit=50 offset=50 service=deezer user=deezer] content cache hit
[2026-08-04T15:08:27.336Z][DEBUG][Zones|Manager] [items=84 startIndex=37 zoneId=2] queue filled in background
[2026-08-04T15:08:27.504Z][DEBUG][Content|DeezerStream] [hasCheckForm=true hasLicense=true offerId=1000001 userId=1234] deezer gw user data summary
[2026-08-04T15:08:27.533Z][DEBUG][Content|DeezerStream] [hasCheckForm=true hasLicense=true offerId=1000001 userId=1234] deezer gw user data summary
[2026-08-04T15:08:27.542Z][DEBUG][Content|DeezerStream] [hasCheckForm=true hasLicense=true offerId=1000001 userId=1234] deezer gw user data summary
[2026-08-04T15:08:27.553Z][DEBUG][Content|DeezerStream] [hasCheckForm=true hasLicense=true offerId=1000001 userId=1234] deezer gw user data summary
[2026-08-04T15:08:27.591Z][DEBUG][Content|DeezerStream] [hasCheckForm=true hasLicense=true offerId=1000001 userId=1234] deezer gw user data summary
[2026-08-04T15:08:27.718Z][INFO][Content|DeezerStream] [method=gw sessionId=92be8d01-af80-4427-8849-0c6ded5bc5dc trackId=3850680281 zoneId=2] deezer stream ready
[2026-08-04T15:08:27.721Z][INFO][Content|DeezerStream] [method=gw sessionId=de99cd1a-5d11-4371-b6ca-1fca6207c418 trackId=3526028401 zoneId=2] deezer stream ready
[2026-08-04T15:08:27.722Z][INFO][Audio|Manager] [hasStream=false label=deezer sourceKind=url zoneId=2] startWithResolvedSource
[2026-08-04T15:08:27.723Z][INFO][Audio|Engine] [zoneId=2] audio session stopped
[2026-08-04T15:08:27.723Z][INFO][Audio|Manager] [handoff=false kind=url profiles=["pcm"] zoneId=2] starting audio engine
[2026-08-04T15:08:27.724Z][INFO][Audio|Session] [maxBufferBytes=262144 outputBitDepth=24 outputChannels=2 outputSampleRate=48000 profile=pcm targetLeadMs=1000 zoneId=2] audio session buffer config
[2026-08-04T15:08:27.725Z][DEBUG][Audio|Session] [args=["-hide_banner","-nostats","-loglevel","info","-probesize","256k","-analyzeduration","1M","-reconnect","1","-reconnect_streamed","1","-reconnect_delay_max","5","-i","http://127.0.0.1:7090/deezer/de99cd1a-5d11-4371-b6ca-1fca6207c418/stream","-vn","-acodec","pcm_s24le","-ar","48000","-ac","2","-af","aresample=resampler=soxr:precision=28:cutoff=0.97:async=1","-f","s24le","pipe:1"] outputBitDepth=24 outputChannels=2 outputSampleRate=48000 profile=pcm zoneId=2] spawning ffmpeg
[2026-08-04T15:08:27.734Z][INFO][Audio|Engine] [crossfadeEnabled=false profile=pcm source=url zoneId=2] audio session started
[2026-08-04T15:08:27.734Z][INFO][Audio|Manager] [sincePlayContentMs=412 source=deezer stream=2-d528705c-3ff5-40b4-9b99-fdd75c1e0945 title="VERLIEBT IN MICH" zoneId=2] playback started
[2026-08-04T15:08:27.735Z][DEBUG][Zones|Manager] [action=play outputCount=1 outputTypes=["sendspin"] zoneId=2] dispatchOutputs
[2026-08-04T15:08:27.736Z][INFO][Output|Sendspin] [clientId=sendspin-cli-cachyos source=deezer zoneId=2 zoneName="Zone 2"] Sendspin play
[2026-08-04T15:08:27.739Z][DEBUG][Zones|PlayerListeners] [activeInput=queue defaultVolume=10 dispatchedVolume=25 hadPendingReset=false isFreshStart=false mode=play outputs=["sendspin"] stateVolume=25 zoneId=2] player started: start-volume decision
[2026-08-04T15:08:27.742Z][DEBUG][Zones|Manager] [actions=[] desiredSignal=1 mode=play offDelayMs=300000 zoneId=2 zoneName=Büro] zone power manager state update
[2026-08-04T15:08:27.743Z][DEBUG][Output|Sendspin] [bitDepth=24 channels=2 clientId=sendspin-cli-cachyos codec=pcm configuredDefaultPrebufferBytes=262144 requestedPrebufferBytes=262144 sampleRate=48000 targetLeadMs=250 zoneId=2] Sendspin stream prebuffer config
[2026-08-04T15:08:27.744Z][DEBUG][Audio|Session] [label=sendspin primedBytes=0 primedMs=0 primeWithBuffer=true profile=pcm sessionBufferedBytes=0 subscriberCount=1 zoneId=2] audio subscriber attached
[2026-08-04T15:08:27.745Z][INFO][Output|Sendspin] [bitDepth=24 channels=2 clientId=sendspin-cli-cachyos sampleRate=48000 sincePlayMs=10 zoneId=2] Sendspin stream started
[2026-08-04T15:08:27.746Z][DEBUG][Output|Sendspin] [bins=48 clientId=sendspin-cli-cachyos rateMax=30 types=["loudness","spectrum","f_peak","peak","pitch"] zoneId=2] Sendspin visualizer@v1 active
[2026-08-04T15:08:27.779Z][INFO][Content|DeezerStream] [method=gw sessionId=767ae27b-e8a1-44ad-acf5-bb91ed2c28e9 trackId=3709347892 zoneId=2] deezer stream ready
[2026-08-04T15:08:27.780Z][INFO][Content|DeezerStream] [method=gw sessionId=38b81221-bc42-4374-b6de-808a82a36ac0 trackId=3602074142 zoneId=2] deezer stream ready
[2026-08-04T15:08:27.800Z][INFO][Content|DeezerStream] [method=gw sessionId=bb04abf2-6e00-4e5d-bfe5-d8bbb1106cf6 trackId=3930630611 zoneId=2] deezer stream ready
[2026-08-04T15:08:28.210Z][DEBUG][LoxoneHttp|Processor] [command=audio/2/recent] command received
[2026-08-04T15:08:28.214Z][DEBUG][Content|DeezerStream] [hasCheckForm=true hasLicense=true offerId=1000001 userId=1234] deezer gw user data summary
[2026-08-04T15:08:28.215Z][DEBUG][Content|DeezerStream] [hasCheckForm=true hasLicense=true offerId=1000001 userId=1234] deezer gw user data summary
[2026-08-04T15:08:28.365Z][INFO][Content|DeezerStream] [method=gw sessionId=cd74bae8-80f5-4633-8abe-f6a8ade476d9 trackId=3106586681 zoneId=2] deezer stream ready
[2026-08-04T15:08:28.367Z][INFO][Content|DeezerStream] [method=gw sessionId=3b052a2c-4ec2-4531-9268-08240a6bbbd3 trackId=3794985752 zoneId=2] deezer stream ready
[2026-08-04T15:08:28.446Z][DEBUG][Audio|Session] [message="Input #0, flac, from 'http://127.0.0.1:7090/deezer/de99cd1a-5d11-4371-b6ca-1fca6207c418/stream':\n  Metadata:\n    encoder         : Lavf60.3.100\n  Duration: 00:02:09.98, start: 0.000000, bitrate: N/A\n  Stream #0:0: Audio: flac, 44100 Hz, stereo, s16\nStream mapping:\n  Stream #0:0 -> #0:0 (flac (native) -> pcm_s24le (native))\nPress [q] to stop, [?] for help\nOutput #0, s24le, to 'pipe:1':\n  Metadata:\n    encoder         : Lavf61.1.100\n  Stream #0:0: Audio: pcm_s24le, 48000 Hz, stereo, s32 (24 bit), 2304 kb/s\n      Metadata:\n        encoder         : Lavc61.3.100 pcm_s24le" zoneId=2] ffmpeg stderr
[2026-08-04T15:08:28.449Z][INFO][Audio|Session] [bytes=65532 profile=pcm spawnToFirstChunkMs=724 zoneId=2] ffmpeg first chunk
[2026-08-04T15:08:28.449Z][DEBUG][Output|Sendspin] [leadMs=250 sampleRate=48000 zoneId=2] Sendspin anchor set
[2026-08-04T15:08:28.450Z][INFO][Audio|Player:2] [playContentToStartedMs=412 profile=pcm ready=true sincePlaybackStartedMs=716 sincePlayContentMs=1128 source=deezer zoneId=2] playback first audio ready
[2026-08-04T15:08:28.450Z][INFO][Output|Sendspin] [clientId=sendspin-cli-cachyos sincePlayMs=715 sinceStreamStartMs=0 zoneId=2] Sendspin first audio frame sent
[2026-08-04T15:08:29.727Z][INFO][Audio|Session] [bufferedBytes=8192 code=null earlyExit=false profile=pcm runMs=61985 signal=SIGKILL stderr="Stream #0:0: Audio: pcm_s24le, 48000 Hz, stereo, s32 (24 bit), 2304 kb/s\n      Metadata:\n        encoder         : Lavc61.3.100 pcm_s24le" stderrAt=1785856048162 subscribers=1 totalBytes=17618894 zoneId=2] ffmpeg exited
[2026-08-04T15:08:40.361Z][DEBUG][Content|DeezerStream] [message="This operation was aborted"] deezer proxy retry fetch failed
[2026-08-04T15:09:22.877Z][DEBUG][Audio|Session] [message="[flac @ 0x2e4b3440] invalid residual\n[flac @ 0x2e4b3440] decode_frame() failed" zoneId=2] ffmpeg stderr
[2026-08-04T15:09:23.398Z][DEBUG][Audio|Session] [message="[aist#0:0/flac @ 0x2e4bb300] [dec:flac @ 0x2e4af9c0] Decoding error: Invalid data found when processing input" zoneId=2] ffmpeg stderr
[2026-08-04T15:09:26.593Z][DEBUG][Audio|Session] [message="[out#0/s24le @ 0x2e4bbbc0] video:0KiB audio:17045KiB subtitle:0KiB other streams:0KiB global headers:0KiB muxing overhead: 0.000000%\nsize=   17045KiB time=00:01:00.60 bitrate=2304.0kbits/s speed=1.04x" zoneId=2] ffmpeg stderr
[2026-08-04T15:09:26.596Z][INFO][Audio|Session] [bufferedBytes=256902 code=0 earlyExit=false profile=pcm runMs=58871 signal=null stderr="[out#0/s24le @ 0x2e4bbbc0] video:0KiB audio:17045KiB subtitle:0KiB other streams:0KiB global headers:0KiB muxing overhead: 0.000000%\nsize=   17045KiB time=00:01:00.60 bitrate=2304.0kbits/s speed=1.04x" stderrAt=1785856166593 subscribers=1 totalBytes=17306866 zoneId=2] ffmpeg exited
[2026-08-04T15:09:26.597Z][WARN][Audio|Manager] [exitCode=0 exitSignal=null reason=undefined source=deezer stderr="[out#0/s24le @ 0x2e4bbbc0] video:0KiB audio:17045KiB subtitle:0KiB other streams:0KiB global headers:0KiB muxing overhead: 0.000000%\nsize=   17045KiB time=00:01:00.60 bitrate=2304.0kbits/s speed=1.04x" zoneId=2] playback session terminated by engine
[2026-08-04T15:09:26.599Z][DEBUG][Zones|Manager] [actions=[] desiredSignal=0 mode=stop offDelayMs=300000 zoneId=2 zoneName=Büro] zone power manager state update
[2026-08-04T15:09:26.599Z][DEBUG][Zones|Manager] [desiredSignal=0 previousDesired=1 zoneId=2] zone power manager desired signal changed
[2026-08-04T15:09:26.600Z][DEBUG][Zones|Manager] [delayMs=300000 signal=0 zoneId=2] zone power manager scheduled signal
[2026-08-04T15:09:26.600Z][DEBUG][Zones|Manager] [action=stop outputCount=1 outputTypes=["sendspin"] zoneId=2] dispatchOutputs
[2026-08-04T15:09:26.601Z][INFO][Output|Sendspin] [clientId=sendspin-cli-cachyos zoneId=2 zoneName="Zone 2"] Sendspin stop
[2026-08-04T15:09:26.603Z][WARN][Zones|Manager] [reason="deezer stream failed: [out#0/s24le @ 0x2e4bbbc0] video:0KiB audio:17045KiB subtitle:0KiB other streams:0KiB global headers:0KiB muxing overhead: 0.000000% size= 17045KiB time=00:01:00.60 bitrate=2304.0kbits/s speed=1.04x" source=output title="Playback unavailable" zoneId=2] playback error

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions