cec: keep the 'busy state' of the command handler in CCECBusDevice
[deb_libcec.git] / src / lib / devices / CECBusDevice.cpp
index bd68dfc1f8e555fede5920b7bd6a690dbf6c78e4..c68fc0584b9ca744244965c26f175c06804df774 100644 (file)
@@ -1,7 +1,7 @@
 /*
  * This file is part of the libCEC(R) library.
  *
- * libCEC(R) is Copyright (C) 2011 Pulse-Eight Limited.  All rights reserved.
+ * libCEC(R) is Copyright (C) 2011-2012 Pulse-Eight Limited.  All rights reserved.
  * libCEC(R) is an original work, containing original code.
  *
  * libCEC(R) is a trademark of Pulse-Eight Limited.
 #include "../implementations/CECCommandHandler.h"
 #include "../implementations/SLCommandHandler.h"
 #include "../implementations/VLCommandHandler.h"
-#include "../platform/timeutils.h"
+#include "../LibCEC.h"
+#include "../platform/util/timeutils.h"
 
 using namespace CEC;
+using namespace PLATFORM;
 
 #define ToString(p) m_processor->ToString(p)
 
@@ -54,9 +56,11 @@ CCECBusDevice::CCECBusDevice(CCECProcessor *processor, cec_logical_address iLogi
   m_menuState(CEC_MENU_STATE_ACTIVATED),
   m_bActiveSource(false),
   m_iLastActive(0),
+  m_iLastPowerStateUpdate(0),
   m_cecVersion(CEC_VERSION_UNKNOWN),
   m_deviceStatus(CEC_DEVICE_STATUS_UNKNOWN),
-  m_handlerMutex(false)
+  m_iHandlerUseCount(0),
+  m_bAwaitingReceiveFailed(false)
 {
   m_handler = new CCECCommandHandler(this);
 
@@ -73,22 +77,19 @@ CCECBusDevice::~CCECBusDevice(void)
   delete m_handler;
 }
 
-void CCECBusDevice::AddLog(cec_log_level level, const CStdString &strMessage)
-{
-  m_processor->AddLog(level, strMessage);
-}
-
 bool CCECBusDevice::HandleCommand(const cec_command &command)
 {
   bool bHandled(false);
 
   /* update "last active" */
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     m_iLastActive = GetTimeMs();
 
     if (m_deviceStatus != CEC_DEVICE_STATUS_HANDLED_BY_LIBCEC)
       m_deviceStatus = CEC_DEVICE_STATUS_PRESENT;
+
+    MarkBusy();
   }
 
   /* handle the command */
@@ -97,32 +98,28 @@ bool CCECBusDevice::HandleCommand(const cec_command &command)
   /* change status to present */
   if (bHandled)
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     if (m_deviceStatus != CEC_DEVICE_STATUS_HANDLED_BY_LIBCEC)
     {
       if (m_deviceStatus != CEC_DEVICE_STATUS_PRESENT)
-      {
-        CStdString strLog;
-        strLog.Format("device %s (%x) status changed to present after command %s", GetLogicalAddressName(), (uint8_t)GetLogicalAddress(), ToString(command.opcode));
-        AddLog(CEC_LOG_DEBUG, strLog);
-      }
+        CLibCEC::AddLog(CEC_LOG_DEBUG, "device %s (%x) status changed to present after command %s", GetLogicalAddressName(), (uint8_t)GetLogicalAddress(), ToString(command.opcode));
       m_deviceStatus = CEC_DEVICE_STATUS_PRESENT;
     }
   }
 
+  MarkReady();
   return bHandled;
 }
 
 bool CCECBusDevice::PowerOn(void)
 {
-  CStdString strLog;
-  strLog.Format("<< powering on '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
-  AddLog(CEC_LOG_DEBUG, strLog.c_str());
-
+  bool bReturn(false);
+  CLibCEC::AddLog(CEC_LOG_DEBUG, "<< powering on '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
+  MarkBusy();
   if (m_handler->TransmitImageViewOn(GetMyLogicalAddress(), m_iLogicalAddress))
   {
     {
-      CLockObject lock(&m_mutex);
+      CLockObject lock(m_mutex);
 //      m_powerStatus = CEC_POWER_STATUS_UNKNOWN;
       m_powerStatus = CEC_POWER_STATUS_IN_TRANSITION_STANDBY_TO_ON;
     }
@@ -132,24 +129,25 @@ bool CCECBusDevice::PowerOn(void)
 //      /* sending the normal power on command appears to have failed */
 //      CStdString strLog;
 //      strLog.Format("<< sending power on keypress to '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
-//      AddLog(CEC_LOG_DEBUG, strLog.c_str());
+//      CLibCEC::AddLog(CEC_LOG_DEBUG, strLog.c_str());
 //
 //      TransmitKeypress(CEC_USER_CONTROL_CODE_POWER);
 //      return TransmitKeyRelease();
 //    }
-    return true;
+    bReturn = true;
   }
 
-  return false;
+  MarkReady();
+  return bReturn;
 }
 
 bool CCECBusDevice::Standby(void)
 {
-  CStdString strLog;
-  strLog.Format("<< putting '%s' (%X) in standby mode", GetLogicalAddressName(), m_iLogicalAddress);
-  AddLog(CEC_LOG_DEBUG, strLog.c_str());
-
-  return m_handler->TransmitStandby(GetMyLogicalAddress(), m_iLogicalAddress);
+  CLibCEC::AddLog(CEC_LOG_DEBUG, "<< putting '%s' (%X) in standby mode", GetLogicalAddressName(), m_iLogicalAddress);
+  MarkBusy();
+  bool bReturn = m_handler->TransmitStandby(GetMyLogicalAddress(), m_iLogicalAddress);
+  MarkReady();
+  return bReturn;
 }
 
 /** @name Getters */
@@ -158,7 +156,7 @@ cec_version CCECBusDevice::GetCecVersion(bool bUpdate /* = false */)
 {
   bool bRequestUpdate(false);
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     bRequestUpdate = (GetStatus() == CEC_DEVICE_STATUS_PRESENT &&
       (bUpdate || m_cecVersion == CEC_VERSION_UNKNOWN));
   }
@@ -166,7 +164,7 @@ cec_version CCECBusDevice::GetCecVersion(bool bUpdate /* = false */)
   if (bRequestUpdate)
     RequestCecVersion();
 
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   return m_cecVersion;
 }
 
@@ -176,11 +174,11 @@ bool CCECBusDevice::RequestCecVersion(void)
 
   if (!MyLogicalAddressContains(m_iLogicalAddress))
   {
-    CStdString strLog;
-    strLog.Format("<< requesting CEC version of '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
-    AddLog(CEC_LOG_NOTICE, strLog);
+    MarkBusy();
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< requesting CEC version of '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
 
     bReturn = m_handler->TransmitRequestCecVersion(GetMyLogicalAddress(), m_iLogicalAddress);
+    MarkReady();
   }
   return bReturn;
 }
@@ -194,7 +192,7 @@ cec_menu_language &CCECBusDevice::GetMenuLanguage(bool bUpdate /* = false */)
 {
   bool bRequestUpdate(false);
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     bRequestUpdate = (GetStatus() == CEC_DEVICE_STATUS_PRESENT &&
         (bUpdate || !strcmp(m_menuLanguage.language, "???")));
   }
@@ -202,7 +200,7 @@ cec_menu_language &CCECBusDevice::GetMenuLanguage(bool bUpdate /* = false */)
   if (bRequestUpdate)
     RequestMenuLanguage();
 
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   return m_menuLanguage;
 }
 
@@ -213,14 +211,20 @@ bool CCECBusDevice::RequestMenuLanguage(void)
   if (!MyLogicalAddressContains(m_iLogicalAddress) &&
       !IsUnsupportedFeature(CEC_OPCODE_GET_MENU_LANGUAGE))
   {
-    CStdString strLog;
-    strLog.Format("<< requesting menu language of '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
-    AddLog(CEC_LOG_NOTICE, strLog);
+    MarkBusy();
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< requesting menu language of '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
     bReturn = m_handler->TransmitRequestMenuLanguage(GetMyLogicalAddress(), m_iLogicalAddress);
+    MarkReady();
   }
   return bReturn;
 }
 
+cec_menu_state CCECBusDevice::GetMenuState(void)
+{
+  CLockObject lock(m_mutex);
+  return m_menuState;
+}
+
 cec_logical_address CCECBusDevice::GetMyLogicalAddress(void) const
 {
   return m_processor->GetLogicalAddress();
@@ -235,7 +239,7 @@ CStdString CCECBusDevice::GetOSDName(bool bUpdate /* = false */)
 {
   bool bRequestUpdate(false);
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     bRequestUpdate = (GetStatus() == CEC_DEVICE_STATUS_PRESENT &&
         (bUpdate || m_strDeviceName.Equals(ToString(m_iLogicalAddress))) &&
         m_type != CEC_DEVICE_TYPE_TV);
@@ -244,7 +248,7 @@ CStdString CCECBusDevice::GetOSDName(bool bUpdate /* = false */)
   if (bRequestUpdate)
     RequestOSDName();
 
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   return m_strDeviceName;
 }
 
@@ -255,10 +259,10 @@ bool CCECBusDevice::RequestOSDName(void)
   if (!MyLogicalAddressContains(m_iLogicalAddress) &&
       !IsUnsupportedFeature(CEC_OPCODE_GIVE_OSD_NAME))
   {
-    CStdString strLog;
-    strLog.Format("<< requesting OSD name of '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
-    AddLog(CEC_LOG_NOTICE, strLog);
+    MarkBusy();
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< requesting OSD name of '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
     bReturn = m_handler->TransmitRequestOSDName(GetMyLogicalAddress(), m_iLogicalAddress);
+    MarkReady();
   }
   return bReturn;
 }
@@ -267,15 +271,15 @@ uint16_t CCECBusDevice::GetPhysicalAddress(bool bUpdate /* = false */)
 {
   bool bRequestUpdate(false);
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     bRequestUpdate = (GetStatus() == CEC_DEVICE_STATUS_PRESENT &&
         (m_iPhysicalAddress == 0xFFFF || bUpdate));
   }
 
   if (bRequestUpdate && !RequestPhysicalAddress())
-    AddLog(CEC_LOG_ERROR, "failed to request the physical address (1)");
+    CLibCEC::AddLog(CEC_LOG_ERROR, "failed to request the physical address");
 
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   return m_iPhysicalAddress;
 }
 
@@ -285,10 +289,10 @@ bool CCECBusDevice::RequestPhysicalAddress(void)
 
   if (!MyLogicalAddressContains(m_iLogicalAddress))
   {
-    CStdString strLog;
-    strLog.Format("<< requesting physical address of '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
-    AddLog(CEC_LOG_NOTICE, strLog);
+    MarkBusy();
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< requesting physical address of '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
     bReturn = m_handler->TransmitRequestPhysicalAddress(GetMyLogicalAddress(), m_iLogicalAddress);
+    MarkReady();
   }
   return bReturn;
 }
@@ -297,16 +301,18 @@ cec_power_status CCECBusDevice::GetPowerStatus(bool bUpdate /* = false */)
 {
   bool bRequestUpdate(false);
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     bRequestUpdate = (GetStatus() == CEC_DEVICE_STATUS_PRESENT &&
         (bUpdate || m_powerStatus == CEC_POWER_STATUS_UNKNOWN ||
-            m_powerStatus == CEC_POWER_STATUS_IN_TRANSITION_STANDBY_TO_ON));
+            m_powerStatus == CEC_POWER_STATUS_IN_TRANSITION_STANDBY_TO_ON ||
+            m_powerStatus == CEC_POWER_STATUS_IN_TRANSITION_ON_TO_STANDBY ||
+            GetTimeMs() - m_iLastPowerStateUpdate >= CEC_POWER_STATE_REFRESH_TIME));
   }
 
   if (bRequestUpdate)
     RequestPowerStatus();
 
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   return m_powerStatus;
 }
 
@@ -317,10 +323,10 @@ bool CCECBusDevice::RequestPowerStatus(void)
   if (!MyLogicalAddressContains(m_iLogicalAddress) &&
       !IsUnsupportedFeature(CEC_OPCODE_GIVE_DEVICE_POWER_STATUS))
   {
-    CStdString strLog;
-    strLog.Format("<< requesting power status of '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
-    AddLog(CEC_LOG_NOTICE, strLog);
+    MarkBusy();
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< requesting power status of '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
     bReturn = m_handler->TransmitRequestPowerStatus(GetMyLogicalAddress(), m_iLogicalAddress);
+    MarkReady();
   }
   return bReturn;
 }
@@ -329,7 +335,7 @@ cec_vendor_id CCECBusDevice::GetVendorId(bool bUpdate /* = false */)
 {
   bool bRequestUpdate(false);
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     bRequestUpdate = (GetStatus() == CEC_DEVICE_STATUS_PRESENT &&
         (bUpdate || m_vendor == CEC_VENDOR_UNKNOWN));
   }
@@ -337,7 +343,7 @@ cec_vendor_id CCECBusDevice::GetVendorId(bool bUpdate /* = false */)
   if (bRequestUpdate)
     RequestVendorId();
 
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   return m_vendor;
 }
 
@@ -347,10 +353,12 @@ bool CCECBusDevice::RequestVendorId(void)
 
   if (!MyLogicalAddressContains(m_iLogicalAddress))
   {
-    CStdString strLog;
-    strLog.Format("<< requesting vendor ID of '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
-    AddLog(CEC_LOG_NOTICE, strLog);
+    MarkBusy();
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< requesting vendor ID of '%s' (%X)", GetLogicalAddressName(), m_iLogicalAddress);
     bReturn = m_handler->TransmitRequestVendorId(GetMyLogicalAddress(), m_iLogicalAddress);
+    MarkReady();
+
+    ReplaceHandler(true);
   }
   return bReturn;
 }
@@ -414,11 +422,11 @@ bool CCECBusDevice::NeedsPoll(void)
 
 cec_bus_device_status CCECBusDevice::GetStatus(bool bForcePoll /* = false */)
 {
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   if (m_deviceStatus != CEC_DEVICE_STATUS_HANDLED_BY_LIBCEC &&
       (m_deviceStatus == CEC_DEVICE_STATUS_UNKNOWN || bForcePoll))
   {
-    lock.Leave();
+    lock.Unlock();
     bool bPollAcked(false);
     if (bForcePoll || NeedsPoll())
       bPollAcked = m_processor->PollDevice(m_iLogicalAddress);
@@ -437,44 +445,35 @@ cec_bus_device_status CCECBusDevice::GetStatus(bool bForcePoll /* = false */)
 void CCECBusDevice::SetCecVersion(const cec_version newVersion)
 {
   m_cecVersion = newVersion;
-
-  CStdString strLog;
-  strLog.Format("%s (%X): CEC version %s", GetLogicalAddressName(), m_iLogicalAddress, ToString(newVersion));
-  AddLog(CEC_LOG_DEBUG, strLog);
+  CLibCEC::AddLog(CEC_LOG_DEBUG, "%s (%X): CEC version %s", GetLogicalAddressName(), m_iLogicalAddress, ToString(newVersion));
 }
 
 void CCECBusDevice::SetMenuLanguage(const cec_menu_language &language)
 {
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   if (language.device == m_iLogicalAddress)
   {
-    CStdString strLog;
-    strLog.Format(">> %s (%X): menu language set to '%s'", GetLogicalAddressName(), m_iLogicalAddress, language.language);
-    m_processor->AddLog(CEC_LOG_DEBUG, strLog);
+    CLibCEC::AddLog(CEC_LOG_DEBUG, ">> %s (%X): menu language set to '%s'", GetLogicalAddressName(), m_iLogicalAddress, language.language);
     m_menuLanguage = language;
   }
 }
 
 void CCECBusDevice::SetOSDName(CStdString strName)
 {
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   if (m_strDeviceName != strName)
   {
-    CStdString strLog;
-    strLog.Format(">> %s (%X): osd name set to '%s'", GetLogicalAddressName(), m_iLogicalAddress, strName);
-    m_processor->AddLog(CEC_LOG_DEBUG, strLog);
+    CLibCEC::AddLog(CEC_LOG_DEBUG, ">> %s (%X): osd name set to '%s'", GetLogicalAddressName(), m_iLogicalAddress, strName.c_str());
     m_strDeviceName = strName;
   }
 }
 
 void CCECBusDevice::SetMenuState(const cec_menu_state state)
 {
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   if (m_menuState != state)
   {
-    CStdString strLog;
-    strLog.Format(">> %s (%X): menu state set to '%s'", GetLogicalAddressName(), m_iLogicalAddress, ToString(m_menuState));
-    m_processor->AddLog(CEC_LOG_DEBUG, strLog);
+    CLibCEC::AddLog(CEC_LOG_DEBUG, ">> %s (%X): menu state set to '%s'", GetLogicalAddressName(), m_iLogicalAddress, ToString(m_menuState));
     m_menuState = state;
   }
 }
@@ -482,7 +481,7 @@ void CCECBusDevice::SetMenuState(const cec_menu_state state)
 void CCECBusDevice::SetInactiveSource(void)
 {
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     m_bActiveSource = false;
   }
 
@@ -492,7 +491,9 @@ void CCECBusDevice::SetInactiveSource(void)
 
 void CCECBusDevice::SetActiveSource(void)
 {
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
+  if (!m_bActiveSource)
+    CLibCEC::AddLog(CEC_LOG_DEBUG, "making %s (%x) the active source", GetLogicalAddressName(), m_iLogicalAddress);
 
   for (int iPtr = 0; iPtr < 16; iPtr++)
     if (iPtr != m_iLogicalAddress)
@@ -504,29 +505,25 @@ void CCECBusDevice::SetActiveSource(void)
 
 bool CCECBusDevice::TryLogicalAddress(void)
 {
-  CStdString strLog;
-  strLog.Format("trying logical address '%s'", GetLogicalAddressName());
-  AddLog(CEC_LOG_DEBUG, strLog);
+  CLibCEC::AddLog(CEC_LOG_DEBUG, "trying logical address '%s'", GetLogicalAddressName());
 
-  m_processor->SetAckMask(0x1 << m_iLogicalAddress);
+  m_processor->SetAckMask(0);
   if (!TransmitPoll(m_iLogicalAddress))
   {
-    strLog.Format("using logical address '%s'", GetLogicalAddressName());
-    AddLog(CEC_LOG_NOTICE, strLog);
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "using logical address '%s'", GetLogicalAddressName());
     SetDeviceStatus(CEC_DEVICE_STATUS_HANDLED_BY_LIBCEC);
 
     return true;
   }
 
-  strLog.Format("logical address '%s' already taken", GetLogicalAddressName());
-  AddLog(CEC_LOG_DEBUG, strLog);
+  CLibCEC::AddLog(CEC_LOG_DEBUG, "logical address '%s' already taken", GetLogicalAddressName());
   SetDeviceStatus(CEC_DEVICE_STATUS_PRESENT);
   return false;
 }
 
 void CCECBusDevice::SetDeviceStatus(const cec_bus_device_status newStatus)
 {
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   switch (newStatus)
   {
   case CEC_DEVICE_STATUS_UNKNOWN:
@@ -558,31 +555,25 @@ void CCECBusDevice::SetDeviceStatus(const cec_bus_device_status newStatus)
 
 void CCECBusDevice::SetPhysicalAddress(uint16_t iNewAddress)
 {
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   if (iNewAddress > 0 && m_iPhysicalAddress != iNewAddress)
   {
-    CStdString strLog;
-    strLog.Format(">> %s (%X): physical address changed from %04x to %04x", GetLogicalAddressName(), m_iLogicalAddress, m_iPhysicalAddress, iNewAddress);
-    AddLog(CEC_LOG_DEBUG, strLog.c_str());
-
+    CLibCEC::AddLog(CEC_LOG_DEBUG, ">> %s (%X): physical address changed from %04x to %04x", GetLogicalAddressName(), m_iLogicalAddress, m_iPhysicalAddress, iNewAddress);
     m_iPhysicalAddress = iNewAddress;
   }
 }
 
 void CCECBusDevice::SetStreamPath(uint16_t iNewAddress, uint16_t iOldAddress /* = 0 */)
 {
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   if (iNewAddress > 0)
   {
-    CStdString strLog;
-    strLog.Format(">> %s (%X): stream path changed from %04x to %04x", GetLogicalAddressName(), m_iLogicalAddress, iOldAddress == 0 ? m_iStreamPath : iOldAddress, iNewAddress);
-    AddLog(CEC_LOG_DEBUG, strLog.c_str());
-
+    CLibCEC::AddLog(CEC_LOG_DEBUG, ">> %s (%X): stream path changed from %04x to %04x", GetLogicalAddressName(), m_iLogicalAddress, iOldAddress == 0 ? m_iStreamPath : iOldAddress, iNewAddress);
     m_iStreamPath = iNewAddress;
 
     if (iNewAddress > 0)
     {
-      lock.Leave();
+      lock.Unlock();
       SetPowerStatus(CEC_POWER_STATUS_ON);
     }
   }
@@ -590,65 +581,83 @@ void CCECBusDevice::SetStreamPath(uint16_t iNewAddress, uint16_t iOldAddress /*
 
 void CCECBusDevice::SetPowerStatus(const cec_power_status powerStatus)
 {
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   if (m_powerStatus != powerStatus)
   {
-    CStdString strLog;
-    strLog.Format(">> %s (%X): power status changed from '%s' to '%s'", GetLogicalAddressName(), m_iLogicalAddress, ToString(m_powerStatus), ToString(powerStatus));
-    m_processor->AddLog(CEC_LOG_DEBUG, strLog);
+    m_iLastPowerStateUpdate = GetTimeMs();
+    CLibCEC::AddLog(CEC_LOG_DEBUG, ">> %s (%X): power status changed from '%s' to '%s'", GetLogicalAddressName(), m_iLogicalAddress, ToString(m_powerStatus), ToString(powerStatus));
     m_powerStatus = powerStatus;
   }
 }
 
-bool CCECBusDevice::ReplaceHandler(bool bInitHandler /* = true */)
+void CCECBusDevice::MarkBusy(void)
 {
-  CLockObject lock(&m_mutex);
-  CLockObject handlerLock(&m_handlerMutex);
+  CLockObject handlerLock(m_handlerMutex);
+  ++m_iHandlerUseCount;
+}
 
-  if (m_vendor != m_handler->GetVendorId())
-  {
-    if (m_handler->InUse())
-      return false;
+void CCECBusDevice::MarkReady(void)
+{
+  CLockObject handlerLock(m_handlerMutex);
+  if (m_iHandlerUseCount > 0)
+    --m_iHandlerUseCount;
+}
 
-    delete m_handler;
+bool CCECBusDevice::ReplaceHandler(bool bActivateSource /* = true */)
+{
+  CTryLockObject lock(m_mutex);
+  if (!lock.IsLocked())
+    return false;
+
+  CLockObject handlerLock(m_handlerMutex);
+  if (m_iHandlerUseCount > 0)
+    return false;
 
-    switch (m_vendor)
+  if (m_vendor != m_handler->GetVendorId())
+  {
+    if (CCECCommandHandler::HasSpecificHandler(m_vendor))
     {
-    case CEC_VENDOR_SAMSUNG:
-      m_handler = new CANCommandHandler(this);
-      break;
-    case CEC_VENDOR_LG:
-      m_handler = new CSLCommandHandler(this);
-      break;
-    case CEC_VENDOR_PANASONIC:
-      m_handler = new CVLCommandHandler(this);
-      break;
-    default:
-      m_handler = new CCECCommandHandler(this);
-      break;
-    }
+      CLibCEC::AddLog(CEC_LOG_DEBUG, "replacing the command handler for device '%s' (%x)", GetLogicalAddressName(), GetLogicalAddress());
+      delete m_handler;
+
+      switch (m_vendor)
+      {
+      case CEC_VENDOR_SAMSUNG:
+        m_handler = new CANCommandHandler(this);
+        break;
+      case CEC_VENDOR_LG:
+        m_handler = new CSLCommandHandler(this);
+        break;
+      case CEC_VENDOR_PANASONIC:
+        m_handler = new CVLCommandHandler(this);
+        break;
+      default:
+        m_handler = new CCECCommandHandler(this);
+        break;
+      }
 
-    if (bInitHandler && m_processor->GetLogicalAddresses().IsSet(m_iLogicalAddress) && m_processor->IsInitialised())
+      m_handler->SetVendorId(m_vendor);
       m_handler->InitHandler();
+
+      if (bActivateSource && m_processor->GetLogicalAddresses().IsSet(m_iLogicalAddress) && m_processor->IsInitialised() && IsActiveSource())
+        m_handler->ActivateSource();
+    }
   }
 
   return true;
 }
 
-bool CCECBusDevice::SetVendorId(uint64_t iVendorId, bool bInitHandler /* = true */)
+bool CCECBusDevice::SetVendorId(uint64_t iVendorId)
 {
   bool bVendorChanged(false);
 
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     bVendorChanged = (m_vendor != (cec_vendor_id)iVendorId);
     m_vendor = (cec_vendor_id)iVendorId;
-    ReplaceHandler(bInitHandler);
   }
 
-  CStdString strLog;
-  strLog.Format("%s (%X): vendor = %s (%06x)", GetLogicalAddressName(), m_iLogicalAddress, ToString(m_vendor), m_vendor);
-  m_processor->AddLog(CEC_LOG_DEBUG, strLog.c_str());
+  CLibCEC::AddLog(CEC_LOG_DEBUG, "%s (%X): vendor = %s (%06x)", GetLogicalAddressName(), m_iLogicalAddress, ToString(m_vendor), m_vendor);
 
   return bVendorChanged;
 }
@@ -661,32 +670,24 @@ bool CCECBusDevice::TransmitActiveSource(void)
   bool bSendActiveSource(false);
 
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     if (m_powerStatus != CEC_POWER_STATUS_ON)
-    {
-      CStdString strLog;
-      strLog.Format("<< %s (%X) is not powered on", GetLogicalAddressName(), m_iLogicalAddress);
-      AddLog(CEC_LOG_DEBUG, strLog);
-    }
+      CLibCEC::AddLog(CEC_LOG_DEBUG, "<< %s (%X) is not powered on", GetLogicalAddressName(), m_iLogicalAddress);
     else if (m_bActiveSource)
     {
-      CStdString strLog;
-      strLog.Format("<< %s (%X) -> broadcast (F): active source (%4x)", GetLogicalAddressName(), m_iLogicalAddress, m_iPhysicalAddress);
-      AddLog(CEC_LOG_NOTICE, strLog);
+      CLibCEC::AddLog(CEC_LOG_NOTICE, "<< %s (%X) -> broadcast (F): active source (%4x)", GetLogicalAddressName(), m_iLogicalAddress, m_iPhysicalAddress);
       bSendActiveSource = true;
     }
     else
-    {
-      CStdString strLog;
-      strLog.Format("<< %s (%X) is not the active source", GetLogicalAddressName(), m_iLogicalAddress);
-      AddLog(CEC_LOG_DEBUG, strLog);
-    }
+      CLibCEC::AddLog(CEC_LOG_DEBUG, "<< %s (%X) is not the active source", GetLogicalAddressName(), m_iLogicalAddress);
   }
 
   if (bSendActiveSource)
   {
+    MarkBusy();
     m_handler->TransmitImageViewOn(m_iLogicalAddress, CECDEVICE_TV);
     m_handler->TransmitActiveSource(m_iLogicalAddress, m_iPhysicalAddress);
+    MarkReady();
     return true;
   }
 
@@ -697,69 +698,73 @@ bool CCECBusDevice::TransmitCECVersion(cec_logical_address dest)
 {
   cec_version version;
   {
-    CLockObject lock(&m_mutex);
-    CStdString strLog;
-    strLog.Format("<< %s (%X) -> %s (%X): cec version %s", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest, ToString(m_cecVersion));
-    AddLog(CEC_LOG_NOTICE, strLog);
+    CLockObject lock(m_mutex);
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< %s (%X) -> %s (%X): cec version %s", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest, ToString(m_cecVersion));
     version = m_cecVersion;
   }
 
-  return m_handler->TransmitCECVersion(m_iLogicalAddress, dest, version);
+  MarkBusy();
+  bool bReturn = m_handler->TransmitCECVersion(m_iLogicalAddress, dest, version);
+  MarkReady();
+  return bReturn;
 }
 
 bool CCECBusDevice::TransmitInactiveSource(void)
 {
   uint16_t iPhysicalAddress;
   {
-    CLockObject lock(&m_mutex);
-    CStdString strLog;
-    strLog.Format("<< %s (%X) -> broadcast (F): inactive source", GetLogicalAddressName(), m_iLogicalAddress);
-    AddLog(CEC_LOG_NOTICE, strLog);
+    CLockObject lock(m_mutex);
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< %s (%X) -> broadcast (F): inactive source", GetLogicalAddressName(), m_iLogicalAddress);
     iPhysicalAddress = m_iPhysicalAddress;
   }
 
-  return m_handler->TransmitInactiveSource(m_iLogicalAddress, iPhysicalAddress);
+  MarkBusy();
+  bool bReturn = m_handler->TransmitInactiveSource(m_iLogicalAddress, iPhysicalAddress);
+  MarkReady();
+  return bReturn;
 }
 
 bool CCECBusDevice::TransmitMenuState(cec_logical_address dest)
 {
   cec_menu_state menuState;
   {
-    CLockObject lock(&m_mutex);
-    CStdString strLog;
-    strLog.Format("<< %s (%X) -> %s (%X): menu state '%s'", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest, ToString(m_menuState));
-    AddLog(CEC_LOG_NOTICE, strLog);
+    CLockObject lock(m_mutex);
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< %s (%X) -> %s (%X): menu state '%s'", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest, ToString(m_menuState));
     menuState = m_menuState;
   }
 
-  return m_handler->TransmitMenuState(m_iLogicalAddress, dest, menuState);
+  MarkBusy();
+  bool bReturn = m_handler->TransmitMenuState(m_iLogicalAddress, dest, menuState);
+  MarkReady();
+  return bReturn;
 }
 
 bool CCECBusDevice::TransmitOSDName(cec_logical_address dest)
 {
   CStdString strDeviceName;
   {
-    CLockObject lock(&m_mutex);
-    CStdString strLog;
-    strLog.Format("<< %s (%X) -> %s (%X): OSD name '%s'", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest, m_strDeviceName.c_str());
-    AddLog(CEC_LOG_NOTICE, strLog.c_str());
+    CLockObject lock(m_mutex);
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< %s (%X) -> %s (%X): OSD name '%s'", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest, m_strDeviceName.c_str());
     strDeviceName = m_strDeviceName;
   }
 
-  return m_handler->TransmitOSDName(m_iLogicalAddress, dest, strDeviceName);
+  MarkBusy();
+  bool bReturn = m_handler->TransmitOSDName(m_iLogicalAddress, dest, strDeviceName);
+  MarkReady();
+  return bReturn;
 }
 
 bool CCECBusDevice::TransmitOSDString(cec_logical_address dest, cec_display_control duration, const char *strMessage)
 {
+  bool bReturn(false);
   if (!IsUnsupportedFeature(CEC_OPCODE_SET_OSD_STRING))
   {
-    CStdString strLog;
-    strLog.Format("<< %s (%X) -> %s (%X): display OSD message '%s'", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest, strMessage);
-    AddLog(CEC_LOG_NOTICE, strLog.c_str());
-
-    return m_handler->TransmitOSDString(m_iLogicalAddress, dest, duration, strMessage);
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< %s (%X) -> %s (%X): display OSD message '%s'", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest, strMessage);
+    MarkBusy();
+    bReturn = m_handler->TransmitOSDString(m_iLogicalAddress, dest, duration, strMessage);
+    MarkReady();
   }
-  return false;
+  return bReturn;
 }
 
 bool CCECBusDevice::TransmitPhysicalAddress(void)
@@ -767,19 +772,19 @@ bool CCECBusDevice::TransmitPhysicalAddress(void)
   uint16_t iPhysicalAddress;
   cec_device_type type;
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     if (m_iPhysicalAddress == 0xffff)
       return false;
 
-    CStdString strLog;
-    strLog.Format("<< %s (%X) -> broadcast (F): physical adddress %4x", GetLogicalAddressName(), m_iLogicalAddress, m_iPhysicalAddress);
-    AddLog(CEC_LOG_NOTICE, strLog.c_str());
-
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< %s (%X) -> broadcast (F): physical adddress %4x", GetLogicalAddressName(), m_iLogicalAddress, m_iPhysicalAddress);
     iPhysicalAddress = m_iPhysicalAddress;
     type = m_type;
   }
 
-  return m_handler->TransmitPhysicalAddress(m_iLogicalAddress, iPhysicalAddress, type);
+  MarkBusy();
+  bool bReturn = m_handler->TransmitPhysicalAddress(m_iLogicalAddress, iPhysicalAddress, type);
+  MarkReady();
+  return bReturn;
 }
 
 bool CCECBusDevice::TransmitPoll(cec_logical_address dest)
@@ -792,13 +797,12 @@ bool CCECBusDevice::TransmitPoll(cec_logical_address dest)
   if (destDevice->m_deviceStatus == CEC_DEVICE_STATUS_HANDLED_BY_LIBCEC)
     return bReturn;
 
-  CStdString strLog;
-  strLog.Format("<< %s (%X) -> %s (%X): POLL", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest);
-  AddLog(CEC_LOG_NOTICE, strLog.c_str());
+  MarkBusy();
+  CLibCEC::AddLog(CEC_LOG_NOTICE, "<< %s (%X) -> %s (%X): POLL", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest);
   bReturn = m_handler->TransmitPoll(m_iLogicalAddress, dest);
-  AddLog(CEC_LOG_DEBUG, bReturn ? ">> POLL sent" : ">> POLL not sent");
+  CLibCEC::AddLog(CEC_LOG_DEBUG, bReturn ? ">> POLL sent" : ">> POLL not sent");
 
-  CLockObject lock(&m_mutex);
+  CLockObject lock(m_mutex);
   if (bReturn)
   {
     m_iLastActive = GetTimeMs();
@@ -807,6 +811,7 @@ bool CCECBusDevice::TransmitPoll(cec_logical_address dest)
   else
     destDevice->m_deviceStatus = CEC_DEVICE_STATUS_NOT_PRESENT;
 
+  MarkReady();
   return bReturn;
 }
 
@@ -814,54 +819,59 @@ bool CCECBusDevice::TransmitPowerState(cec_logical_address dest)
 {
   cec_power_status state;
   {
-    CLockObject lock(&m_mutex);
-    CStdString strLog;
-    strLog.Format("<< %s (%X) -> %s (%X): %s", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest, ToString(m_powerStatus));
-    AddLog(CEC_LOG_NOTICE, strLog.c_str());
+    CLockObject lock(m_mutex);
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< %s (%X) -> %s (%X): %s", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest, ToString(m_powerStatus));
     state = m_powerStatus;
   }
 
-  return m_handler->TransmitPowerState(m_iLogicalAddress, dest, state);
+  MarkBusy();
+  bool bReturn = m_handler->TransmitPowerState(m_iLogicalAddress, dest, state);
+  MarkReady();
+  return bReturn;
 }
 
 bool CCECBusDevice::TransmitVendorID(cec_logical_address dest, bool bSendAbort /* = true */)
 {
+  bool bReturn(false);
   uint64_t iVendorId;
   {
-    CLockObject lock(&m_mutex);
+    CLockObject lock(m_mutex);
     iVendorId = (uint64_t)m_vendor;
   }
 
+  MarkBusy();
   if (iVendorId == CEC_VENDOR_UNKNOWN)
   {
     if (bSendAbort)
     {
-      CStdString strLog;
-      strLog.Format("<< %s (%X) -> %s (%X): vendor id feature abort", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest);
-      AddLog(CEC_LOG_NOTICE, strLog);
-
+      CLibCEC::AddLog(CEC_LOG_NOTICE, "<< %s (%X) -> %s (%X): vendor id feature abort", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest);
       m_processor->TransmitAbort(dest, CEC_OPCODE_GIVE_DEVICE_VENDOR_ID);
+      bReturn = true;
     }
-    return false;
   }
   else
   {
-    CStdString strLog;
-    strLog.Format("<< %s (%X) -> %s (%X): vendor id %s (%x)", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest, ToString((cec_vendor_id)iVendorId), iVendorId);
-    AddLog(CEC_LOG_NOTICE, strLog);
-
-    return m_handler->TransmitVendorID(m_iLogicalAddress, iVendorId);
+    CLibCEC::AddLog(CEC_LOG_NOTICE, "<< %s (%X) -> %s (%X): vendor id %s (%x)", GetLogicalAddressName(), m_iLogicalAddress, ToString(dest), dest, ToString((cec_vendor_id)iVendorId), iVendorId);
+    bReturn = m_handler->TransmitVendorID(m_iLogicalAddress, iVendorId);
   }
+  MarkReady();
+  return bReturn;
 }
 
 bool CCECBusDevice::TransmitKeypress(cec_user_control_code key, bool bWait /* = true */)
 {
-  return m_handler->TransmitKeypress(m_processor->GetLogicalAddress(), m_iLogicalAddress, key, bWait);
+  MarkBusy();
+  bool bReturn = m_handler->TransmitKeypress(m_processor->GetLogicalAddress(), m_iLogicalAddress, key, bWait);
+  MarkReady();
+  return bReturn;
 }
 
 bool CCECBusDevice::TransmitKeyRelease(bool bWait /* = true */)
 {
-  return m_handler->TransmitKeyRelease(m_processor->GetLogicalAddress(), m_iLogicalAddress, bWait);
+  MarkBusy();
+  bool bReturn = m_handler->TransmitKeyRelease(m_processor->GetLogicalAddress(), m_iLogicalAddress, bWait);
+  MarkReady();
+  return bReturn;
 }
 
 bool CCECBusDevice::IsUnsupportedFeature(cec_opcode opcode) const
@@ -874,10 +884,27 @@ void CCECBusDevice::SetUnsupportedFeature(cec_opcode opcode)
   m_unsupportedFeatures.insert(opcode);
 }
 
-bool CCECBusDevice::InitHandler(void)
+bool CCECBusDevice::ActivateSource(void)
 {
-  CLockObject lock(&m_mutex);
-  return m_handler->InitHandler();
+  MarkBusy();
+  bool bReturn = m_handler->ActivateSource();
+  MarkReady();
+  return bReturn;
+}
+
+void CCECBusDevice::HandlePoll(cec_logical_address iDestination)
+{
+  CLockObject lock(m_mutex);
+  CLibCEC::AddLog(CEC_LOG_DEBUG, "<< POLL: %s (%x) -> %s (%x)", ToString(m_iLogicalAddress), m_iLogicalAddress, ToString(iDestination), iDestination);
+  m_bAwaitingReceiveFailed = true;
+}
+
+bool CCECBusDevice::HandleReceiveFailed(void)
+{
+  CLockObject lock(m_mutex);
+  bool bReturn = m_bAwaitingReceiveFailed;
+  m_bAwaitingReceiveFailed = false;
+  return bReturn;
 }
 
 //@}