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

TypeError: Cannot read property 'send' of null #36

Closed
linchen4000 opened this issue Jun 16, 2018 · 11 comments
Closed

TypeError: Cannot read property 'send' of null #36

linchen4000 opened this issue Jun 16, 2018 · 11 comments

Comments

@linchen4000
Copy link

After a frew requests for chromecast text to speech triggers over the sayit plugin, there is an error with the chromecast instance. When I restart the instance, the problem is gone. But it's very annoying that the error is always, when I have more than a few requests in a short time and the chromecast did not play any playlists anymore...

chromecast.0 2018-06-16 21:11:20.428 error Badezimmer - Could not play announcement: TypeError: Cannot read property 'send' of null
chromecast.0 2018-06-16 21:11:20.428 error at process._tickCallback (internal/process/next_tick.js:109:7)
chromecast.0 2018-06-16 21:11:20.428 error at /opt/iobroker/node_modules/iobroker.chromecast/node_modules/castv2-player/lib/playlist.js:75:23
chromecast.0 2018-06-16 21:11:20.428 error at PersistentPlayer.queueLoadPromise (/opt/iobroker/node_modules/iobroker.chromecast/node_modules/castv2-player/lib/persistentPlayer.js:477:14)
chromecast.0 2018-06-16 21:11:20.428 error at /opt/iobroker/node_modules/iobroker.chromecast/node_modules/castv2-player/lib/persistentPlayer.js:486:24
chromecast.0 2018-06-16 21:11:20.428 error at DefaultMediaReceiver.queueLoad (/opt/iobroker/node_modules/iobroker.chromecast/node_modules/castv2-client/lib/senders/default-media-receiver.js:50:24)
chromecast.0 2018-06-16 21:11:20.428 error at MediaController.queueLoad (/opt/iobroker/node_modules/iobroker.chromecast/node_modules/castv2-client/lib/controllers/media.js:146:8)
chromecast.0 2018-06-16 21:11:20.428 error at MediaController.RequestResponseController.request (/opt/iobroker/node_modules/iobroker.chromecast/node_modules/castv2-client/lib/controllers/request-response.js:34:8)
chromecast.0 2018-06-16 21:11:20.428 error at MediaController.Controller.send (/opt/iobroker/node_modules/iobroker.chromecast/node_modules/castv2-client/lib/controllers/controller.js:28:16)
chromecast.0 2018-06-16 21:11:20.428 error at Channel.send (/opt/iobroker/node_modules/iobroker.chromecast/node_modules/castv2/lib/channel.js:34:12)
chromecast.0 2018-06-16 21:11:20.428 error at Client.send (/opt/iobroker/node_modules/iobroker.chromecast/node_modules/castv2/lib/client.js:128:10)
chromecast.0 2018-06-16 21:11:20.428 error Badezimmer - Error playing playlist - TypeError: Cannot read property 'send' of null
@angelnu
Copy link
Collaborator

angelnu commented Jun 17, 2018

@linchen4000 Is the log from you trying to play something after hitting the problem? If so what is the status of the adapter (content of chromecast.0..status ?

The adapter should restart automatically after hitting an exception - if this is not the case I would need to fix that.

@linchen4000
Copy link
Author

Yes the log was after I tried to play something and it didn't work. I reinstalled the hole adapter after having this problem more often. But after that so far the error has not yet occured again.
When it occur again, I will read out the status.

@linchen4000
Copy link
Author

Okay, now it occurred again:

chromecast.0 2018-06-21 18:27:30.412 error Badezimmer - Could not play announcement: TypeError: Cannot read property 'launch' of null

And the adapter is still alive and did not restart.

system.adapter.chromecast.0.outputCount ioBroker outputs level ioBroker outputs level 8 true chromecast.0 2018-06-21 18:30:32.317 2018-06-21 16:28:46.719
system.adapter.chromecast.0.inputCount ioBroker - inputs level ioBroker - inputs level 0 true chromecast.0 2018-06-21 18:30:32.317 2018-06-21 18:27:47.304
system.adapter.chromecast.0.uptime chromecast.0 chromecast.0.uptime 373311 true chromecast.0 2018-06-21 18:30:32.317 2018-06-21 18:30:32.317
system.adapter.chromecast.0.memRss chromecast.0 chromecast.0.memRss 38.38 true chromecast.0 2018-06-21 18:30:32.315 2018-06-21 18:30:17.319
system.adapter.chromecast.0.memHeapTotal chromecast.0 chromecast.0.memHeapTotal 23.03 true chromecast.0 2018-06-21 18:30:32.316 2018-06-21 14:52:01.136
system.adapter.chromecast.0.memHeapUsed chromecast.0 chromecast.0.memHeapUsed 19.15 true chromecast.0 2018-06-21 18:30:32.316 2018-06-21 18:30:32.316
system.adapter.chromecast.0.connected chromecast.0 chromecast.0.connected true true chromecast.0 2018-06-21 18:30:32.312 2018-06-17 10:48:42.085
system.adapter.chromecast.0.alive chromecast.0 chromecast.0.alive true true chromecast.0 2018-06-21 18:30:32.308 2018-06-17 10:48:42.082

@Xyolyp
Copy link
Contributor

Xyolyp commented Mar 21, 2019

I'm experiencing something very similar

@linchen4000
Copy link
Author

I think I resolved it by restarting the adapter daily in the night with a CRON job.

@Xyolyp
Copy link
Contributor

Xyolyp commented Mar 25, 2019

Sadly the issue appears multiple times per day sometimes even per hour. So I don't think I can work around it using a cron job.
I can't correlate it to connection issues either. I tried using the ping adapter to check if the issue appears whenever there is a connection error but there is no correlation.
I would love to see some improvements in the adapter regarding reconnecting

@angelnu
Copy link
Collaborator

angelnu commented Mar 31, 2019

What version of the adapter are you on? In version 2.1.5 I added reconnects based on mDNS updates.

In order to debug the issue I would need the full log for the device with issues so I can see what sequence of events&triggers it gets.

The status I would need is the one from the chromecast device since it shows if the adapter is currently connected:
image

@raintonr
Copy link
Contributor

I am using this adapter to output speech from sayit and also the 'bongs' from our doorbell (just a nice MP3 file) and have been trying to debug this issue with...

DEBUG=* node --inspect node_modules/iobroker.chromecast/main.js --force --logs

Looks like castv2 connection closed is the magic phrase to watch out for ;)

One can start the adapter and request playback of any number of items so long as they are withing a short period of each other. However, after some time with no playback the above castv2 connection closed message is output and after this no further playback is possible.

I notice it's just over 1 minute between the last playback and the connection closed message.

Something else odd when looking at the debug logs is that the heartbeat messages all look fine (ie. one 'PING' followed by a 'PONG' for each device detected) until at some point they start being duplicated (ie. two sets of 'PING' followed by a 'PONG' for each device detected!).

This duplication always seems to happen some time between the last successful playback and the failure which appears rather suspicious.

BTW, my stack trace looks like this just to confirm it's the same one we're talking about:

Kitchen - Error playing playlist - TypeError: Cannot read property 'send' of null
    at Client.send (/opt/iobroker/node_modules/castv2/lib/client.js:128:11)
    at Channel.send (/opt/iobroker/node_modules/castv2/lib/channel.js:34:12)
    at fn.Controller.send (/opt/iobroker/node_modules/castv2-client/lib/controllers/controller.js:28:16)
    at fn.RequestResponseController.request (/opt/iobroker/node_modules/castv2-client/lib/controllers/request-response.js:34:8)
    at fn.MediaController.queueLoad (/opt/iobroker/node_modules/castv2-client/lib/controllers/media.js:146:8)
    at DefaultMediaReceiver.queueLoad (/opt/iobroker/node_modules/castv2-client/lib/senders/default-media-receiver.js:50:24)
    at /opt/iobroker/node_modules/castv2-player/lib/persistentPlayer.js:504:26
    at new Promise (<anonymous>)
    at /opt/iobroker/node_modules/castv2-player/lib/persistentPlayer.js:495:16
    at process._tickCallback (internal/process/next_tick.js:68:7)

@raintonr
Copy link
Contributor

So the problem is that the closed connection from the underlying castv2 module is not passed up as expected to the castv2-client and therefore is not triggering a reconnect here:

https://github.com/angelnu/castv2-player/blob/523fd5a8317656a5038b7a7b3ca9d1de4e89f1a7/lib/persistentClient.js#L252

A fix is discussed here: thibauts/node-castv2-client#58 (comment), and indeed changing the line in persistentClient.js from...

            //If connection closes afterwards then re-open it again
            that._client.once("close", function(){
              that._close();
              that._connectClient();
            });

...to...

            //If connection closes afterwards then re-open it again
            that._client.client.once("close", function(){
              that._close();
              that._connectClient();
            });

... works perfectly. Or at least for me. I will create an issue in that module and reference everything there.

@stale
Copy link

stale bot commented Aug 26, 2021

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs within the next 7 days. Please check if the issue is still relevant in the most current version of the adapter and tell us. Also check that all relevant details, logs and reproduction steps are included and update them if needed. Thank you for your contributions.
Dieses Problem wurde automatisch als veraltet markiert, da es in letzter Zeit keine Aktivitäten gab. Es wird geschlossen, wenn nicht innerhalb der nächsten 7 Tage weitere Aktivitäten stattfinden. Bitte überprüft, ob das Problem auch in der aktuellsten Version des Adapters noch relevant ist, und teilt uns dies mit. Überprüft auch, ob alle relevanten Details, Logs und Reproduktionsschritte enthalten sind bzw. aktualisiert diese. Vielen Dank für Eure Unterstützung.

@stale stale bot added the wontfix label Aug 26, 2021
@stale
Copy link

stale bot commented Sep 2, 2021

This issue has been automatically closed because of inactivity. Please open a new issue if still relevant and make sure to include all relevant details, logs and reproduction steps. Thank you for your contributions.
Dieses Problem wurde aufgrund von Inaktivität automatisch geschlossen. Bitte öffnet ein neues Issue, falls dies noch relevant ist und stellt sicher das alle relevanten Details, Logs und Reproduktionsschritte enthalten sind. Vielen Dank für Eure Unterstützung.

@stale stale bot closed this as completed Sep 2, 2021
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