Closed th4git closed 2 years ago
Hi @th4git
thanks for creation this issue. I'm aware of this adapter issue and currently it's still pretty foggy around the solution. ;)
All I can say for now is that there are two eventlisteners in place. One for device state messages and one for errors:
_sse.addEventListener( 'devices', function(event) { adapter.log.debug('Received devices message by SSE: ' + JSON.stringify(event)); splitMieleDevices(JSON.parse(event.data), false); });
_sse.addEventListener( 'error', function(event) { adapter.log.warn('Received error message by SSE: ' + JSON.stringify(event)); if (event.readyState === EventSource.CLOSED) { adapter.log.info('The connection has been closed. Trying to reconnect.'); adapter.setState('info.connection', false, true); _sse = mieleAPITools.APIregisterForEvents(adapter, _auth); }
since you are logging in silly mode: please grab your log for the string "SSE:" . This will bring up all event related log entries. After that you will be able to determine exactly when the server stopped sending device updates and whether there has been an error around that. Maybe this will help to locate the issue, since it appeared a while in the past in my envirentment as well, but vanished sometimes without further notice. Therefor I can't reproduce it on my own. The adapter works stable for my three devices.
Servus @Grizzelbee (ich schreibe mal weiter in Englisch, falls auch entferntere Nutzer dieses Adapters hierzu auf die Suche gehen).
The last log entry containing substring "message by SSE" is
2022-01-23 22:44:23.650 - debug: mielecloudservice.0 (1421) Received devices message by SSE: {"type":"devices","data":"{\"000123456789\":{\"ident\":{\"type\":{\"key_localized\":\"Gerätetyp\",\"value_raw\":7,\"value_localized\":\"Geschirrspüler\"},\"deviceName\":\"\",\"protocolVersion\":4,\"deviceIdentLabel\":{\"fabNumber\":\"000123456789\",\"fabIndex\":\"65\",\"techType\":\"G7915\",\"matNumber\":\"11071180\",\"swids\":[\"5419\",\"20469\",\"20468\",\"25259\",\"20470\",\"35536\",\"25294\",\"4684\",\"20454\",\"25168\",\"4928\",\"20475\",\"25266\",\"4874\",\"20366\",\"20462\"]},\"xkmIdentLabel\":{\"techType\":\"EK037\",\"releaseVersion\":\"03.88\"}},\"state\":{\"ProgramID\":{\"value_raw\":44,\"value_localized\":\"Biergläser warm\",\"key_localized\":\"Programmbezeichnung\"},\"status\":{\"value_raw\":1,\"value_localized\":\"Aus\",\"key_localized\":\"Status\"},\"programType\":{\"value_raw\":0,\"value_localized\":\"Programm\",\"key_localized\":\"Programmart\"},\"programPhase\":{\"value_raw\":0,\"value_localized\":\"\",\"key_localized\":\"Programmphase\"},\"remainingTime\":[2,33],\"startTime\":[0,0],\"targetTemperature\":[{\"value_raw\":-32768,\"value_localized\":null,\"unit\":\"Celsius\"},{\"value_raw\":-32768,\"value_localized\":null,\"unit\":\"Celsius\"},{\"value_raw\":-32768,\"value_localized\":null,\"unit\":\"Celsius\"}],\"temperature\":[{\"value_raw\":-32768,\"value_localized\":null,\"unit\":\"Celsius\"},{\"value_raw\":-32768,\"value_localized\":null,\"unit\":\"Celsius\"},{\"value_raw\":-32768,\"value_localized\":null,\"unit\":\"Celsius\"}],\"signalInfo\":false,\"signalFailure\":false,\"signalDoor\":false,\"remoteEnable\":{\"fullRemoteControl\":true,\"smartGrid\":false,\"mobileStart\":true},\"ambientLight\":null,\"light\":2,\"elapsedTime\":[0,0],\"spinningSpeed\":{\"unit\":\"U/min\",\"value_raw\":null,\"value_localized\":null,\"key_localized\":\"Schleuderdrehzahl\"},\"dryingStep\":{\"value_raw\":null,\"value_localized\":\"\",\"key_localized\":\"Trockenstufe\"},\"ventilationStep\":{\"value_raw\":null,\"value_localized\":\"\",\"key_localized\":\"Lüfterstufe\"},\"plateStep\":[],\"ecoFeedback\":null,\"batteryLevel\":null}}}","lastEventId":"","origin":"https://api.mcs3.miele.com"}
which was a few milliseconds before final log lines mentioned in the issue above,
After the above log entry, the first entry containing substring "message by SSE" again was on the following day after I upgraded the adapter from v5.0.2 to v5.0.4 (which causes adapter restart):
2022-01-24 23:08:59.820 - debug: mielecloudservice.0 (29282) Received devices message by SSE: {"type":"devices","data":"{\"000123456789\":{\"ident\":{\"type\":{\"key_localized\":\"Gerätetyp\",\"value_raw\":7,\"value_localized\":\"Geschirrspüler\"},\"deviceName\":\"\",\"protocolVersion\":4,\"deviceIdentLabel\":{\"fabNumber\":\"000123456789\",\"fabIndex\":\"65\",\"techType\":\"G7915\",\"matNumber\":\"11071180\",\"swids\":[\"5419\",\"20469\",\"20468\",\"25259\",\"20470\",\"35536\",\"25294\",\"4684\",\"20454\",\"25168\",\"4928\",\"20475\",\"25266\",\"4874\",\"20366\",\"20462\"]},\"xkmIdentLabel\":{\"techType\":\"EK037\",\"releaseVersion\":\"03.88\"}},\"state\":{\"ProgramID\":{\"value_raw\":0,\"value_localized\":\"\",\"key_localized\":\"Programmbezeichnung\"},\"status\":{\"value_raw\":1,\"value_localized\":\"Aus\",\"key_localized\":\"Status\"},\"programType\":{\"value_raw\":0,\"value_localized\":\"Programm\",\"key_localized\":\"Programmart\"},\"programPhase\":{\"value_raw\":0,\"value_localized\":\"\",\"key_localized\":\"Programmphase\"},\"remainingTime\":[0,1],\"startTime\":[0,0],\"targetTemperature\":[{\"value_raw\":-32768,\"value_localized\":null,\"unit\":\"Celsius\"},{\"value_raw\":-32768,\"value_localized\":null,\"unit\":\"Celsius\"},{\"value_raw\":-32768,\"value_localized\":null,\"unit\":\"Celsius\"}],\"temperature\":[{\"value_raw\":-32768,\"value_localized\":null,\"unit\":\"Celsius\"},{\"value_raw\":-32768,\"value_localized\":null,\"unit\":\"Celsius\"},{\"value_raw\":-32768,\"value_localized\":null,\"unit\":\"Celsius\"}],\"signalInfo\":false,\"signalFailure\":false,\"signalDoor\":false,\"remoteEnable\":{\"fullRemoteControl\":true,\"smartGrid\":false,\"mobileStart\":true},\"ambientLight\":null,\"light\":2,\"elapsedTime\":[0,0],\"spinningSpeed\":{\"unit\":\"U/min\",\"value_raw\":null,\"value_localized\":null,\"key_localized\":\"Schleuderdrehzahl\"},\"dryingStep\":{\"value_raw\":null,\"value_localized\":\"\",\"key_localized\":\"Trockenstufe\"},\"ventilationStep\":{\"value_raw\":null,\"value_localized\":\"\",\"key_localized\":\"Lüfterstufe\"},\"plateStep\":[],\"ecoFeedback\":null,\"batteryLevel\":null}}}","lastEventId":"","origin":"https://api.mcs3.miele.com"}
No "message by SSE" was sent before this adapter update even when I created an manual event at iobroker (which was sent to the miele device and confirmed by it - see logfiles at the issue above).
BTW: I highly appreciate your work on this adapter!
Hallo, bin ebenfalls von den Problem betroffen. Gibt es schon eine Lösung?
Sobald man die Instanz neustartet, funktioniert alles wieder.
Gruß Dominik
@Domi920 Unfortunately there still no solution. We are still searching for the reason. Which is not easy - since I'm not facing this issue myself.
Are there already ways to a possible solution?
Thanks for the answer
@Domi920
There can't be any way to a solution since (as I already said) I still have no clue what causes this issue and what this issue is about. Without a known root cause I can't think about solutions.
Fact is:
Intresting might be: Does this happen on random times or is there a pattern?
Any fingerpointing to a possible root cause is welcome!
A discussion in ioBroker-Forum is also welcome: https://forum.iobroker.net/topic/29836/mielecloudservice-adapter/466?_=1643699673658#
I am also seeing this - I could easily reproduce by:
Do you have any IP adress the adapter is talking to? I would like to capture a Wireshark trace of the TCP - maybe we see any timeout or something on TCP level. Hopefully we dont need to dig into the payload thus do not need to break https.
BR
...Duration (10+20min) do not seem to be deterministic - 2nd run with a try of tcpdump is now woring for more than 40min.
@hmersch Thanks for digging deeper into this.
Do you have any IP adress the adapter is talking to?
I'm connecting to the Miele server @ https://api.mcs3.miele.com/
Hey
So far: I am capturing to 20.86.20.70 which is my connection to miele.com. Additonally any Update to STATUS is sent to me via Telegram.
I observed an outtake this morning: I got an "nicht verbunden" as change on STATUS this morning on 7:30. --> Does that indicate anything? BUT that doesnt seem to be our main Problem, because 1) The functionality came back without Adapter-Restart 32min later (I got another update to "aus" on my telegram). 2) I dont see any 30min "silence" in my capture.
So for now the Adapter seem to work approx 24h ... I am waiting for the issue to happen + persist...
BTW: I do see quite some reconnections on TCP in my capture - those seem to work...
BR -
Still working without any restart and without further "nicht verbunden" notifications. Anyone else has seen the issue within last 2 days during my capture?
@hmersch Thank you for your effort. I really value it. The 'Nicht verbunden' Thing looks intresting to me. Maybe I can observe it and perform an automatic reconnect if it occurs. Do you have some more details on it? Not really sure what "Status" your talking about.
@Grizzelbee :-) Since after the "nicht verbunden" the issue doesnt came up (it worked without adapter restart) I dont thing that is really our real issue. Additionally: Sadly I dont have correct timerelations on that log file thus we cant look into the deails The "status" I am monitoring (and send me Telegram messages) is on the device (my oven): "mielecloudservice.0.000175000877.Status"
Currently: Still working after 3 days without any issue ... and no more "nicht verbunden" came up. Still waiting for the issue to come back.
@all: Feeling right now is that the issue is server-side - or does anyone have seen this issue within the last 3 days?
Hi there, I think it's great that something is happening in the problem-solving process. Have been following these posts for a while. I'm talking about a dishwasher. Have also restarted the adapter since 11.03 at 12:30 and activated history. I received the last traffic jam report at 7:30 p.m. on the same day. The status should have been updated in the morning the next day at the latest. But that didn't happen. However, the status only contains "Off, settings, ready, program selected, ..." but nothing about the connection status.
What new insights are there now?
Greetings Dominik
Hi all, mainly driven by this issue I started rewriting the adapter from scratch. I already reworked the eventing-stuff and it seems to work pretty well and stable. At least much better than the current code. ;o) And it turned out that Miele sends a keep alive ping every five seconds - so I implemented a watchdog upon this. Currently I'm working on creating the device tree and trying to stay compatible with the current version. But not sure if that works out.
That's great news :-)))) When can I test?
When can I test?
Depends on my spare time. ;o) But I'm pretty sure that it will take a couple of weeks.
I understand. Does it still make sense to invest in the old "adapter" for VIS & scripts? Or will the adapter be completely different?
Or will the adapter be completely different?
I don't think so. The structure is given by miele. So it might be slightly different but not completely.
Yet another itermediate notice: Still working without any issue and restart - almost a week now.
@Grizzelbee ok well that's good to hear. Thank you for your work & effort!
@hmersch in my case the connection doesn't even last a day :-( Enabled a restart every 6 hours to solve the problem for now.
Okay - now the issue arrived again. Wiresharktrace simply stopped capture anything - without any issue on TCP level. Lets hope that the mentioned keepalve will change that with the rework of the adapter
Thank you very much! To be honest: I already expected this result. The logging of the adapter pointed to the same direction. So I really hope that the rewrite of the adapter is going to solve this issue. Let's wait for a test in the wild... But it's still a way to go in coding ...
From my perspective this should be (is) fixed in upcomming v6.0.0. Please reopen this issue if not.
Quick feedback using v6.1.0: Connections lost after a few days while
Update: Yes, there is activity in the log when losing connection. But adapter fails to reconnect.
@th4git
Quick feedback using v6.1.0: Connections lost after a few days while
Can confirm that. My instance crashed yesterday as well. But this time it's not completely silient. But I agree that the traffic light updates need some optimization. ;-) On my side there are many warnings in the log file stating that the connection is broken. I'm currently trying an error handling extension in my environment. I'm optimistic to release a fix in a few days.
Hi ! Ich habe leider auch das Problem. Ich würde gerne erstmal wieder zurück zu 5.0.4, die bei mir gut lief. Leider kann ich im iobroker bei der Installation nur V>6 auswählen. Wie bekomme ich die 5.0.4 wieder installiert ? Besten Dank und Gruß, Sebastian
@pacco81
Der broker bietet immer nur die letzten paar Versionen an.
Du solltest auf der Kommandozeile aber zum Ziel kommen:
im Verzeichnis der basisinstallation des Brokers gibt du ein: npm install iobroker.mielecloudservice@5.0.4
Auf diese Weise kannst Du jede beliebige Version installieren.
@Alle Ich arbeite gerade an einer neuen Version. Die sollte in wenigen Tagen erscheinen.
Kurzes Ergänzungsfeedback: Auch mit Adapter v6.1.5. füllt sich das Logfile mit Meldungen während die Verbindung unterbrochen bleibt. Nur ein Adapter-Neustart löst dann den Knoten.
2022-05-11 22:03:48.350 - info: mielecloudservice.0 (29164) Watchdog detected ping failure. Last ping occurred over a minute ago. Trying to reconnect.
2022-05-11 22:08:48.350 - info: mielecloudservice.0 (29164) Watchdog detected ping failure. Last ping occurred over a minute ago. Trying to reconnect.
2022-05-11 22:13:48.352 - info: mielecloudservice.0 (29164) Watchdog detected ping failure. Last ping occurred over a minute ago. Trying to reconnect.
2022-05-11 22:18:48.352 - info: mielecloudservice.0 (29164) Watchdog detected ping failure. Last ping occurred over a minute ago. Trying to reconnect.
2022-05-11 22:23:48.352 - info: mielecloudservice.0 (29164) Watchdog detected ping failure. Last ping occurred over a minute ago. Trying to reconnect.
2022-05-11 22:28:48.353 - info: mielecloudservice.0 (29164) Watchdog detected ping failure. Last ping occurred over a minute ago. Trying to reconnect.
2022-05-11 22:33:48.354 - info: mielecloudservice.0 (29164) Watchdog detected ping failure. Last ping occurred over a minute ago. Trying to reconnect.
2022-05-11 22:38:48.353 - info: mielecloudservice.0 (29164) Watchdog detected ping failure. Last ping occurred over a minute ago. Trying to reconnect.
2022-05-11 22:43:48.354 - info: mielecloudservice.0 (29164) Watchdog detected ping failure. Last ping occurred over a minute ago. Trying to reconnect.
2022-05-11 22:48:48.354 - info: mielecloudservice.0 (29164) Watchdog detected ping failure. Last ping occurred over a minute ago. Trying to reconnect.
2022-05-11 22:53:48.355 - info: mielecloudservice.0 (29164) Watchdog detected ping failure. Last ping occurred over a minute ago. Trying to reconnect.
@th4git Ja - ich weiß. :-(
Das SSE Thema is echt vertrackt. Allerdings liegt es nur zum Teil an mir. Das Problem ist, dass die Miele-API einfach irgendwann einen Fehler meldet und dann die SSE-Verbindung kaputt geht - und sich nicht so einfach neu aufbauen lässt. Ich habe aber gerade einen neuen Versuch bei mir in den Test genommen - mal sehen wie es in ein paar Stunden so aussieht. Um dem Adapter aber mittelfristig erst einmal wieder stabilität zu verleihen habe ich das Polling wieder als Config-Option eingebaut. Die kommende Version kann also als Fallback beides: SSE und Polling. Nichts desto trotz wird weiterhin SSE bevorzugt.
from my point of view this is fixed.
Describe the bug
Adapter runs fine (in my case using diswasher "Miele G 7915 Sci XXL AutoDos") for some days. But suddenly it stops receiving events from Miele API while the Miele device is operated.
The status state
mielecloudservice.0.000123456789.Connected
staystrue
all the time with timestamp of latest activity recorded at the logfile (see below).But even while the adapter does not receive device updates anymore, it immediately sends out new activties initated at iobroker, e.g. when manually setting the state
mielecloudservice.0.000123456789.ACTIONS.Power
totrue
- see these log entries below. But after doing this, the adapter still does not receive any device activites from Miele API.So the adapter is not completly dead: It still sends out events created at iobroker but stops receiving events from Miele API caused by Miele device. ("one-way-mode-only")
Restarting the adapter revives it - until it stops working after some days of working, again.
Forum: see https://forum.iobroker.net/post/729512
To Reproduce
Run the adapter. Wait some days while using the Miele device. No specific activity known to reproduce the problem.
Expected behavior
Adapter keeps on runnning and does not stop receiving device activities. :-)
Screenshots & Logfiles
Last activities of the Miele device recorded at the logfile before adapter stops receiving events:
After above log entries there were no more activites logged when the Miele device is operated.
Manually creating activity at iobroker, e.g. by setting state
mielecloudservice.0.000123456789.ACTIONS.Power
totrue
after adapter seems to be frozen, the following fresh log entries are created:Versions
Workaround Configure to restart the Adapter every night: