MPD-Device aktualisiert nicht immer alle Readings

Begonnen von RigorM, 23 April 2024, 16:29:56

Vorheriges Thema - Nächstes Thema

RigorM

Hallo zusammen,

dies ist mein erster Beitrag im Forum, und ich bin entsprechend nervös, also seid bitte nachsichtig mit mir. falls ich einiges nicht sofort richtig mache. Ich verspreche zu lernen.

Seit sechs Jahren betreibe ich einen FHEM-Server in meinem Häuschen und habe mich bislang mithilfe dieses Forums (großes Dankeschön!) und anderer Quellen eingentlich immer gut durchgewurschtelt und alles umsetzen können, was ich wollte. Jetzt aber bin ich auf ein Problem gestoßen, das meinen Horizont überfordert und zu dem ich auch nach intensiven Recherchen keine Lösung gefunden habe, so dass ich es nunmehr einmal an die Experten heranzutragen versuche.

Folgende Situation:

FHEM läuft auf einem Raspi 2 unter Debian Raspi Linux 4.14.34-v7+.
Auf der gleichen Maschine läuft ein mpd, ein weiterer auf einem anderen Raspi im LAN (Raspi 4 unter Debian Raspi4 Linux 6.6.20+rpt-rpi-v8).
Beide mpds überwache ich in FHEM mit je einem MPD-Device.
Das MPD-Device für den lokalen mpd aktualisiert alle seine Readings zufriedenstellend.
Das für den mpd auf dem Remote-Raspi allerdings aktualisiert gewisse Readings (z. B. file & Title) nur für jedes zweite Lied.
Das Problem ist reproduzierbar in einem anderen FHEM mit frisch definiertem MPD-Device.
Eine Neuinstallation von mpd auf dem Remote-Raspi hat das Problem nicht behoben.
Ein verbose = 5 auf dem problematischen MPD-Device ergibt u. a. Folgendes (auffällige Einträge hervorgehoben):

2024.04.22 22:12:12 5: myMPD, idle PID 16142 found
2024.04.22 22:12:12 5: myMPD, mpd_cmd[1] -> status
2024.04.22 22:12:12 5: myMPD, rec: repeat: 1
2024.04.22 22:12:12 5: myMPD, rec: random: 1
2024.04.22 22:12:12 5: myMPD, rec: single: 0
2024.04.22 22:12:12 5: myMPD, rec: consume: 0
2024.04.22 22:12:12 5: myMPD, rec: partition: default
2024.04.22 22:12:12 5: myMPD, rec: playlist: 2
2024.04.22 22:12:12 5: myMPD, rec: playlistlength: 9225
2024.04.22 22:12:12 5: myMPD, rec: mixrampdb: 0
2024.04.22 22:12:12 5: myMPD, rec: state: play
2024.04.22 22:12:12 5: myMPD, rec: song: 8766
2024.04.22 22:12:12 5: myMPD, rec: songid: 8767
2024.04.22 22:12:12 5: myMPD, rec: time: 142:152
2024.04.22 22:12:12 5: myMPD, rec: elapsed: 142.254
2024.04.22 22:12:12 5: myMPD, rec: bitrate: 0
2024.04.22 22:12:12 5: myMPD, rec: duration: 152.000
2024.04.22 22:12:12 5: myMPD, rec: audio: 44100:f:2
2024.04.22 22:12:12 5: myMPD, rec: nextsong: 7925
2024.04.22 22:12:12 5: myMPD, rec: nextsongid: 7926
!--------------------------------------------------------------
2024.04.22 22:12:22 5: myMPD, MPD_EVENT : player
2024.04.22 22:12:22 4: myMPD, MPD_EVENT : player
!--------------------------------------------------------------
2024.04.22 22:12:22 5: myMPD, mpd_cmd[1] -> command_list_begin
status
stats
currentsong
command_list_end
2024.04.22 22:12:22 5: myMPD, rec: repeat: 1
2024.04.22 22:12:22 5: myMPD, rec: random: 1
2024.04.22 22:12:22 5: myMPD, rec: single: 0
2024.04.22 22:12:22 5: myMPD, rec: consume: 0
2024.04.22 22:12:22 5: myMPD, rec: partition: default
2024.04.22 22:12:22 5: myMPD, rec: playlist: 2
2024.04.22 22:12:22 5: myMPD, rec: playlistlength: 9225
2024.04.22 22:12:22 5: myMPD, rec: mixrampdb: 0
2024.04.22 22:12:22 5: myMPD, rec: state: play
2024.04.22 22:12:22 5: myMPD, rec: song: 7925
2024.04.22 22:12:22 5: myMPD, rec: songid: 7926
2024.04.22 22:12:22 5: myMPD, rec: time: 0:409
2024.04.22 22:12:22 5: myMPD, rec: elapsed: 0.000
2024.04.22 22:12:22 5: myMPD, rec: bitrate: 128
2024.04.22 22:12:22 5: myMPD, rec: duration: 408.829
2024.04.22 22:12:22 5: myMPD, rec: audio: 44100:24:2
2024.04.22 22:12:22 5: myMPD, rec: nextsong: 7288
2024.04.22 22:12:22 5: myMPD, rec: nextsongid: 7289
2024.04.22 22:12:22 5: myMPD, rec: uptime: 10734
2024.04.22 22:12:22 5: myMPD, rec: playtime: 10735
2024.04.22 22:12:22 5: myMPD, rec: artists: 2508
2024.04.22 22:12:22 5: myMPD, rec: albums: 1260
2024.04.22 22:12:22 5: myMPD, rec: songs: 9225
2024.04.22 22:12:22 5: myMPD, rec: db_playtime: 2105031
2024.04.22 22:12:22 5: myMPD, rec: db_update: 1713802306
2024.04.22 22:12:22 5: myMPD, rec: file: International/T/Type O Negative/October Rust/Type O Negative - Red Water (Christmas Mourning).mp3
2024.04.22 22:12:22 5: myMPD, rec: Last-Modified: 2020-10-29T14:51:32Z
2024.04.22 22:12:22 5: myMPD, rec: Format: 44100:24:2
2024.04.22 22:12:22 5: myMPD, rec: Artist: Type O Negative
2024.04.22 22:12:22 5: myMPD, rec: Title: Red Water (Christmas Mourning)
2024.04.22 22:12:22 5: myMPD, rec: Album: October Rust
2024.04.22 22:12:22 5: myMPD, rec: Date: 1996
2024.04.22 22:12:22 5: myMPD, rec: Genre: Rock
2024.04.22 22:12:22 5: myMPD, rec: Time: 409
2024.04.22 22:12:22 5: myMPD, rec: duration: 408.829
2024.04.22 22:12:22 5: myMPD, rec: Pos: 7925
2024.04.22 22:12:22 5: myMPD, rec: Id: 7926
!--------------------------------------------------------------
2024.04.22 22:12:22 5: myMPD, new Playlist in ->
2024.04.22 22:12:22 5: myMPD, IdleDone -> myMPD|socket error
2024.04.22 22:12:22 4: myMPD, idle error -> socket error
2024.04.22 22:12:37 4: myMPD, Idle new PID : 16558
!--------------------------------------------------------------
2024.04.22 22:12:37 5: myMPD, mpd_cmd[1] -> command_list_begin
status
stats
currentsong
command_list_end
2024.04.22 22:12:37 5: myMPD, rec: repeat: 1
2024.04.22 22:12:37 5: myMPD, rec: random: 1
2024.04.22 22:12:37 5: myMPD, rec: single: 0
2024.04.22 22:12:37 5: myMPD, rec: consume: 0
2024.04.22 22:12:37 5: myMPD, rec: partition: default
2024.04.22 22:12:37 5: myMPD, rec: playlist: 2
2024.04.22 22:12:37 5: myMPD, rec: playlistlength: 9225
2024.04.22 22:12:37 5: myMPD, rec: mixrampdb: 0
2024.04.22 22:12:37 5: myMPD, rec: state: play
2024.04.22 22:12:37 5: myMPD, rec: song: 7925
2024.04.22 22:12:37 5: myMPD, rec: songid: 7926
2024.04.22 22:12:37 5: myMPD, rec: time: 15:409
2024.04.22 22:12:37 5: myMPD, rec: elapsed: 15.124
2024.04.22 22:12:37 5: myMPD, rec: bitrate: 128
2024.04.22 22:12:37 5: myMPD, rec: duration: 408.829
2024.04.22 22:12:37 5: myMPD, rec: audio: 44100:24:2
2024.04.22 22:12:37 5: myMPD, rec: nextsong: 7288
2024.04.22 22:12:37 5: myMPD, rec: nextsongid: 7289
2024.04.22 22:12:37 5: myMPD, rec: uptime: 10749
2024.04.22 22:12:37 5: myMPD, rec: playtime: 10750
2024.04.22 22:12:37 5: myMPD, rec: artists: 2508
2024.04.22 22:12:37 5: myMPD, rec: albums: 1260
2024.04.22 22:12:37 5: myMPD, rec: songs: 9225
2024.04.22 22:12:37 5: myMPD, rec: db_playtime: 2105031
2024.04.22 22:12:37 5: myMPD, rec: db_update: 1713802306
2024.04.22 22:12:37 5: myMPD, rec: file: International/T/Type O Negative/October Rust/Type O Negative - Red Water (Christmas Mourning).mp3
2024.04.22 22:12:37 5: myMPD, rec: Last-Modified: 2020-10-29T14:51:32Z
2024.04.22 22:12:37 5: myMPD, rec: Format: 44100:24:2
2024.04.22 22:12:37 5: myMPD, rec: Artist: Type O Negative
2024.04.22 22:12:37 5: myMPD, rec: Title: Red Water (Christmas Mourning)
2024.04.22 22:12:37 5: myMPD, rec: Album: October Rust
2024.04.22 22:12:37 5: myMPD, rec: Date: 1996
2024.04.22 22:12:37 5: myMPD, rec: Genre: Rock
2024.04.22 22:12:37 5: myMPD, rec: Time: 409
2024.04.22 22:12:37 5: myMPD, rec: duration: 408.829
2024.04.22 22:12:37 5: myMPD, rec: Pos: 7925
2024.04.22 22:12:37 5: myMPD, rec: Id: 7926
2024.04.22 22:12:37 5: myMPD, mpd_cmd[2] -> command_list_begin
status
stats
currentsong
command_list_end
2024.04.22 22:12:52 5: myMPD, idle PID 16558 found
2024.04.22 22:12:52 5: myMPD, mpd_cmd[1] -> status
2024.04.22 22:12:52 5: myMPD, rec: repeat: 1
2024.04.22 22:12:52 5: myMPD, rec: random: 1
2024.04.22 22:12:52 5: myMPD, rec: single: 0
2024.04.22 22:12:52 5: myMPD, rec: consume: 0
2024.04.22 22:12:52 5: myMPD, rec: partition: default
2024.04.22 22:12:52 5: myMPD, rec: playlist: 2
2024.04.22 22:12:52 5: myMPD, rec: playlistlength: 9225
2024.04.22 22:12:52 5: myMPD, rec: mixrampdb: 0
2024.04.22 22:12:52 5: myMPD, rec: state: play
2024.04.22 22:12:52 5: myMPD, rec: song: 7925
2024.04.22 22:12:52 5: myMPD, rec: songid: 7926
2024.04.22 22:12:52 5: myMPD, rec: time: 30:409
2024.04.22 22:12:52 5: myMPD, rec: elapsed: 30.088
2024.04.22 22:12:52 5: myMPD, rec: bitrate: 128
2024.04.22 22:12:52 5: myMPD, rec: duration: 408.829
2024.04.22 22:12:52 5: myMPD, rec: audio: 44100:24:2
2024.04.22 22:12:52 5: myMPD, rec: nextsong: 7288
2024.04.22 22:12:52 5: myMPD, rec: nextsongid: 7289

Auffällig ist hier der Fehler socket_error, der aber auch bei dem anderen, unproblematischen MPD-Device regelmäßig auftritt, so dass das eigentlich kein Hinweis auf die Ursache sein kann.
Allerdings ist genau dieses Lied, bei dem der Fehler auftritt, dasjenige, dessen Readings komplett aktualisiert werden.
Beim nächsten Lied kommt dann jedoch kein MPD_EVENT : player mehr, und die Readings 'file', 'Title' und 'rawTitle' werden nicht aktualisiert.
Beim übernächsten Lied kommt es wieder - zusammen mit dem socket_error. Und nun werden auch wieder alle Readings aktualisiert.
Beim unproblematischen MPD hingegen kommt vor jedem neuen Lied ein MPD_EVENT : player.

Hier ein Auszug aus den Internals für das problematische MPD-Device:

define MPD_local MPD 192.168.178.40 6600
attr MPD_local devStateIcon play:rc_PLAY:stop stop:rc_STOP:play pause:rc_PAUSE:pause error:icoBlitz
attr MPD_local icon it_radio
attr MPD_local loadMusic 0
attr MPD_local loadPlaylists 0
attr MPD_local no_playlistcollection 1
attr MPD_local player mpd
attr MPD_local titleSplit 1
attr MPD_local unknown_artist_image /fhem/icons/1px-spacer
attr MPD_local verbose 5
attr MPD_local waits 15
#   DEF        192.168.178.40 6600
#   DeviceName 192.168.178.40:6600
#   FUUID      659c465f-f33f-3b1b-687c-9d8d598910939ba3
#   HOST       192.168.178.40
#   IPID       13129
#   NAME       MPD_local
#   NR         269
#   PORT       6600
#   PRESENCE   present
#   STATE      play
#   SUBVERSION 23
#   TIMEOUT    0.7
#   TYPE       MPD
#   VERSION    0.23.5
#   eventCount 9325
#   mute       -1
#   helper:
#     RUNNING_PID:
#       abortArg  
#       abortFn   
#       arg        MPD_local
#       bc_pid     44845
#       finishFn   MPD_IdleDone
#       fn         MPD_IdleStart
#       pid        13129
#       timeout   
#     playlistcollection:
#       val        -1

Und hier für das unproblematische:

define MPD_remote MPD
attr MPD_remote devStateIcon play:rc_PLAY:stop stop:rc_STOP:play pause:rc_PAUSE:pause error:icoBlitz
attr MPD_remote icon it_radio
attr MPD_remote loadMusic 0
attr MPD_remote loadPlaylists 0
attr MPD_remote no_playlistcollection 1
attr MPD_remote player mpd
attr MPD_remote titleSplit 1
attr MPD_remote unknown_artist_image /fhem/icons/1px-spacer
attr MPD_remote verbose 5
attr MPD_remote waits 15
#   DeviceName 127.0.0.1:6600
#   FUUID      61444f90-f33f-3b1b-5541-f87ec1b1ec77cb43
#   HOST       127.0.0.1
#   IPID       14481
#   NAME       MPD_remote
#   NR         208
#   PORT       6600
#   PRESENCE   present
#   STATE      play
#   SUBVERSION 19
#   TIMEOUT    0.7
#   TYPE       MPD
#   VERSION    0.19.0
#   eventCount 13063
#   mute       -1
#   helper:
#     RUNNING_PID:
#       abortArg  
#       abortFn   
#       arg        MPD_remote
#       bc_pid     45199
#       finishFn   MPD_IdleDone
#       fn         MPD_IdleStart
#       pid        14481
#       timeout   
#     playlistcollection:
#       val        -1

Und hier noch einige Versionsinformationen:

mpd (lokal): 0.19.21
mpd (remote, der problematische): 0.23.12

FHEM rev.: 28809
fhem.pl rev.: 28666
73_MPD.pm rev.: 27027

Hat irgendwer 'ne Ahnung, was hier vor sich gehen könnte?
Da ich persönlich eher mittelmäßig in der Materie verwurzelt bin, wäre ich für jeden Hinweis, in welche Richtung ich weitergehen sollte, dankbar.

LG
Rigor