[Altes Modul] GoogleCast (98_GOOGLECAST.pm)

dominik · 04 September 2020, 15:20:39

Danke! Findest du im FHEM Log vielleicht noch Eintraege um diese Uhrzeit 2020-09-04 02:48:37,963 . Weil ca. um diese Zeit duerfte aus irgendeinem Grund die Verbindung zwischen FHEM und PythonBinding abgerissen sein.

JF Mennedy · 04 September 2020, 15:26:43

Hier der Auszug von heute Nacht...

dominik · 04 September 2020, 15:36:58

Sieht fast so aus, als wuerde pythonbinding ein zweites Mal gestartet worden sein. Wegen dieser Log Meldung:
2020.09.04 02:48:43 3: Pythonbinding_15733: using logfile: ./log/PythonBinding-2020-09-04.log

Hast du vielleicht noch ein 2. PythonBinding Device von vorigen Tests? Ich werde dennoch bisschen was umbauen, damit bei fehlerhaften Verbindungen nach ein paar Timeouts ein Reconnect gemacht wird. Das loest aber noch nicht den Ursprung des Problems.

JF Mennedy · 04 September 2020, 15:42:35

Da sollte nichts mehr gewesen sein... Ich hatte vor dem Update alles gelöscht...

dominik · 04 September 2020, 20:54:41

Kannst du bitte noch im FHEM Log schauen was vor 2020.09.04 02:48:42 passiert ist? Ich habe gerade gesehen, dass pythonbinding per Websocket die Msg um 2020.09.04 02:48:37 versendet hat, die jedoch erst um 2:48:42 in FHEM angekommen ist. Kann es vielleicht sein, dass ein anderes Device FHEM zu der Zeit blockiert hat?
Diesen Fall habe ich nämlich noch nicht berücksichtigt, wenn die FHEM Mainloop für längere Zeit blockiert ist.

JF Mennedy · 04 September 2020, 21:02:56

Da war eigentlich nix besonderes...:

Code Auswählen

2020.09.04 02:43:22 1: NaturallySalt, RX, 676, old: 0
2020.09.04 02:43:43 1: NaturallySalt, RX, 677, old: 0
2020.09.04 02:45:13 1: NaturallySalt, RX, 676, old: 0
2020.09.04 02:45:25 1: NaturallySalt, RX, 677, old: 0
2020.09.04 02:48:42 5: BindingsIo: DevIo_SimpleRead
2020.09.04 02:48:42 5: BindingsIo: DevIo_SimpleRead NoTimeout

dominik · 04 September 2020, 21:37:05

Hmm...ich finde leider den Fehler noch nicht. Ich bau jetzt ein, dass nach 3 Timeouts hintereinander die Verbindung neu aufgebaut wird. Falls der Fehler wieder auftritt, melde dich bitte wenn moeglich ohne sofort neu zu starten, damit wir das dann gemeinsam anschauen koennen.

JF Mennedy · 04 September 2020, 21:41:36

OK... Wenn es passiert wenn wir nicht zu Hause sind können wir das gerne zusammen durchschauen... Aber wenn hier halligalli ist muss ich wohl oder übel neu starten 🤪

dominik · 04 September 2020, 21:42:57

Zitat von: JF Mennedy am 04 September 2020, 21:41:36
OK... Wenn es passiert wenn wir nicht zu Hause sind können wir das gerne zusammen durchschauen... Aber wenn hier halligalli ist muss ich wohl oder übel neu starten 🤪

Schon klar, das kenne ich

Sommerfeld · 07 September 2020, 08:26:44

Hallo Dominik,
vielen Dank für deine hervorragende Arbeit.
Ich teste zur Zeit deine Umstellung und es läuft soweit gut.
Allerdings habe ich nach jedem shutdown restart jedesmal die Meldung
im Device:

Function execution >1s, cancelled: Castdevice_Schlafzimmer - Define

Nachdem ich das Device definiert habe, läuft wieder alles wie gewollt.

Code Auswählen

Internals:
   .FhemMetaInternals 1
   DEF        googlecast "Schlafzimmer"
   FUUID      5f51370d-f33f-3b5c-2838-a9213a700e951cc1
   FVERSION   10_PythonModule.pm:0.182830/2019-01-16
   IODev      pythonbinding
   NAME       Castdevice_Schlafzimmer
   NR         1093
   PYTHONTYPE googlecast
   STATE      Function execution >1s, cancelled: Castdevice_Schlafzimmer - Define
   TYPE       PythonModule
   .attraggr:
   .attrminint:
   READINGS:
     2020-09-06 22:32:14   app_id          
     2020-09-03 21:01:21   cast_type       audio
     2020-09-07 08:07:51   connection      disconnected
     2020-09-06 22:32:14   display_name    
     2020-09-03 21:01:21   ignore_cec      0
     2020-09-06 22:29:08   mediaAlbum      
     2020-09-06 22:32:14   mediaContentId  
     2020-09-06 22:32:14   mediaContentType 
     2020-09-03 21:08:59   mediaCurrentPosPercent 
     2020-09-03 21:20:35   mediaCurrentPosition 0
     2020-09-03 21:08:59   mediaDuration   
     2020-09-06 22:32:14   mediaPlayerState UNKNOWN
     2020-09-06 22:32:14   mediaStreamType UNKNOWN
     2020-09-06 22:32:14   mediaTitle      
     2020-09-03 21:01:21   model_name      Google Home Mini
     2020-09-03 21:01:21   mute            0
     2020-09-03 21:01:21   name            Schlafzimmer
     2020-09-06 22:32:14   session_id      
     2020-09-07 08:07:52   state           Function execution >1s, cancelled: Castdevice_Schlafzimmer - Define
     2020-09-06 22:32:14   status_text     
     2020-09-06 22:32:14   transport_id    
     2020-09-03 21:01:21   uuid            0b17bd65-d266-18c8-2974-ef2efd4e3731
     2020-09-06 21:07:16   volume          50
   args:
     Castdevice_Schlafzimmer
     PythonModule
     googlecast
     Schlafzimmer
   argsh:
Attributes:
   comment    https://github.com/dominikkarall/fhem_pythonbinding

https://forum.fhem.de/index.php/topic,45505.765.html
   icon       hue_filled_aura@yellow
   room       01_0_OG->01_6_OG_Schlafzimmer,06_1_Sprachausgabe,Test

dominik · 08 September 2020, 23:32:30

Hi,

nutzt du die letzte Version? Falls nicht, mach bitte noch ein update, vor ca. 5 Tagen hatte ich da noch was verbessert.

Wenn du schon die letzte Version nutzt, poste bitte einen Auszug aus dem FHEM Log.

dominik · 09 September 2020, 21:49:32

Update gemacht, playFavorit mit 1-5 Favoriten im Attribut wird nun ebenfalls unterstuetzt.

Man kann nun auch das "verbose" Attribut nutzen, da wird dann das Log Level bei verbose=5 auf DEBUG im Python Modul gesetzt.

Wer weiter testen mag, kann auch mal folgendes testen:
define py_mdns PythonModule discover_mdns: Da werden alle Chromecasts automatisch erkannt und angelegt, genauso wie BOSE SoundTouch. Wenn bereits ein Device dazu existiert, wird es nicht neu angelegt.

JF Mennedy · 10 September 2020, 12:08:55

Hallo,

soweit alles i.O. Favoriten funktionieren, und auch das automatische Anlegen der Devices. Hatte seit dem letzten Ausfall auch keine Probleme mehr...

Gruss Jan

Sommerfeld · 10 September 2020, 20:27:14

Hallo Dominik,

Version 10_BindingsIo.pm:0.182830/2019-01-16
10_PythonModule.pm:0.182830/2019-01-16

Logauszug:

Code Auswählen

Server: Python/3.8 websockets/8.1
2020.09.10 18:27:17.560 4: BindingsIo: start PythonFunction: Castdevice_Schlafzimmer => Define (99861745)
2020.09.10 18:27:17.560 4: BindingsIo: <<< WS: {"msgtype":"function","PYTHONTYPE":"googlecast","NAME":"Castdevice_Schlafzimmer","id":99861745,"args":["Castdevice_Schlafzimmer","PythonModule","googlecast","Schlafzimmer"],"defargs":["Castdevice_Schlafzimmer","PythonModule","googlecast","Schlafzimmer"],"argsh":{},"defargsh":{},"function":"Define"}
2020.09.10 18:27:17.561 5: SW: 7b226d736774797065223a2266756e6374696f6e222c22505954484f4e54595045223a22676f6f676c6563617374222c224e414d45223a22436173746465766963655f5363686c61667a696d6d6572222c226964223a39393836313734352c2261726773223a5b22436173746465766963655f5363686c61667a696d6d6572222c22507974686f6e4d6f64756c65222c22676f6f676c6563617374222c225363686c61667a696d6d6572225d2c2264656661726773223a5b22436173746465766963655f5363686c61667a696d6d6572222c22507974686f6e4d6f64756c65222c22676f6f676c6563617374222c225363686c61667a696d6d6572225d2c226172677368223a7b7d2c226465666172677368223a7b7d2c2266756e6374696f6e223a22446566696e65227d
2020.09.10 18:27:17.562 5: BindingsIo: DevIo_SimpleRead
2020.09.10 18:27:17.562 5: BindingsIo: DevIo_SimpleRead WithTimeout
2020.09.10 18:27:17.563 4: BindingsIo: >>> WS: {"msgtype": "function", "PYTHONTYPE": "googlecast", "NAME": "Castdevice_Schlafzimmer", "id": 99861745, "args": ["Castdevice_Schlafzimmer", "PythonModule", "googlecast", "Schlafzimmer"], "defargs": ["Castdevice_Schlafzimmer", "PythonModule", "googlecast", "Schlafzimmer"], "argsh": {}, "defargsh": {}, "function": "Define", "finished": 1, "returnval": ""}
2020.09.10 18:27:17.564 5: BindingsIo: QUEUE: start handling - 1
2020.09.10 18:27:17.564 5: processMessage: {"msgtype": "function", "PYTHONTYPE": "googlecast", "NAME": "Castdevice_Schlafzimmer", "id": 99861745, "args": ["Castdevice_Schlafzimmer", "PythonModule", "googlecast", "Schlafzimmer"], "defargs": ["Castdevice_Schlafzimmer", "PythonModule", "googlecast", "Schlafzimmer"], "argsh": {}, "defargsh": {}, "function": "Define", "finished": 1, "returnval": ""}
2020.09.10 18:27:17.564 5: BindingsIo: QUEUE: finished handling - 0
2020.09.10 18:27:17.564 4: BindingsIo: end PythonFunction: Castdevice_Schlafzimmer => Define (99861745) - result: 
2020.09.10 18:27:17.565 3: pythonbinding device opened
2020.09.10 18:27:17.571 3: FS20 set BZ_EG_Spiegelschrank off
2020.09.10 18:27:17.616 1: PERL WARNING: Argument "undefined" isn't numeric in numeric eq (==) at ./FHEM/88_HMCCU.pm line 3403.
2020.09.10 18:27:17.660 3: FS20 set Gartenhaus_Deckenlicht off
2020.09.10 18:27:17.801 3: FBDECT set Lautsprecher_R off
2020.09.10 18:27:17.802 3: FBDECT set Lautsprecher_L off
2020.09.10 18:27:17.930 2: HMCCU: [d_ccu : 1035] Update success=47 failed=0
2020.09.10 18:27:18.061 1: PERL WARNING: Argument "undefined" isn't numeric in numeric eq (==) at ./FHEM/88_HMCCUCHN.pm line 220.
2020.09.10 18:27:18.567 5: BindingsIo: DevIo_SimpleRead
2020.09.10 18:27:18.567 5: BindingsIo: DevIo_SimpleRead NoTimeout
2020.09.10 18:27:18.567 4: BindingsIo: >>> WS: {"awaitId": 82351020, "NAME": "Castdevice_Schlafzimmer", "msgtype": "command", "command": "readingsBeginUpdate($defs{'Castdevice_Schlafzimmer'});;"}
2020.09.10 18:27:18.567 5: BindingsIo: QUEUE: start handling - 1
2020.09.10 18:27:18.567 5: processMessage: {"awaitId": 82351020, "NAME": "Castdevice_Schlafzimmer", "msgtype": "command", "command": "readingsBeginUpdate($defs{'Castdevice_Schlafzimmer'});;"}
2020.09.10 18:27:18.568 4: BindingsIo: <<< WS: {"awaitId":82351020,"result":"2020-09-10 18:27:18","error":0}
2020.09.10 18:27:18.568 5: SW: 7b2261776169744964223a38323335313032302c22726573756c74223a22323032302d30392d31302031383a32373a3138222c226572726f72223a307d
2020.09.10 18:27:18.569 5: BindingsIo: QUEUE: finished handling - 0
2020.09.10 18:27:18.625 5: BindingsIo: DevIo_SimpleRead
2020.09.10 18:27:18.625 5: BindingsIo: DevIo_SimpleRead NoTimeout
2020.09.10 18:27:18.625 4: BindingsIo: >>> WS: {"awaitId": 93316355, "NAME": "Castdevice_Schlafzimmer", "msgtype": "command", "command": "readingsBulkUpdateIfChanged($defs{'Castdevice_Schlafzimmer'},'state','offline');;"}
2020.09.10 18:27:18.626 5: BindingsIo: QUEUE: start handling - 1
2020.09.10 18:27:18.626 5: processMessage: {"awaitId": 93316355, "NAME": "Castdevice_Schlafzimmer", "msgtype": "command", "command": "readingsBulkUpdateIfChanged($defs{'Castdevice_Schlafzimmer'},'state','offline');;"}
2020.09.10 18:27:18.626 4: BindingsIo: <<< WS: {"result":"offline","error":0,"awaitId":93316355}
2020.09.10 18:27:18.626 5: SW: 7b22726573756c74223a226f66666c696e65222c226572726f72223a302c2261776169744964223a39333331363335357d
2020.09.10 18:27:18.627 5: BindingsIo: QUEUE: finished handling - 0
2020.09.10 18:27:18.795 3: harmony: IODev for device 49115890 is Harmony_Universal
2020.09.10 18:27:19.099 5: BindingsIo: DevIo_SimpleRead
2020.09.10 18:27:19.100 5: BindingsIo: DevIo_SimpleRead NoTimeout
2020.09.10 18:27:19.100 4: BindingsIo: >>> WS: {"awaitId": 48674361, "NAME": "Castdevice_Schlafzimmer", "msgtype": "command", "command": "readingsBulkUpdateIfChanged($defs{'Castdevice_Schlafzimmer'},'connection','disconnected');;"}
2020.09.10 18:27:19.100 4: BindingsIo: >>> WS: {"awaitId": 83852992, "NAME": "Castdevice_Schlafzimmer", "msgtype": "command", "command": "readingsSingleUpdate($defs{'Castdevice_Schlafzimmer'},'state','Function execution >1s, cancelled: Castdevice_Schlafzimmer - Define',1)"}
2020.09.10 18:27:19.100 5: BindingsIo: QUEUE: start handling - 2
2020.09.10 18:27:19.100 5: processMessage: {"awaitId": 48674361, "NAME": "Castdevice_Schlafzimmer", "msgtype": "command", "command": "readingsBulkUpdateIfChanged($defs{'Castdevice_Schlafzimmer'},'connection','disconnected');;"}
2020.09.10 18:27:19.100 4: BindingsIo: <<< WS: {"awaitId":48674361,"result":null,"error":0}
2020.09.10 18:27:19.100 5: SW: 7b2261776169744964223a34383637343336312c22726573756c74223a6e756c6c2c226572726f72223a307d
2020.09.10 18:27:19.102 5: processMessage: {"awaitId": 83852992, "NAME": "Castdevice_Schlafzimmer", "msgtype": "command", "command": "readingsSingleUpdate($defs{'Castdevice_Schlafzimmer'},'state','Function execution >1s, cancelled: Castdevice_Schlafzimmer - Define',1)"}
2020.09.10 18:27:19.103 4: BindingsIo: start PythonFunction: Castdevice_Schlafzimmer => Set (84595363)
2020.09.10 18:27:19.103 4: BindingsIo: <<< WS: {"function":"Set","defargsh":{},"argsh":{},"defargs":["Castdevice_Schlafzimmer","PythonModule","googlecast","Schlafzimmer"],"args":["Castdevice_Schlafzimmer","?"],"NAME":"Castdevice_Schlafzimmer","id":84595363,"PYTHONTYPE":"googlecast","msgtype":"function"}
2020.09.10 18:27:19.103 5: SW: 7b2266756e6374696f6e223a22536574222c226465666172677368223a7b7d2c226172677368223a7b7d2c2264656661726773223a5b22436173746465766963655f5363686c61667a696d6d6572222c22507974686f6e4d6f64756c65222c22676f6f676c6563617374222c225363686c61667a696d6d6572225d2c2261726773223a5b22436173746465766963655f5363686c61667a696d6d6572222c223f225d2c224e414d45223a22436173746465766963655f5363686c61667a696d6d6572222c226964223a38343539353336332c22505954484f4e54595045223a22676f6f676c6563617374222c226d736774797065223a2266756e6374696f6e227d
2020.09.10 18:27:19.105 5: BindingsIo: DevIo_SimpleRead
2020.09.10 18:27:19.115 5: BindingsIo: DevIo_SimpleRead WithTimeout
2020.09.10 18:27:19.115 5: BindingsIo: QUEUE: start handling - 0
2020.09.10 18:27:19.116 5: BindingsIo: QUEUE: finished handling - 0
2020.09.10 18:27:19.116 5: BindingsIo: DevIo_SimpleRead
2020.09.10 18:27:19.126 5: BindingsIo: DevIo_SimpleRead WithTimeout
2020.09.10 18:27:19.126 5: BindingsIo: QUEUE: start handling - 0
2020.09.10 18:27:19.126 5: BindingsIo: QUEUE: finished handling - 0
2020.09.10 18:27:19.127 5: BindingsIo: DevIo_SimpleRead
2020.09.10 18:27:19.137 5: BindingsIo: DevIo_SimpleRead WithTimeout
2020.09.10 18:27:19.138 5: BindingsIo: QUEUE: start handling - 0
2020.09.10 18:27:19.138 5: BindingsIo: QUEUE: finished handling - 0
2020.09.10 18:27:19.138 5: BindingsIo: DevIo_SimpleRead
2020.09.10 18:27:19.144 5: BindingsIo: DevIo_SimpleRead WithTimeout
2020.09.10 18:27:19.144 4: BindingsIo: >>> WS: {"function": "Set", "defargsh": {}, "argsh": {}, "defargs": ["Castdevice_Schlafzimmer", "PythonModule", "googlecast", "Schlafzimmer"], "args": ["Castdevice_Schlafzimmer", "?"], "NAME": "Castdevice_Schlafzimmer", "id": 84595363, "PYTHONTYPE": "googlecast", "msgtype": "function", "finished": 1, "returnval": "Unknown argument ?, choose one of stop:noArg pause:noArg rewind:noArg skip:noArg quitApp:noArg play playFavorite:1,2,3,4,5 volume:slider,0,1,100 seek next:noArg prev:noArg subtitles:on,off displayWebsite speak startApp volUp:noArg volDown:noArg"}
2020.09.10 18:27:19.144 5: BindingsIo: QUEUE: start handling - 1
2020.09.10 18:27:19.145 5: processMessage: {"function": "Set", "defargsh": {}, "argsh": {}, "defargs": ["Castdevice_Schlafzimmer", "PythonModule", "googlecast", "Schlafzimmer"], "args": ["Castdevice_Schlafzimmer", "?"], "NAME": "Castdevice_Schlafzimmer", "id": 84595363, "PYTHONTYPE": "googlecast", "msgtype": "function", "finished": 1, "returnval": "Unknown argument ?, choose one of stop:noArg pause:noArg rewind:noArg skip:noArg quitApp:noArg play playFavorite:1,2,3,4,5 volume:slider,0,1,100 seek next:noArg prev:noArg subtitles:on,off displayWebsite speak startApp volUp:noArg volDown:noArg"}
2020.09.10 18:27:19.145 5: BindingsIo: QUEUE: finished handling - 0
2020.09.10 18:27:19.145 4: BindingsIo: end PythonFunction: Castdevice_Schlafzimmer => Set (84595363) - result: Unknown argument ?, choose one of stop:noArg pause:noArg rewind:noArg skip:noArg quitApp:noArg play playFavorite:1,2,3,4,5 volume:slider,0,1,100 seek next:noArg prev:noArg subtitles:on,off displayWebsite speak startApp volUp:noArg volDown:noArg
2020.09.10 18:27:19.146 4: BindingsIo: <<< WS: {"error":0,"result":"Function execution >1s, cancelled: Castdevice_Schlafzimmer - Define","awaitId":83852992}
2020.09.10 18:27:19.146 5: SW: 7b226572726f72223a302c22726573756c74223a2246756e6374696f6e20657865637574696f6e203e31732c2063616e63656c6c65643a20436173746465766963655f5363686c61667a696d6d6572202d20446566696e65222c2261776169744964223a38333835323939327d
2020.09.10 18:27:19.148 5: BindingsIo: QUEUE: finished handling - 0

dominik · 10 September 2020, 21:17:25

Code Auswählen

2020.09.10 18:27:17.565 3: pythonbinding device opened

Wie sieht deine Reihenfolge der define Commands in der fhem.cfg aus? Kann es sein, dass das Cast Device vor dem pythonbinding geladen wird? Ich glaub da liegt der "Fehler". Wichtig waere, dass pythonbinding zuerst geladen wird, erst danach die Devices.

Poste bitte noch mehr vom Log, oder schick es mir per PN. Interessant waere in welcher Reihenfolge es geladen wird, so bei mir:

Code Auswählen

020.09.07 18:17:53.057 3: BindingsIo v1.0.0
2020.09.07 18:17:53.066 3: PythonBinding v1.0.0
2020.09.07 18:17:53.088 3: PythonModule v1.0.0 (googlecast)

Natuerlich ist das kein "Fehler" von dir, das muss ich dann noch im Code korrigieren, damit die Reihenfolge egal ist.