Neuigkeiten:

Am Sonntag den 8.12.2024 kann es ab ca. 8:00 Uhr zu kurzzeitigen Einschränkungen / Ausfällen bei den Diensten des FHEM Vereines kommen.
Die Server müssen mal gewartet und dabei neu gestartet werden ;)

Hauptmenü

Modul für MPD

Begonnen von roedert, 08 Januar 2014, 12:17:21

Vorheriges Thema - Nächstes Thema

HGButte

Habe meinen Raspi von bullseye auf bookworm upgegradet.

Bei mpd selbst musste ich einige Änderungen machen. Ich nutze einen usb audio Stick und nicht das Original Raspi Audio. Nach dem Upgrade hat sich da einiges geändert. Mpd selbst läuft jetzt aber wieder.

Aktuell bringt aber das 73_MPD Modul meinen fhem Server komplett zum Absturz direkt nach dessen Start.

2023.10.09 18:49:47 1: Including fhem.cfg
2023.10.09 18:50:00 1: Including ./log/fhem.save
2023.10.09 18:50:09 0: Featurelevel: 6.2
2023.10.09 18:50:09 0: Server started with 261 defined entities (fhem.pl:28007/2023-09-28 perl:5.036000 os:linux user:fhem pid:18978)
2023.10.09 18:50:10 1: PERL WARNING: Use of uninitialized value $data in concatenation (.) or string at ./FHEM/73_MPD.pm line 1485, <FILE> line 1.
2023.10.09 18:50:11 1: PERL WARNING: timeout at ./FHEM/73_MPD.pm line 1033.
        main::__ANON__("ALRM") called at ./FHEM/73_MPD.pm line 1035
        eval {...} called at ./FHEM/73_MPD.pm line 1035
        eval {...} called at ./FHEM/73_MPD.pm line 1032
        main::mpd_cmd(HASH(0x3fea798), "i|outputs|x") called at ./FHEM/73_MPD.pm line 972
        main::MPD_Outputs_Status(HASH(0x3fea798)) called at ./FHEM/73_MPD.pm line 204
        main::MPD_updateConfig(HASH(0x3fea798)) called at fhem.pl line 3503
        main::HandleTimeout() called at fhem.pl line 705

Glaube das Problem ist erst nach einem "apt autoremove" aufgetreten. Bin mit aber nicht wirklich sicher.

Kann es an perl 5.36 liegen?

HGButte

Problem gelöst.

Long story short: Ich hatte ein Userreading, dass scheinbar bei der neuen mpd version von bookworm nicht mehr so wollte.

Medel

Ich bekomme immer wieder einen socket error

2024.01.01 23:36:43 5: myMPD, idle PID 13494 found

2024.01.01 23:37:43 5: myMPD, idle PID 13494 found
2024.01.01 23:37:43 5: myMPD, MPD_EVENT : playlist
2024.01.01 23:37:43 4: myMPD, MPD_EVENT : playlist
2024.01.01 23:37:43 5: myMPD, new Playlist in ->
2024.01.01 23:37:43 5: myMPD, IdleDone -> myMPD|socket error
2024.01.01 23:37:43 4: myMPD, idle error -> socket error

2024.01.01 23:38:43 4: myMPD, Idle new PID : 14065
2024.01.01 23:38:43 5: myMPD, mpd_cmd[1] -> command_list_begin
status
stats
currentsong
command_list_end
2024.01.01 23:38:43 5: myMPD, rec: volume: 100
2024.01.01 23:38:43 5: myMPD, rec: repeat: 0
2024.01.01 23:38:43 5: myMPD, rec: random: 0
2024.01.01 23:38:43 5: myMPD, rec: single: 0
2024.01.01 23:38:43 5: myMPD, rec: consume: 0
2024.01.01 23:38:43 5: myMPD, rec: playlist: 2
2024.01.01 23:38:43 5: myMPD, rec: playlistlength: 1
2024.01.01 23:38:43 5: myMPD, rec: xfade: 0
2024.01.01 23:38:43 5: myMPD, rec: state: play
2024.01.01 23:38:43 5: myMPD, rec: song: 0
2024.01.01 23:38:43 5: myMPD, rec: songid: 1
2024.01.01 23:38:43 5: myMPD, rec: time: 2109:0
2024.01.01 23:38:43 5: myMPD, rec: elapsed: 2109.267
2024.01.01 23:38:43 5: myMPD, rec: bitrate: 0
2024.01.01 23:38:43 5: myMPD, rec: artists: 0
2024.01.01 23:38:43 5: myMPD, rec: albums: 0
2024.01.01 23:38:43 5: myMPD, rec: songs: 0
2024.01.01 23:38:43 5: myMPD, rec: uptime: 0
2024.01.01 23:38:43 5: myMPD, rec: db_playtime: 0
2024.01.01 23:38:43 5: myMPD, rec: db_update: 0
2024.01.01 23:38:43 5: myMPD, rec: playtime: 0
2024.01.01 23:38:43 5: myMPD, rec: file: tunein:station:s24896
2024.01.01 23:38:43 5: myMPD, rec: Time: 0
2024.01.01 23:38:43 5: myMPD, rec: Artist: SWR3
2024.01.01 23:38:43 5: myMPD, rec: Album: SWR3
2024.01.01 23:38:43 5: myMPD, rec: Title: Bad / Michael Jackson
2024.01.01 23:38:43 5: myMPD, rec: Name: Mehr Hits. Mehr Kicks. Einfach SWR3
2024.01.01 23:38:43 5: myMPD, rec: Pos: 0
2024.01.01 23:38:43 5: myMPD, rec: Id: 1
2024.01.01 23:38:43 5: myMPD, rec: X-AlbumUri: tunein:station:s24896
2024.01.01 23:38:44 5: myMPD, mpd_cmd[2] -> command_list_begin
status
stats
currentsong
command_list_end

hier meine config
defmod myMPD MPD 192.168.1.31 6660
attr myMPD alias myMPD
attr myMPD devStateIcon play:rc_PLAY:stop stop:rc_STOP:play pause:rc_PAUSE:pause error:icoBlitz
attr myMPD icon it_radio
attr myMPD loadPlaylists 1
attr myMPD player mopidy
attr myMPD titleSplit 0
attr myMPD unknown_artist_image /fhem/icons/1px-spacer
attr myMPD verbose 5

soweit ich herausgefunden habe immer bei einem Playlist Event in dem die Liste scheinbar leer ist

Beta-User

Zitat von: Medel am 01 Januar 2024, 23:56:19Ich bekomme immer wieder einen socket error
Na ja, das wird mit verbose 4 bzw. 5 geloggt. Sowas ist in der Regel dann eher kein echtes Problem, oder übersehe ich was?
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

Medel

Es kommt aber auch ein state: error und presence: absend

Ein weiteres Problem das mir aufgefallen ist:
Wenn ich das play Kommando schicke wird der Player gestartet aber der state play nicht angezeigt.
Erst beim 2. play oder beim abfragen des  status requests

Medel

Hier ist noch der Log von mopidy wenn der Fehler (socket error) auftritt:
DEBUG    [MainThread] mopidy.audio.gst Got TAG bus message: tags={'title': ['SWR3 NOW   Die Vormittagsshow'], 'has-crc': [False], 'channel-mode': ['joint-stereo'], 'audio-codec': ['MPEG-1 Layer 3 (MP3)'], 'nominal-bitrate': [128000], 'minimum-bitrate': [128000], 'maximum-bitrate': [128000], 'bitrate': [128000]}
DEBUG    [MainThread] mopidy.audio.actor Audio event: tags_changed(tags=['title'])
DEBUG    [MainThread] mopidy.listener Sending tags_changed to AudioListener: {'tags': ['title']}
DEBUG    [Core-8] mopidy.listener Sending stream_title_changed to CoreListener: {'title': 'SWR3 NOW   Die Vormittagsshow'}
DEBUG    [MpdFrontend-11] mopidy.listener Sending playlist to MpdSession: {}
DEBUG    [AutoplayFrontend-13] mopidy_autoplay.frontend on_event(stream_title_changed, {'title': 'SWR3 NOW   Die Vormittagsshow'})
DEBUG    [MpdSession-18] mopidy_mpd.session Request from [::ffff:192.168.1.34]:59880: idle
DEBUG    [MpdSession-18] mopidy_mpd.session Request from [::ffff:192.168.1.34]:59880: idle
DEBUG    [MpdSession-18] mopidy_mpd.dispatcher Client sent us 'idle', only 'noidle' is allowed while in the idle state
DEBUG    [MpdSession-18] pykka Unregistered MpdSession (urn:uuid:20ffdc5c-f13f-40fc-9590-ff20f795d59d)
DEBUG    [MpdSession-18] pykka Stopped MpdSession (urn:uuid:20ffdc5c-f13f-40fc-9590-ff20f795d59d)
DEBUG    [MpdSession-18] mopidy_mpd.network Actor is shutting down.

Medel

#696
Habe mal in der 73_MPD.pm noch ein OK eingefügt:
1285     elsif ($_ !~ m{\Aplayer|playlist|mixer|options|update|OK\z}x){
Bisher hatte ich keinen socket error mehr und auch das Problem mit dem Play und der Aktualisierung ist weg. Wird gleich beim erstem Mal richtig angezeigt.
Bitte mal jemand der sich damit besser auskennt darüber schauen und ggf. einpflegen.

Medel

Kann sich jemand der sich mit MPD befasst mal darum kümmern?
ZitatHabe mal in der 73_MPD.pm noch ein OK eingefügt:
Code Auswählen
1285     elsif ($_ !~ m{\Aplayer|playlist|mixer|options|update|OK\z}x){
Bisher hatte ich keinen socket error mehr und auch das Problem mit dem Play und der Aktualisierung ist weg. Wird gleich beim erstem Mal richtig angezeigt.
Bitte mal jemand der sich damit besser auskennt darüber schauen und ggf. einpflegen.

Beta-User

Zitat von: Medel am 02 Januar 2024, 15:05:08Habe mal in der 73_MPD.pm noch ein OK eingefügt:
1285     elsif ($_ !~ m{\Aplayer|playlist|mixer|options|update|OK\z}x){
Bisher hatte ich keinen socket error mehr und auch das Problem mit dem Play und der Aktualisierung ist weg. Wird gleich beim erstem Mal richtig angezeigt.
Bitte mal jemand der sich damit besser auskennt darüber schauen und ggf. einpflegen.
Hab's auf der Liste, muss aber erst schauen, ob es mit dem normalen MPD damit keine Probleme gibt.
Hoffe, ggf. dieses WE dazu zu kommen.
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

Medel

Gibt es zu meinem Problem schon was neues :) . Habe es immer noch von dem update ausgeschlossen :(

Beta-User

#700
Zitat von: Medel am 30 März 2024, 12:17:22Gibt es zu meinem Problem schon was neues :) . Habe es immer noch von dem update ausgeschlossen :(
Hmmmm, hab's mir angesehen, aber....:

- der OK-Fall ist innerhalb des Codes (im Rahmen der fraglichen while-Schleife) eigentlich auch (mehrfach) berücksichtigt
- Falls das Problem nicht doch ganz woanders herhommt, würde ich eher den "OK"-Teil im Hinblick auf das anscheinend andere Verhalten von mopidity ändern wollen. Dafür bitte deinen Fix rückgängig machen und es mal damit probieren:

# ab Zeile 1294
 else { #if ($_ eq "OK") 
 if ($step || AttrVal($name,'player','mpd') eq 'mopidy') {
 print $sock "idle\n";
 } else {
 print $sock "playlistinfo\n";
 }
 $step=2 if ($step==1);
    } # OK
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

Medel

So hab's mal getestet. Das Problem wird durch diese Änderung nicht behoben. Was mir aufgefallen ist:
Eine Änderung macht sich erst mit Neustart von Fhem bemerkbar, ein einfaches reload reicht nicht.
Habe mal ein paar Testzeilen eingefügt:
     elsif ($_ !~ m{\Aplayer|playlist|mixer|options|update\z}x){
 Log3 $name,5,"$name, Idle test1 : $_";
 Log3 $name,5,"$name, Idle test1 step : $step";
      print $sock "idle\n";
       $step=1;
       readingsSingleUpdate($hash,'last_error',$_,1);
     }
     elsif ($_ eq 'update'){ #might be extended for other new message types w/o further action to FHEM
 Log3 $name,5,"$name, Idle test2 : $_";
 Log3 $name,5,"$name, Idle test2 step : $step";
       print $sock "idle\n";
       $step=1;
     }
     else { #if ($_ eq "OK") 
 Log3 $name,5,"$name, Idle test3 : $_";
 Log3 $name,5,"$name, Idle test3 step : $step";
       if ($step || AttrVal($name,'player','mpd') eq 'mopidy') {
         print $sock "idle\n";
       } else {
         print $sock "playlistinfo\n";
       }
       $step=2 if ($step==1);
    } # OK

Hier der Log, vielleicht hilft es weiter:
command_list_end
2024.04.21 16:34:55 5: myMPD, Idle test1 : OK
2024.04.21 16:34:55 5: myMPD, Idle test1 step : 0
2024.04.21 16:35:15 5: myMPD, Idle test3 : playlist
2024.04.21 16:35:15 5: myMPD, Idle test3 step : 1
2024.04.21 16:35:15 5: myMPD, Idle test1 : OK
2024.04.21 16:35:15 5: myMPD, Idle test1 step : 0
2024.04.21 16:35:15 5: myMPD, MPD_EVENT : playlist
2024.04.21 16:35:15 4: myMPD, MPD_EVENT : playlist
2024.04.21 16:35:15 5: myMPD, new Playlist in ->
2024.04.21 16:35:15 5: myMPD, IdleDone -> myMPD|socket error
2024.04.21 16:35:15 4: myMPD, idle error -> socket error
2024.04.21 16:36:15 4: myMPD, Idle new PID : 1130680
2024.04.21 16:36:15 5: myMPD, mpd_cmd[1] -> command_list_begin
status

Beta-User

Ups, irgendwie stand ich da wohl auf dem (Invertierungs-) Schlauch, sorry....

Habe den Fix
Zitat von: Medel am 02 Januar 2024, 15:05:08Habe mal in der 73_MPD.pm noch ein OK eingefügt:
wie vorgeschlagen eingecheckt, nachdem das jüngst auch hier nochmal aufgeschlagen war: https://forum.fhem.de/index.php?topic=138009.0

Danke für's mehrfache Schubsen!
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

CBSnake

Moin zusammen,

heute Nacht hat mein FHEM beschlossen sich mal eine Pause zu gönnen, kein Problem starte ich halt neu. Laut systemctl alles i.O. trotzdem ist weder die Weboberfläche zu erreichen noch funktioniert sonst irgendwas. Im Log dann schnell den Übeltäter gefunden 73_MPD ;-) - .pm Datei gelöscht, neustart, geht wieder. Update gemacht, geht noch immer, MPD Device angelegt, ging noch und dann versucht einen Stream abzuspielen, zack wieder abgestürzt :-(

2024.11.08 05:38:14.682 1: PERL WARNING: timeout at ./FHEM/73_MPD.pm line 1033.
main::__ANON__("ALRM") called at ./FHEM/73_MPD.pm line 1035
eval {...} called at ./FHEM/73_MPD.pm line 1035
eval {...} called at ./FHEM/73_MPD.pm line 1032
main::mpd_cmd(HASH(0x560dd9b38690), "i|outputs|x") called at ./FHEM/73_MPD.pm line 972
main::MPD_Outputs_Status(HASH(0x560dd9b38690)) called at ./FHEM/73_MPD.pm line 204
main::MPD_updateConfig(HASH(0x560dd9b38690)) called at fhem.pl line 3508
main::HandleTimeout() called at fhem.pl line 707
2024.11.08 05:38:14.682 1: stacktrace:
2024.11.08 05:38:14.682 1:     main::__ANON__                      called by /usr/lib/x86_64-linux-gnu/perl-base/Carp.pm (291)
2024.11.08 05:38:14.683 1:     Carp::carp                          called by ./FHEM/73_MPD.pm (1033)
2024.11.08 05:38:14.683 1:     main::__ANON__                      called by ./FHEM/73_MPD.pm (1035)
2024.11.08 05:38:14.683 1:     (eval)                              called by ./FHEM/73_MPD.pm (1035)
2024.11.08 05:38:14.683 1:     (eval)                              called by ./FHEM/73_MPD.pm (1032)
2024.11.08 05:38:14.683 1:     main::mpd_cmd                       called by ./FHEM/73_MPD.pm (972)
2024.11.08 05:38:14.684 1:     main::MPD_Outputs_Status            called by ./FHEM/73_MPD.pm (204)
2024.11.08 05:38:14.684 1:     main::MPD_updateConfig              called by fhem.pl (3508)
2024.11.08 05:38:14.684 1:     main::HandleTimeout                 called by fhem.pl (707)

Das angesprochene Device ist im Netzwerk erreichbar, MPD ist dort auch active/running *hmmm*

Jetzt ist erstmal die Familie am Aufstehen, da will nicht nicht rumprobieren und ständig neu starten ;-)

Kann nachher aber mal noch das zweite MPD Endgerät testen bzw. das erste auch mal neu starten.

Viele Grüße
Achim
FHEM auf Debian 10, HM-Wlan, JeeLink-Wlan, Wlanduino, ConBee, TP-Link Steckdose, GHoma Steckdosen, Shelly Steckdosen

Beta-User

#704
Moin,

hab jetzt mal einen ersten Blick in den Code geworfen, der problematische Code scheint von mir zu stammen...

Wir hatten sowas hier schon mal gemeldet, erst mal mit einer Entwarnung am Ende:
Zitat von: HGButte am 10 Oktober 2023, 21:50:55Problem gelöst.

Long story short: Ich hatte ein Userreading, dass scheinbar bei der neuen mpd version von bookworm nicht mehr so wollte.
Fragen:
- Könnte das hier auch ein Thema sein? (Verdacht: Der "alte" oder weitere "Fehler" im userReadings-Code bringt carp durcheinander)
- Funktioniert es, wenn du um Modulcode die alte Fassung von diesem Bereich verwendest (siehe z.B. https://forum.fhem.de/index.php?msg=1225609)?

Nachtrag:

Eventuell könnte der (bisher ungetestete) geänderte Schnippsel hier weiterhelfen:
if ( !eval {
        local $SIG{ALRM} = sub {Carp::carp 'timeout\n';}; #see https://perldoc.perl.org/functions/alarm
        alarm(1);
        while (<$sock>)      # MPD rede mit mir , egal was ;)
            { last if $_ ; } # end of output.
        alarm(0);
        1; }
    ) {
        return $@ if $@ && $@ eq "timeout\n"; # propagate unexpected errors
    }
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files