Unresponsive system and repeated chromecast log errors

Question

Unresponsive system and repeated chromecast log errors

Closed this issue 6 years ago · 7 comments

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.

Answer 1 · 2019-03-06T14:50:30.000Z

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.

Answer 2 · 2019-03-06T15:10:36.000Z

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).

Answer 3 · 2019-03-06T18:13:33.000Z

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.

Answer 4 · 2019-03-07T08:39:17.000Z

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.

Answer 5 · 2019-03-07T09:15:05.000Z

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

Answer 6 · 2019-03-07T10:06:25.000Z

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.

Answer 7 · 2019-03-07T10:08:24.000Z

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 :)