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

Unresponsive system and repeated chromecast log errors #3

Closed
mrstegeman opened this issue Mar 6, 2019 · 7 comments
Closed

Unresponsive system and repeated chromecast log errors #3

mrstegeman opened this issue Mar 6, 2019 · 7 comments

Comments

@mrstegeman
Copy link
Collaborator

Originally from WebThingsIO/gateway#1694 (via @clockbrain)

My whole system has become unresponsive with only a few of the devices working. Some will work for a short time after removing and adding again but some refuse to work at all. I have about 20 devices, some are wifi and some are zigbee.

One possible clue is my log file has 17 repeats of this error:

2019-03-06 09:50:15.636 ERROR  : chromecast: Re-creating client after Error: Device timeout
2019-03-06 09:50:15.639 ERROR  : chromecast:     at fn.ontimeout (/home/pi/.mozilla-iot/addons/chromecast-adapter/node_modules/castv2-client/lib/senders/platform.js:56:26)
2019-03-06 09:50:15.641 ERROR  : chromecast:     at Object.onceWrapper (events.js:313:30)
2019-03-06 09:50:15.642 ERROR  : chromecast:     at emitNone (events.js:106:13)
2019-03-06 09:50:15.643 ERROR  : chromecast:     at fn.emit (events.js:208:7)
2019-03-06 09:50:15.645 ERROR  : chromecast:     at Timeout.ontimeout [as _onTimeout] (/home/pi/.mozilla-iot/addons/chromecast-adapter/node_modules/castv2-client/lib/controllers/heartbeat.js:44:10)
2019-03-06 09:50:15.646 ERROR  : chromecast:     at ontimeout (timers.js:498:11)
2019-03-06 09:50:15.647 ERROR  : chromecast:     at tryOnTimeout (timers.js:323:5)
2019-03-06 09:50:15.648 ERROR  : chromecast:     at Timer.listOnTimeout (timers.js:290:5)

immediately followed by this in the log file:

2019-03-06 09:50:50.962 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.965 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.966 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.967 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.969 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.970 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.972 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.973 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.975 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.976 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.977 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.978 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.980 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.981 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.983 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.984 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:50.985 INFO   : chromecast: Adapter: ChromecastAdapter id ChromecastAdapter removeThing( Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. ) started
2019-03-06 09:50:51.139 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.140 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.141 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.143 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.144 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.145 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.146 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.147 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.151 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.152 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.153 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.154 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.155 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.157 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.157 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.159 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.160 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.161 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.164 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.165 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.166 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.167 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.169 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.170 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.171 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.172 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.173 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.174 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.175 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.176 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.177 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.178 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.179 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.180 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.181 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.182 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.183 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.184 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.185 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.186 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.187 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.188 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.189 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.190 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.191 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.192 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.193 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.194 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.195 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.196 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.197 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.198 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.199 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.200 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.201 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.202 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.203 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.204 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.205 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:50:51.206 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-06 09:53:56.123 ERROR  : (node:780) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 propertyChanged listeners added. Use emitter.setMaxListeners() to increase limit
2019-03-06 09:53:57.580 ERROR  : (node:780) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 actionStatus listeners added. Use emitter.setMaxListeners() to increase limit

The chromecast is turned off for most of each day but even so I wouldn't expect failed connections to clog up the gateway.

Any suggestions on how to reset or clear my system?

I'm on version 0.7 of the gateway.

@freaktechnik
Copy link
Collaborator

This is either due to a missing removeThing at https://github.com/freaktechnik/chromecast-adapter/blob/master/adapter.js#L136 though in that case it should not lock up, or a continuous network problem with keeping the connection to the chromecast open.

@freaktechnik
Copy link
Collaborator

I think there may be a loop with closing and events, will put up a fix later today (which should also fix the first part I mentioned above).

@freaktechnik
Copy link
Collaborator

Version 0.3.4 s now available. If that doesn't fix the issue I'm a bit lost, since the error comes from the client library I use to talk with chromecasts.

@clockbrain
Copy link

Thanks for your quick response to my issue. I've updated to latest adaptor now although I think you meant v0.3.3.

I don't see that first device timeout error anymore so that seems fixed but I am still seeing the second error message. I've narrowed it down to when I try to add new devices. Every time I scan for new devices it adds one more error row per device to those chromecast device already exists messages. A reboot of the system resets the count back to just 1 error for each device but then the errors keep accumulating whenever I scan for new devices. So this extract is after reboot and 3 device scans. If I scan again I'll see 5 error messages for each chromecast device.

2019-03-07 08:20:51.190 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.192 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.194 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.196 ERROR  : chromecast: Device: Google-Home-130b7c70bc769ee08f13f1a25e3e9ce1._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.206 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.208 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.210 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.211 ERROR  : chromecast: Device: Google-Cast-Group-25a3a7482b6246eba57186af9fbc7900._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.220 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.223 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.224 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.226 ERROR  : chromecast: Device: Google-Home-Mini-7683b2d0eb36490a4ca981378bdbf011._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.292 ERROR  : chromecast: Device: Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.294 ERROR  : chromecast: Device: Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.296 ERROR  : chromecast: Device: Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. already exists.
2019-03-07 08:20:51.298 ERROR  : chromecast: Device: Chromecast-ec591b84d19b2957ba33d5844aabb9ef._googlecast._tcp.local. already exists.

Removing and re-adding a chromecast device doesn't help. It picks up where it left off with repeated error rows.

One other minor thing I noticed, when scanning for and adding a chromecast device, it initially shows the device type as On/Off Switch with the only other option being Custom Thing. Once it is added though it appears ok with the splat giving Mute:Play/Pause:App:Volume:Muted properties.

@freaktechnik
Copy link
Collaborator

This second error is not really relevant and shouldn't have any impact on responsiveness, it's possibly just a memory leak, if even.

it initially shows the device type as On/Off Switch with the only other option being Custom Thing

Yes, there's no more specific device type yet, see WebThingsIO/schemas#34

@clockbrain
Copy link

Ok. I'm only just getting started with Things Gateway so still getting my head around it all.

The first error is back - coincided with powering off the Chromecast.

2019-03-07 09:50:59.318 ERROR  : chromecast: Re-creating client after Error: Device timeout
2019-03-07 09:50:59.319 ERROR  : chromecast:     at fn.ontimeout (/home/pi/.mozilla-iot/addons/chromecast-adapter/node_modules/castv2-client/lib/senders/platform.js:56:26)
2019-03-07 09:50:59.321 ERROR  : chromecast:     at Object.onceWrapper (events.js:313:30)
2019-03-07 09:50:59.322 ERROR  : chromecast:     at emitNone (events.js:106:13)
2019-03-07 09:50:59.324 ERROR  : chromecast:     at fn.emit (events.js:208:7)
2019-03-07 09:50:59.326 ERROR  : chromecast:     at Timeout.ontimeout [as _onTimeout] (/home/pi/.mozilla-iot/addons/chromecast-adapter/node_modules/castv2-client/lib/controllers/heartbeat.js:44:10)
2019-03-07 09:50:59.330 ERROR  : chromecast:     at ontimeout (timers.js:498:11)
2019-03-07 09:50:59.332 ERROR  : chromecast:     at tryOnTimeout (timers.js:323:5)
2019-03-07 09:50:59.335 ERROR  : chromecast:     at Timer.listOnTimeout (timers.js:290:5)

System responsiveness is ok though - but I did also disable a few other devices so can't really say whether your update helped or not. Will keep an eye on how it behaves over time.

@freaktechnik
Copy link
Collaborator

You'll continue seeing these timeouts, those are an issue with the chromecasts and their network handling. I'll close this for now, feel free to re-open with additional details if you encounter this again and open other issues your come across :)

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

No branches or pull requests

3 participants