From a6f8c3f6620cf9ad0187a09e320feb9d52787577 Mon Sep 17 00:00:00 2001
From: Paulus Schoutsen <paulus@home-assistant.io>
Date: Tue, 2 Oct 2018 13:33:16 +0200
Subject: [PATCH] Add logging to light updates (#17069)

---
 homeassistant/components/light/hue.py | 14 ++++++++++++--
 1 file changed, 12 insertions(+), 2 deletions(-)

diff --git a/homeassistant/components/light/hue.py b/homeassistant/components/light/hue.py
index 958abaca033..686fc01caf9 100644
--- a/homeassistant/components/light/hue.py
+++ b/homeassistant/components/light/hue.py
@@ -7,6 +7,7 @@ https://home-assistant.io/components/light.hue/
 import asyncio
 from datetime import timedelta
 import logging
+from time import monotonic
 import random
 
 import async_timeout
@@ -159,18 +160,23 @@ async def async_update_items(hass, bridge, async_add_entities,
     import aiohue
 
     if is_group:
+        api_type = 'group'
         api = bridge.api.groups
     else:
+        api_type = 'light'
         api = bridge.api.lights
 
     try:
+        start = monotonic()
         with async_timeout.timeout(4):
             await api.update()
-    except (asyncio.TimeoutError, aiohue.AiohueException):
+    except (asyncio.TimeoutError, aiohue.AiohueException) as err:
+        _LOGGER.debug('Failed to fetch %s: %s', api_type, err)
+
         if not bridge.available:
             return
 
-        _LOGGER.error('Unable to reach bridge %s', bridge.host)
+        _LOGGER.error('Unable to reach bridge %s (%s)', bridge.host, err)
         bridge.available = False
 
         for light_id, light in current.items():
@@ -179,6 +185,10 @@ async def async_update_items(hass, bridge, async_add_entities,
 
         return
 
+    finally:
+        _LOGGER.debug('Finished %s request in %.3f seconds',
+                      api_type, monotonic() - start)
+
     if not bridge.available:
         _LOGGER.info('Reconnected to bridge %s', bridge.host)
         bridge.available = True