[Ecobee] Thread issues with discovery services

[morph166955]

Opening as per @kaikreuzer from openhab/openhab-core#1998

The EcobeeThermostatBridgeHandler does nasty stuff by starting discovery services itself (and not returning immediately, what would be anyhow expected from startBackgroundDiscovery()). This causes multiple discoveries running in parallel and blocking the 3 remaining threads of the thread pool:

"OH-thingHandler-3" #229 daemon prio=5 os_prio=0 cpu=6314.43ms elapsed=3419.08s tid=0x00007fbd14039000 nid=0x40cde waiting for monitor entry  [0x00007fbd00521000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl.thingDiscovered(DiscoveryServiceRegistryImpl.java:252)
	- waiting to lock <0x00000000c4f0d968> (a org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl)
	at org.openhab.core.config.discovery.AbstractDiscoveryService.thingDiscovered(AbstractDiscoveryService.java:266)
	at org.openhab.binding.ecobee.internal.discovery.SensorDiscoveryService.discoverSensors(SensorDiscoveryService.java:111)
	- locked <0x00000000cee7e450> (a org.openhab.binding.ecobee.internal.discovery.SensorDiscoveryService)
	at org.openhab.binding.ecobee.internal.discovery.SensorDiscoveryService.startBackgroundDiscovery(SensorDiscoveryService.java:84)
	at org.openhab.binding.ecobee.internal.handler.EcobeeThermostatBridgeHandler.discoverSensors(EcobeeThermostatBridgeHandler.java:847)

"OH-thingHandler-5" #238 daemon prio=5 os_prio=0 cpu=7112.63ms elapsed=3419.01s tid=0x00007fbd4c012800 nid=0x40cea waiting for monitor entry  [0x00007fbcff918000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl.thingDiscovered(DiscoveryServiceRegistryImpl.java:252)
	- waiting to lock <0x00000000c4f0d968> (a org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl)
	at org.openhab.core.config.discovery.AbstractDiscoveryService.thingDiscovered(AbstractDiscoveryService.java:266)
	at org.openhab.binding.ecobee.internal.discovery.ThermostatDiscoveryService.discoverThermostats(ThermostatDiscoveryService.java:118)
	- locked <0x00000000ce589800> (a org.openhab.binding.ecobee.internal.discovery.ThermostatDiscoveryService)
	at org.openhab.binding.ecobee.internal.discovery.ThermostatDiscoveryService.startBackgroundDiscovery(ThermostatDiscoveryService.java:88)
	at org.openhab.binding.ecobee.internal.handler.EcobeeAccountBridgeHandler.discoverThermostats(EcobeeAccountBridgeHandler.java:253)
	at org.openhab.binding.ecobee.internal.handler.EcobeeAccountBridgeHandler.refresh(EcobeeAccountBridgeHandler.java:226)
	at org.openhab.binding.ecobee.internal.handler.EcobeeAccountBridgeHandler$$Lambda$900/0x0000000100e30040.run(Unknown Source)

"OH-thingHandler-4" #237 daemon prio=5 os_prio=0 cpu=6348.00ms elapsed=3419.01s tid=0x00007fbd14049800 nid=0x40ceb waiting for monitor entry  [0x00007fbcff816000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl.thingDiscovered(DiscoveryServiceRegistryImpl.java:252)
	- waiting to lock <0x00000000c4f0d968> (a org.openhab.core.config.discovery.internal.DiscoveryServiceRegistryImpl)
	at org.openhab.core.config.discovery.AbstractDiscoveryService.thingDiscovered(AbstractDiscoveryService.java:266)
	at org.openhab.binding.ecobee.internal.discovery.SensorDiscoveryService.discoverSensors(SensorDiscoveryService.java:111)
	- locked <0x00000000cef465f8> (a org.openhab.binding.ecobee.internal.discovery.SensorDiscoveryService)
	at org.openhab.binding.ecobee.internal.discovery.SensorDiscoveryService.startBackgroundDiscovery(SensorDiscoveryService.java:84)
	at org.openhab.binding.ecobee.internal.handler.EcobeeThermostatBridgeHandler.discoverSensors(EcobeeThermostatBridgeHandler.java:847)

[mhilbush]

I'm a little lost here.

Of the 3 threads shown above, the 2 calls to EcobeeThermostatBridgeHandler.discoverSensors are discovering the sensors configured on each of 2 separate thermostats. These calls take 1 or 2 msec max. @morph166955 can you confirm that you have 2 thermostat things in your system?

The call to EcobeeAccountBridgeHandler.discoverThermostats does make an external call to the ecobee API to discover the thermostats configured on the account. I agree that this should return immediately.

However, I don't understand why all 3 of these threads are stuck on the synchronized block at the start of DiscoveryServiceRegistryImpl.thingDiscovered.

[morph166955]

Yes, I have two. One per floor in the house. The main floor has 7 sensors, the second has 2.

[kaikreuzer]

@mhilbush You are right, it is not ecobee itself that causes the blocking, that is done by a bug in the SamsungTV binding in @morph166955's case. But ecobee then causes the thing handler pool to get blocked, because it itself is blocked by discovery, which should not happen.

Note that all discovery activity should be triggered by discovery services ONLY. A thing handler must not do this. Also, the method startBackgroundDiscovery is expected to be called by the framework only and it should merely activate the discovery service' ability to silently do discovery in the background while not being actively triggered. It usually should hence only set a flag within the discovery service and maybe start a scheduled job, but it should not do any discovery activity itself.

[mhilbush]

Ok, thanks. I'll rework the binding to prevent the bridge handlers from doing the actual discovery. But I still have a couple questions.

But ecobee then causes the thing handler pool to get blocked, because it itself is blocked by discovery, which should not happen.

I understand that. But maybe I don't fully understand what the Samsung binding is doing. Won't all the discovery services eventually become blocked when they call thingDiscovered?

It usually should hence only set a flag within the discovery service and maybe start a scheduled job

By "it", you're referring to the bridge/thing handler, correct?

[kaikreuzer]

Won't all the discovery services eventually become blocked when they call thingDiscovered?

Yes, indeed. As I said, the root cause is the SamsungTV binding as it registers as a discovery listener and blocks this thread, so that discovery services cannot announce any discovered things anymore. But ecobee now not only causes discovery to not work anymore, but also to block the thing handlers.

By "it", you're referring to the bridge/thing handler, correct?

No, the startBackgroundDiscovery method of the discovery service.