[37_echodevice] Amazon Echo Modul (nicht Alexa)

[michael.winkler]

Hallo zusammen,
ich hab seit ein paar Tagen/Wochen das Problem das Fhem riesen Logfiles erzeugt was das System dann lahm legt, dazu hatte ich diese Thread eröffnet.
https://forum.fhem.de/index.php/topic,118401.0.html

Jetzt hat sich dabei rausgestellt das es wohl am Echo Modul liegt, denn sobald ich dieses deaktiviere besteht das Problem nicht mehr, nach dem ich es wieder aktiviert habe ist es direkt wieder da.

Ist das ein bekanntes problem und wie kann ich es lösen?

Was steht denn im LOG?

[michael.winkler]

Ab morgen früh steht eine neue Version zur Verfügung.

Code Auswählen Erweitern


# 2021.02.10 v0.2.9
# - BUG:     Probleme wenn getbehavior keine Antwort liefert.
# - CHANGE:  CMD_Queue check
#            ($hash->{model} eq "Reverb" || $hash->{model} eq "Sonos One" || $hash->{model} eq "Sonos Beam" Unterscheidung entfernt
# - FEATURE: Geräte Kennung THIRD_PARTY_AVS_SONOS_BOOTLEG hinzugefügt
#


Danke für die Unterstützung und Geduld mit mir  @JoWiemann

[JoWiemann]

Danke für die Unterstützung und Geduld mit mir  @JoWiemann

Hallo Michael,

gern geschehen und jederzeit wieder. Hat Spaß gemacht.

Grüße Jörg

[Tommy82]

Was steht denn im LOG?

Jede Menge dieser Meldungen

Code Auswählen Erweitern

2021.02.10 05:18:38.440 1: Accept failed (telnetPort: Too many open files)
2021.02.10 05:18:38.442 1: Accept failed (AMAD: Too many open files)
2021.02.10 05:18:38.444 1: Accept failed (telnetPort: Too many open files)
2021.02.10 05:18:38.446 1: Accept failed (AMAD: Too many open files)
2021.02.10 05:18:38.447 1: Accept failed (telnetPort: Too many open files)

über ein

Code Auswählen Erweitern

lsof -p 31002 (fhem/perl pid) zeigt dann aber viele zugriffe auf

Code Auswählen Erweitern

perl    31002 fhem  248u  IPv4    7052318       0t0     TCP Cubie.fritz.box:37778->server-99-86-1-173.fra6.r.cloudfront.net:https (CLOSE_WAIT)
perl    31002 fhem  249u  IPv4    7052352       0t0     TCP Cubie.fritz.box:37790->server-99-86-1-173.fra6.r.cloudfront.net:https (CLOSE_WAIT)
perl    31002 fhem  250u  IPv4    7051974       0t0     TCP Cubie.fritz.box:42852->server-13-225-74-35.fra2.r.cloudfront.net:https (CLOSE_WAIT)
perl    31002 fhem  251u  IPv4    7052635       0t0     TCP Cubie.fritz.box:37830->server-99-86-1-173.fra6.r.cloudfront.net:https (CLOSE_WAIT)

[michael.winkler]

Jede Menge dieser Meldungen

Code Auswählen Erweitern

2021.02.10 05:18:38.440 1: Accept failed (telnetPort: Too many open files)
2021.02.10 05:18:38.442 1: Accept failed (AMAD: Too many open files)
2021.02.10 05:18:38.444 1: Accept failed (telnetPort: Too many open files)
2021.02.10 05:18:38.446 1: Accept failed (AMAD: Too many open files)
2021.02.10 05:18:38.447 1: Accept failed (telnetPort: Too many open files)

über ein

Code Auswählen Erweitern

lsof -p 31002 (fhem/perl pid) zeigt dann aber viele zugriffe auf

Code Auswählen Erweitern

perl    31002 fhem  248u  IPv4    7052318       0t0     TCP Cubie.fritz.box:37778->server-99-86-1-173.fra6.r.cloudfront.net:https (CLOSE_WAIT)
perl    31002 fhem  249u  IPv4    7052352       0t0     TCP Cubie.fritz.box:37790->server-99-86-1-173.fra6.r.cloudfront.net:https (CLOSE_WAIT)
perl    31002 fhem  250u  IPv4    7051974       0t0     TCP Cubie.fritz.box:42852->server-13-225-74-35.fra2.r.cloudfront.net:https (CLOSE_WAIT)
perl    31002 fhem  251u  IPv4    7052635       0t0     TCP Cubie.fritz.box:37830->server-99-86-1-173.fra6.r.cloudfront.net:https (CLOSE_WAIT)

und was sollen diese Einträge mit dem Modul zu tun haben? Wo ist hier der Zusammenhang?

[Tommy82]

Das ist eine gute Frage, der Zusammenhang kommt daher das das

r.cloudfront.net:https

wohl ein AWS Server ist, was mich dann auf die Suche in diesem Bereich (Echomodul oder Alex, da ich nur diese beiden Sachen aktiv habe) gebracht hat, hab dann beides deaktiviert und dann waren die Einträge weg, ich hab dann das Alexa Modul wieder aktiviert und einen Tag gewartet, auch keine Log Einträge, dann habe ich das Echo Modul wieder aktiviert und hatte am folge Tag wieder das Log voll. Hab das MOdul dann wieder deaktiviert und seit dem keine Probleme mehr. Daher vermute ich einen Zusammenhang zwischen dem Echo Modul und meinem Problem.

[michael.winkler]

Das ist eine gute Frage, der Zusammenhang kommt daher das das  wohl ein AWS Server ist, was mich dann auf die Suche in diesem Bereich (Echomodul oder Alex, da ich nur diese beiden Sachen aktiv habe) gebracht hat, hab dann beides deaktiviert und dann waren die Einträge weg, ich hab dann das Alexa Modul wieder aktiviert und einen Tag gewartet, auch keine Log Einträge, dann habe ich das Echo Modul wieder aktiviert und hatte am folge Tag wieder das Log voll. Hab das MOdul dann wieder deaktiviert und seit dem keine Probleme mehr. Daher vermute ich einen Zusammenhang zwischen dem Echo Modul und meinem Problem.

Ich sehe da immer noch keinen Zusammenhang! Ja das echo Modul arbeitet mit Amazon, aber die URL "server-99-86-1-173.fra6.r.cloudfront.net" ist aus Modulsicht unbekannt.

Die Fehlermeldung wird auch von AMAD und TelnetPort geschrieben. Ich würde eher mal dort suchen, warum die beiden Module hier das LOG vollballern. Das echo Modul schreibt ja nichts ins LOG.

[ghoost82]

Ich habe seit ein paar Tagen genau das selbe Phänomen. Aufgetreten ist es nachdem ich mein Debian System inklusive des FHEM Servers und allen Node Pakete aktualisiert habe.

Die Logeinträge von AMAD oder TelnetPort sagen nur das keine neuen Verbindungen mehr aufgebaut werden können da das Maximum der offenen Dateien für den FHEM Perl Prozess erreicht sind. Schaut man sich nun mit lsof die offenen Verbindungen an fallen einen viele Einträge mit CLOSE_WAIT auf die auf diverse cloudfront Server zeigen. Diese sind teil des Amazon CDNs. Auch wenn diese Adressen nicht direkt vom Modul angesprochen werden ist es ist durchaus möglich das diese durch Weiterleitungen, Loadbalancing etc dennoch verwendet werden.

Das CLOSE_WAIT sieht danach aus das ein Childprozess die Verbindung noch offen hält und dadrauf wartet das ein Rückgabewert oder Ähnliches abgerufen wird.
Ob der Fehler jetzt im Modul verursacht wird oder in einer externen verwendeten Komponente kann ich nicht sagen.

[samsmooth]

Hallo zusammen.

Ich habe seit ein paar Wochen das Problem, dass sämtliche Echos im Haus die Wiedergabe ca. innerhalb einer Minute unvermittelt stoppen.

Nachdem ich zunächst unsere WLAN-Netze in Verdacht hatte, bin ich nun darauf gekommen mal den FHEM-Rpi auszustecken. Und siehe da: Die Musik stoppt nicht mehr.

Kann es an dem Modul liegen? Hat jemand ähnliche Erfahrungen gemacht?

Gruß

[michael.winkler]

Ich habe seit ein paar Tagen genau das selbe Phänomen. Aufgetreten ist es nachdem ich mein Debian System inklusive des FHEM Servers und allen Node Pakete aktualisiert habe.

Die Logeinträge von AMAD oder TelnetPort sagen nur das keine neuen Verbindungen mehr aufgebaut werden können da das Maximum der offenen Dateien für den FHEM Perl Prozess erreicht sind. Schaut man sich nun mit lsof die offenen Verbindungen an fallen einen viele Einträge mit CLOSE_WAIT auf die auf diverse cloudfront Server zeigen. Diese sind teil des Amazon CDNs. Auch wenn diese Adressen nicht direkt vom Modul angesprochen werden ist es ist durchaus möglich das diese durch Weiterleitungen, Loadbalancing etc dennoch verwendet werden.

Das CLOSE_WAIT sieht danach aus das ein Childprozess die Verbindung noch offen hält und dadrauf wartet das ein Rückgabewert oder Ähnliches abgerufen wird.
Ob der Fehler jetzt im Modul verursacht wird oder in einer externen verwendeten Komponente kann ich nicht sagen.

Welche ECHO Device Version habt Ihr im Einsatz? schickt mal ein get status vom Account Device

[michael.winkler]

Hallo zusammen.

Ich habe seit ein paar Wochen das Problem, dass sämtliche Echos im Haus die Wiedergabe ca. innerhalb einer Minute unvermittelt stoppen.

Nachdem ich zunächst unsere WLAN-Netze in Verdacht hatte, bin ich nun darauf gekommen mal den FHEM-Rpi auszustecken. Und siehe da: Die Musik stoppt nicht mehr.

Kann es an dem Modul liegen? Hat jemand ähnliche Erfahrungen gemacht?

Gruß

Es wurde schon öfters von diesem Problem berichtet. Ich kann es leider nicht nachvollziehen.

[Per]

Ja, ich. ABER: nur beim Echo Show (5). Sobald ich den Pi wieder anstöpsle, geht nach kurzer Zeit der Show wieder aus. Die Dots 3 (+/- Uhr) gehen unbeeindruckt weiter.
Interessanterweise gibt es im EventLog oder den Readings keine Info.

[ghoost82]

Welche ECHO Device Version habt Ihr im Einsatz? schickt mal ein get status vom Account Device

Code Auswählen Erweitern


Modul Infos:

Beschreibung    Bereich    Wert
STATE    Reading connected
Version    Reading 0.2.9
NPM Cookie Version    Reading 3.4.2
COOKIE_STATE    Reading OK
COOKIE_TYPE    Reading READING_NPM
COOKIE_MODE    Reading NPM
amazon_refreshtoken    Reading vorhanden
npm_refresh_intervall    Attribut 86400
room    Attribut Amazon
.*    Attribut 1
icon    Attribut echo
event-on-change-reading    Attribut .*
server    Attribut layla.amazon.de

Amazon Cookie:

Beschreibung    Bereich    Wert
.COOKIE    Reading {"loginCookie":"frc=....
COOKIE_STATE    Reading OK
COOKIE_TYPE    Reading READING_NPM
amazon_refreshtoken    Reading vorhanden
.COOKIE    Helper session-id=261-15092....
.COMMSID    Helper amzn1.comms.id.perso....
.CSRF    Helper -15....
.DIRECTID    Helper amzn1.account.AG6UB6....
RUNLOGIN    Helper 0
RUNNING_REQUEST    Helper 0
LOGINERROR    Helper 0


[Per]

ABER: nur beim Echo Show (5).

Gruppen gehen auch. Ist in der Gruppe ein Show (5), geht die ganze Gruppe aus.

Modul Infos:

Code Auswählen Erweitern

Beschreibung    Bereich    Wert
STATE    Reading connected
Version    Reading 0.2.9
NPM Cookie Version    Reading 3.4.2
COOKIE_STATE    Reading OK
COOKIE_TYPE    Reading NPM_Login
COOKIE_MODE    Reading NPM
amazon_refreshtoken    Reading vorhanden
server    Attribut layla.amazon.de
autocreate_refresh    Attribut 1
event-on-change-reading    Attribut .*
webCmd    Attribut autocreate_devices


Amazon Cookie:
Beschreibung    Bereich    Wert
.COOKIE    Reading {"loginCookie":"frc=....
COOKIE_STATE    Reading OK
COOKIE_TYPE    Reading NPM_Login
amazon_refreshtoken    Reading vorhanden
.COOKIE    Helper session-id=258-64873....
.COMMSID    Helper amzn1.comms.id.perso....
.CSRF    Helper 625....
.DIRECTID    Helper amzn1.account.AECZPL....
RUNLOGIN    Helper 0
RUNNING_REQUEST    Helper 0
LOGINERROR    Helper 0

Update: nicht das Ziel ist entscheident, sondern wo ich es reinspreche. Bei einem Dot geht es, beim Show (5) nicht. Bzw. wenn ich bei "laufenden Programm" mit dem Show (5) spreche (ansprechen ohne Befehl reicht), bricht es nach kurzer Zeit ab. Gebe ich den Befehl über Fhem direkt an den Show (5) ab, funktioniert alles.

Update2: jetzt habe ich soviel probiert, jetzt tritt der Fehler nicht mehr auf 
set xxx ging, set textcommand kann ich nicht mehr testen, da s.o.

[samsmooth]

Gruppen gehen auch. Ist in der Gruppe ein Show (5), geht die ganze Gruppe aus.

Danke für den Hinweis, dann stöpsel ich den testweise mal aus...