Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Automatic rediscover after power restore #37

Closed
gahujipo opened this issue Sep 6, 2017 · 24 comments
Closed

Automatic rediscover after power restore #37

gahujipo opened this issue Sep 6, 2017 · 24 comments
Assignees

Comments

@gahujipo
Copy link
Collaborator

gahujipo commented Sep 6, 2017

I use only one speaker (1 zone) which I control via node-raumserver. Overnight I disconnect the power so the speaker isn’t available during that period. I realized that without a restart of the server, node-raumserver isn’t able to send it’s commands to the speaker once the power gets restored the morning after. I think that node-raumserver has to do a rediscover to get all new used ports and description XMLs.

  • Which is the recommended way to trigger a rediscover within node-raumserver?
  • Is there a command (e.g. /raumserver/rediscover) that can be called to trigger a rediscover?
  • Is there a parameter that can be lowered to reduce the interval between possible automatic rediscovers?
@ChriD
Copy link
Owner

ChriD commented Sep 6, 2017

Hmm.. in fact it should be no problem for the node-raumsever to automatically find the host again if it comes online. I will check this

@gahujipo
Copy link
Collaborator Author

gahujipo commented Sep 6, 2017

Okay. Anyways is there already implemented a function in raumserver that could be called to trigger a rediscover?

@ChriD
Copy link
Owner

ChriD commented Sep 10, 2017

Maybee you may look into the log file and tell me if there is an error like that?

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory

Thanks!

@ChriD
Copy link
Owner

ChriD commented Sep 10, 2017

And please may you provide the log here?

@ChriD
Copy link
Owner

ChriD commented Sep 10, 2017

For a workaround you may add a fixed IP in the settings for the host!

@ChriD
Copy link
Owner

ChriD commented Sep 10, 2017

@gahujipo Can you update the node.raumserver to the newest version and check if the problem is gone!

@gahujipo
Copy link
Collaborator Author

after restoring power the following log entries appear.

debug: [MediaRenderer|debug: [MediaRenderer|Raum] Call Next from Raum
error: [MediaRenderer|Raum] Next on Raum failed with params: {} Error: connect ECONNREFUSED 192.168.0.113:56707
    at Object._errnoException (util.js:1041:11)
    at _exceptionWithHostPort (util.js:1064:20)
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1153:14)
error: [Request.next] Exception thrown:  Error: connect ECONNREFUSED 192.168.0.113:56707
    at Object._errnoException (util.js:1041:11)
    at _exceptionWithHostPort (util.js:1064:20)
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1153:14)
error: [Request.next] Some renderers had exceptions:  Error: connect ECONNREFUSED 192.168.0.113:56707
    at Object._errnoException (util.js:1041:11)
    at _exceptionWithHostPort (util.js:1064:20)
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1153:14)
error: [Raumserver] Request was rejected:  errorMessage=Error: connect ECONNREFUSED 192.168.0.113:56707, errorData=null] Call Next from Raum
error: [MediaRenderer|Raum] Next on Raum failed with params: {} Error: connect ECONNREFUSED 192.168.0.113:56707
    at Object._errnoException (util.js:1041:11)
    at _exceptionWithHostPort (util.js:1064:20)
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1153:14)
error: [Request.next] Exception thrown:  Error: connect ECONNREFUSED 192.168.0.113:56707
    at Object._errnoException (util.js:1041:11)
    at _exceptionWithHostPort (util.js:1064:20)
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1153:14)
error: [Request.next] Some renderers had exceptions:  Error: connect ECONNREFUSED 192.168.0.113:56707
    at Object._errnoException (util.js:1041:11)
    at _exceptionWithHostPort (util.js:1064:20)
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1153:14)
error: [Raumserver] Request was rejected:  errorMessage=Error: connect ECONNREFUSED 192.168.0.113:56707, errorData=null

Of course the connection is refused because after reboot the speaker uses different ports.

The fixed IP was already set to the config. I do not use autodiscover.

After updating node-raumserver to 0.10.0 by issuing

npm update

the problem still exists and the following logs appear regularly

error: [MediaRenderer|Raum] GetVolume on Raum failed with params: {"Channel":"Master"} Error: connect ECONNREFUSED 192.168.0.113:58825
    at Object._errnoException (util.js:1041:11)
    at _exceptionWithHostPort (util.js:1064:20)
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1153:14)
error: [Request.volumeUp] Exception thrown:  Error: connect ECONNREFUSED 192.168.0.113:58825
    at Object._errnoException (util.js:1041:11)
    at _exceptionWithHostPort (util.js:1064:20)
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1153:14)
error: [Request.volumeUp] Some renderers had exceptions:  Error: connect ECONNREFUSED 192.168.0.113:58825
    at Object._errnoException (util.js:1041:11)
    at _exceptionWithHostPort (util.js:1064:20)
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1153:14)

@gahujipo
Copy link
Collaborator Author

An addition to my previous comment: the entries come up every time a call to raumserver gets done. They come up regularly only because I have a system running that queries some information regularly.

@gahujipo
Copy link
Collaborator Author

I'm writing the following paragraph in german to be as clear as possible.

Seit dem letzten Update von node-raumkernel/node-raumserver (ich bilde mir ein, das seitdem zu beobachten) habe ich folgendes Problem:

  • Manchmal verschwindet mein Raumfeld-Speaker aus der "Devices Available"-Liste in Spotify
  • Das Starten eines Songs dauert bis zu 10 Sekunden.
  • Das Weiterschalten auf den nächsten Song dauert ebenfalls bis zu 10 Sekunden.

Ich habe den Raumserver seit 2 Tagen mal deaktiviert und kann das Problem nun nicht mehr feststellen. Dazu zu sagen ist, dass ich, wenn er aktiviert ist alle 10 Sekunden /raumserver/controller/getRendererState?id=Raum aufrufe um verschiedene Parameter weiterzuverarbeiten. Nutzt du Spotify? Ist dir ein solches Verhalten auch aufgefallen? Gibt es einen Teil im Code, der hier u.U. zu einer höheren Auslastung (von bspw. Speicher oder Prozessor) auf dem Speaker führt? Das Phänomen stelle ich auf meinen Stereo L fest.

Danke schon mal im Voraus.

@rwitkamp
Copy link

I have similar problems as gahujipo writes since the last update of node-raumserver. I did not do researh yet but the symptoms are also in my Raumfeld at home.

Seit dem letzten Update von node-raumkernel/node-raumserver (ich bilde mir ein, das seitdem zu beobachten) habe ich folgendes Problem:
Manchmal verschwindet mein Raumfeld-Speaker aus der "Devices Available"-Liste in Spotify
Das Starten eines Songs dauert bis zu 10 Sekunden.
Das Weiterschalten auf den nächsten Song dauert ebenfalls bis zu 10 Sekunden.

@gahujipo
Copy link
Collaborator Author

To give you more useful information than just writing what does not work I'd like to send you the relevant part of the log. How can I let raumserver log to a file? My raumserver runs in the background so that I usually don't have access to the stdout.

@ChriD
Copy link
Owner

ChriD commented Sep 22, 2017

it should write a log file anyway in the "logs" folder
If there is no "logs" folder then create one

@gahujipo
Copy link
Collaborator Author

gahujipo commented Oct 19, 2017

Manchmal verschwindet mein Raumfeld-Speaker aus der "Devices Available"-Liste in Spotify

This happens when I standby the speaker with EnterManaualStandby. When I do EnterAutomaticStandby, the speaker stays visible. So for me this is not an issue anymore, but I think this behaviour should be documented somewhere. I will add that note in my wiki proposal (#38)

  • Das Starten eines Songs dauert bis zu 10 Sekunden.
  • Das Weiterschalten auf den nächsten Song dauert ebenfalls bis zu 10 Sekunden.

I tested this a few weeks now, but with the v0.0.9 and I can see only a delay for one second or so. So I think this issue was introduced with v0.0.10.

Das Phänomen stelle ich auf meinen Stereo L fest.

I added an additional speaker (One S) which shows the same behaviour with v0.0.10. So this issue is neither limited to a single speaker installation nor to the hardware (of Speaker L).

The logs that appear after power has beeen restored, for the connections that fail I already posted above.

@gahujipo
Copy link
Collaborator Author

but I think this behaviour should be documented somewhere. I will add that note in my wiki proposal (#38)

added that: gahujipo/node-raumserver-wiki@47998b8

I retested the behaviour after power restore. Unfortunately it still does not recognise the device anymore without a restart of node-raumserver. Could you maybe fix that too?

@ChriD
Copy link
Owner

ChriD commented Dec 22, 2017

@gahujipo
den node-raumserver auf den rf devices zu installieren ist zwar möglich, aber nicht recommended.
Das ging bei der C++ version beser da C++ code performanter läuft als ein nodeJs auf einem RF-Device
Da sind die RF devices gleich mal überfordert.

Das Problem mit den Reconnect kann ich jetzt aber nachvollziehen wenn das System über den Bonjour den host sucht anstatt mit SSDP. Ich sehe mir das an

@gahujipo
Copy link
Collaborator Author

gahujipo commented Jan 3, 2018

den node-raumserver auf den rf devices zu installieren ist zwar möglich, aber nicht recommended.
Das ging bei der C++ version beser da C++ code performanter läuft als ein nodeJs auf einem RF-Device
Da sind die RF devices gleich mal überfordert.

Okay, worauf beziehst du dich diesbezüglich? Hatte den alten Raumserver nie auf einem RF-Device installiert. Alle meine Issues habe ich von einer Installation auf einem Debian. Die Raumfelds sind bei mir komplett untouched, weil ich mögliche dadurch entstehende delays bei der Annahme von Befehlen (next, prev, pause, play) partout nicht leiden kann :)

Das Problem mit den Reconnect kann ich jetzt aber nachvollziehen wenn das System über den Bonjour den host sucht anstatt mit SSDP. Ich sehe mir das an

Sehr, sehr gerne! Das würde mir bei meinem Wecker sehr helfen. Im Moment helfe ich mir mit einem getriggerten Neustart der Maschine auf dem der raumserver läuft und nachfolgende um einige Minuten verzögerte Befehle für die richtige Lautstärke der Speaker. Das läuft mittelmäßig gut, weil die Neustarts nicht immer gleich lange dauern und oftmals Befehle verloren gehen. :-(

@ChriD
Copy link
Owner

ChriD commented Jan 4, 2018

Seit dem letzten Update von node-raumkernel/node-raumserver (ich bilde mir ein, das seitdem zu beobachten) habe ich folgendes Problem:

Manchmal verschwindet mein Raumfeld-Speaker aus der "Devices Available"-Liste in Spotify
Das Starten eines Songs dauert bis zu 10 Sekunden.
Das Weiterschalten auf den nächsten Song dauert ebenfalls bis zu 10 Sekunden.
Ich habe den Raumserver seit 2 Tagen mal deaktiviert und kann das Problem nun nicht mehr feststellen.

Gibt es einen Teil im Code, der hier u.U. zu einer höheren Auslastung (von bspw. Speicher oder Prozessor) auf dem Speaker führt? Das Phänomen stelle ich auf meinen Stereo L fest.

Durch die paar Zeilen habe ich gedacht du hast den node-raumserver auf einem device installiert.
Denn dass das Starten/Weiterschalten eines Song 10 sekunden dauert, und das mit dem node-raumserver zusammenhängt würde mich stark wundern. Auch das Verschwinden des Raumfeld-Speakers.
Da es aber auch rwitkamp hat bin ich etwas verwirrt. Entweder ihr habt beide ein RF-update aufgespielt oder es hat wirklich was mit dem node-raumserver zu tun, was ich mir aber nicht erklären könnte.

BTW: getRendereState beherrscht auch longPolling. Du musst nicht alle 10 Sekunden pollen.

@gahujipo
Copy link
Collaborator Author

gahujipo commented Jan 4, 2018

  • Denn dass das Starten/Weiterschalten eines Song 10 sekunden dauert, und das mit dem node-raumserver zusammenhängt würde mich stark wundern.
  • Das Starten eines Songs dauert bis zu 10 Sekunden.
  • Gibt es einen Teil im Code, der hier u.U. zu einer höheren Auslastung (von bspw. Speicher oder Prozessor) auf dem Speaker führt? Das Phänomen stelle ich auf meinen Stereo L fest.

Diese 3 Punkte wurden mit #42 bereits gelöst und sind somit nicht mehr aktuell. v0.0.10 mit der neuen raumkernel version ist davon nicht mehr betroffen.

Manchmal verschwindet mein Raumfeld-Speaker aus der "Devices Available"-Liste in Spotify

Dies ist wohl nicht auf ein Problem vom raumserver zurückzuführen, sondern ist wohl eine Eigenheit vom Raumfeld-System selbst. Siehe auch hier in meinem Vorschlag für die Wiki: https://github.com/gahujipo/node-raumserver-wiki/blob/master/Use/Standby.md#enter-standby
#37 (comment)

BTW: getRendereState beherrscht auch longPolling. Du musst nicht alle 10 Sekunden pollen.

Leider verwende ich als "client" für den Raumserver ein System bei dem ich ohne zusätzlichen "Proxy" keine Möglichkeit sehe ein long polling zu implementieren.

Nochmal zum rediscover:

Eventuell wäre als kurzfristigen Workaround auch schon geholfen, wenn man einen Befehl an den Raumserver schicken könnte, welchen ihn neu startet.

@ChriD
Copy link
Owner

ChriD commented Jan 10, 2018

Eventuell wäre als kurzfristigen Workaround auch schon geholfen, wenn man einen Befehl an den Raumserver schicken könnte, welchen ihn neu startet.

Ich muss hier etwas aufpassen. Nicht das hier wieder einen Bug mit den offenen Ports generiere!
Ich benutze für die SSDP und Bonjour discovery 3rd party libs und die scheinen etwas anfällig zu sein.
Sorry das alles etwas dauert. Ich bin beruflich gut ausgelastet und auch privat mitten in einer Baustelle, aber ich vergess das nicht ;-)

@gahujipo
Copy link
Collaborator Author

Das mit den offenen Ports durch die externen Libraries leuchtet mir ein.
Nimm dir die Zeit dafür. Den wichtigen Dingen muss die höchste Priorität eingeräumt werden 👍

@ChriD
Copy link
Owner

ChriD commented Jan 13, 2018

problem should be solbed with 0.1.1 and newest kernel

@ChriD ChriD closed this as completed Jan 13, 2018
@gahujipo
Copy link
Collaborator Author

I tested this now for a while. It seems to me, that it isn't fully solved yet. I read that you are busy at the moment. Could you explain the following parameters in the default.json-config-file in the meantime?

"alivePingerIntervall"      : 2500,
"ssdpDiscovertimeout"       : 5000,
"bonjourDiscoverTimeout"    : 3000,
"rendererStateTriggerConfirmationTimout": 3500,
"zoneTriggerConfirmationTimout": 6000

Maybe I can find out something on my own in the meantime. Are those values always ms?

@ChriD
Copy link
Owner

ChriD commented Mar 26, 2018

All values are in [ms]

alivePingerIntervall
intervall used to check if host is alive with a "ping" on the last know ip

bonjourDiscoverTimeout
If the system is searching for the host it first uses the bonjour discovery. If host is not found within this amount of time there is a fallback to ssdp-discovery

ssdpDiscoverTimeout
if the host is not found via bonjour the kernel tries to find it via ssdp for this amount of time
if it does not find the host it starts again with the the bonjour search. This will be done until a host ist found

rendererStateTriggerConfirmationTimout and zoneTriggerConfirmationTimout are internal values which do not have any relation to finding/rediscovering the host

@kaloschke
Copy link

Hi,
same problem as gahujipo for me. Until now: after update to 0.1.5 my speaker reconnects after current interruption.

Thank you very much

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants