2018-02-02, 12:16
I am using a RPi 3 with OSMC to run Kodi. Recently I upgraded my Apple TV (4th gen) to an Apple TV 4K, and after I plugged in the Apple TV 4K, I started experiencing a strange issue where my AVR would keep turning back on. If I turn off the TV, my AVR turns off, and then after a few seconds, the AVR turns back on. A couple of times I woke up in the middle of the night to realize that my TV had also turned itself on.
Initially I thought perhaps there was an incompatibility with RPi Kodi + Apple TV 4K. I played around with it a bit, and tried every Kodi distribution I could find for the RPi. All of them had the same issue, except for OpenELEC 8.04, which is a bit dated (June 2017).
I collected the following logs.
OSMC, latest version, where the AVR turns back on after turning off the TV:
The difference between OSMC and OpenELEC seems to be the following in the OSMC log:
From what I can work out, the Apple TV is requesting the active source after I turn off the TV. With OSMC, Kodi responds with a message saying it is the active source, and I suspect this is causing my AVR to turn back on.
I tested this theory by setting the Apple TV as the active source, and turning off the TV. In this case the AVR stayed off, and the logs looked similar to the OpenELEC ones, where Kodi did not respond that it was the active source.
I also tried copying the libCEC.so from OpenELEC and OSMC, and that also fixed the issue. No more AVR turning itself back on.
Based on this hunch, I looked at the libCEC code, and worked out how to compile libCEC as per the instructions here:
https://github.com/Pulse-Eight/libcec/bl...berrypi.md
https://github.com/Pulse-Eight/libcec/issues/373
I edited the code as follows:
After that I replaced the OSMC libcec.so with the compiled one (sudo cp ~/libcec/build/src/libcec/libcec.so.4.0.2 /usr/osmc/lib/libcec.so.4.0.2).
I’ve been testing this for the last few weeks, and it is rock solid. I have not had my AVR turn back on once.
What I am wondering is where the real issue lies. Is it a problem with the AVR, with the Apple TV 4K, or with Kodi? I am also curious why OpenELEC behaves differently from all the other Kodi distributions on RPi.
While I am happy to keep recompiling libCEC to fix this issue, it would also be great if this could be fixed somehow.
Can anyone explain why this is happening with libCEC in OSMC?
Initially I thought perhaps there was an incompatibility with RPi Kodi + Apple TV 4K. I played around with it a bit, and tried every Kodi distribution I could find for the RPi. All of them had the same issue, except for OpenELEC 8.04, which is a bit dated (June 2017).
I collected the following logs.
OSMC, latest version, where the AVR turns back on after turning off the TV:
Quote:TRAFFIC: [ 1126988] >> 0f:a0:08:00:46:00:09:00:01OpenELEC 8.04, where the AVR stays off after turning off the TV:
DEBUG: [ 1126989] >> TV (0) -> Broadcast (F): vendor command with id (A0)
TRAFFIC: [ 1127088] >> 0f:36
DEBUG: [ 1127088] TV (0): power status changed from 'on' to 'standby'
DEBUG: [ 1127088] >> TV (0) -> Broadcast (F): standby (36)
DEBUG: [ 1128497] GetPhysicalAddress - physical address = 4300
DEBUG: [ 1128497] physical address unchanged (4300)
TRAFFIC: [ 1129099] >> 5f:84:40:00:05
DEBUG: [ 1129100] >> Audio (5) -> Broadcast (F): report physical address (84)
TRAFFIC: [ 1129260] >> 4f:a6:06:10:56:10
DEBUG: [ 1129260] >> Playback 1 (4) -> Broadcast (F): UNKNOWN (A6)
TRAFFIC: [ 1129410] >> 4f:84:42:00:04
DEBUG: [ 1129410] >> Playback 1 (4) -> Broadcast (F): report physical address (84)
TRAFFIC: [ 1129488] >> 4f:85
DEBUG: [ 1129488] >> 4 requests active source
DEBUG: [ 1129488] Playback 1 (4): power status changed from 'standby' to 'on'
NOTICE: [ 1129488] << Recorder 1 (1) -> broadcast (F): active source (4300)
TRAFFIC: [ 1129488] << 1f:82:43:00
DEBUG: [ 1129488] >> Playback 1 (4) -> Broadcast (F): request active source (85)
WARNING: [ 1129818] unhandled response received: opcode=82 initiator=1 destination=f response=0
TRAFFIC: [ 1129818] >> 4f:90:01
DEBUG: [ 1129818] Playback 1 (4): power status changed from 'on' to 'standby'
DEBUG: [ 1129818] >> Playback 1 (4) -> Broadcast (F): report power status (90)
TRAFFIC: [ 1130640] >> 0f:84:00:00:00
DEBUG: [ 1130640] << Recorder 1 (1) -> broadcast (F): physical address 4300
TRAFFIC: [ 1130640] << 1f:84:43:00:01
DEBUG: [ 1130640] >> TV (0) -> Broadcast (F): report physical address (84)
DEBUG: [ 1130852] GetPhysicalAddress - physical address = 4300
DEBUG: [ 1130852] physical address unchanged (4300)
WARNING: [ 1131032] unhandled response received: opcode=84 initiator=1 destination=f response=0
TRAFFIC: [ 1131225] >> 5f:84:40:00:05
DEBUG: [ 1131226] >> Audio (5) -> Broadcast (F): report physical address (84)
TRAFFIC: [ 1132082] >> 0f:87:08:00:46
DEBUG: [ 1132082] << Recorder 1 (1) -> Broadcast (F): vendor id Pulse Eight (1582)
TRAFFIC: [ 1132082] << 1f:87:00:15:82
DEBUG: [ 1132082] >> TV (0) -> Broadcast (F): device vendor id (87)
WARNING: [ 1132535] unhandled response received: opcode=87 initiator=1 destination=f response=0
TRAFFIC: [ 1132536] >> 4f:a6:06:10:56:10
DEBUG: [ 1132536] >> Playback 1 (4) -> Broadcast (F): UNKNOWN (A6)
TRAFFIC: [ 1132653] >> 4f:84:42:00:04
DEBUG: [ 1132653] >> Playback 1 (4) -> Broadcast (F): report physical address (84)
TRAFFIC: [ 1132810] >> 4f:85
DEBUG: [ 1132811] >> 4 requests active source
DEBUG: [ 1132811] Playback 1 (4): power status changed from 'standby' to 'on'
NOTICE: [ 1132811] << Recorder 1 (1) -> broadcast (F): active source (4300)
TRAFFIC: [ 1132811] << 1f:82:43:00
DEBUG: [ 1132811] >> Playback 1 (4) -> Broadcast (F): request active source (85)
WARNING: [ 1133144] unhandled response received: opcode=82 initiator=1 destination=f response=0
TRAFFIC: [ 1133145] >> 4f:90:01
DEBUG: [ 1133145] Playback 1 (4): power status changed from 'on' to 'standby'
DEBUG: [ 1133145] >> Playback 1 (4) -> Broadcast (F): report power status (90)
TRAFFIC: [ 1133333] >> 5f:87:00:09:b0
DEBUG: [ 1133333] >> Audio (5) -> Broadcast (F): device vendor id (87)
TRAFFIC: [ 1134135] >> 0f:87:08:00:46
DEBUG: [ 1134135] << Recorder 1 (1) -> Broadcast (F): vendor id Pulse Eight (1582)
TRAFFIC: [ 1134135] << 1f:87:00:15:82
DEBUG: [ 1134135] >> TV (0) -> Broadcast (F): device vendor id (87)
WARNING: [ 1134495] unhandled response received: opcode=87 initiator=1 destination=f response=0
TRAFFIC: [ 1134682] >> 5f:84:40:00:05
DEBUG: [ 1134683] >> Audio (5) -> Broadcast (F): report physical address (84)
TRAFFIC: [ 1134985] >> 5f:84:40:00:05
DEBUG: [ 1134985] >> Audio (5) -> Broadcast (F): report physical address (84)
TRAFFIC: [ 1135330] >> 5f:87:00:09:b0
DEBUG: [ 1135331] >> Audio (5) -> Broadcast (F): device vendor id (87)
Quote:TRAFFIC: [ 407023] >> 0f:84:00:00:00My CEC devices are as follows (from the scan command in cec-client):
DEBUG: [ 407023] << Recorder 1 (1) -> broadcast (F): physical address 4300
TRAFFIC: [ 407024] << 1f:84:43:00:01
DEBUG: [ 407024] >> TV (0) -> Broadcast (F): report physical address (84)
WARNING: [ 407444] unhandled response received: opcode=84 initiator=1 destination=f response=0
TRAFFIC: [ 407444] >> 0f:87:08:00:46
DEBUG: [ 407444] << Recorder 1 (1) -> Broadcast (F): vendor id Pulse Eight (1582)
TRAFFIC: [ 407444] << 1f:87:00:15:82
DEBUG: [ 407444] >> TV (0) -> Broadcast (F): device vendor id (87)
TRAFFIC: [ 407688] >> 0f:82:00:00
DEBUG: [ 407688] TV (0): power status changed from 'standby' to 'on'
DEBUG: [ 407688] making TV (0) the active source
DEBUG: [ 407688] >> TV (0) -> Broadcast (F): active source (82)
WARNING: [ 407868] unhandled response received: opcode=87 initiator=1 destination=f response=0
TRAFFIC: [ 408029] >> 0f:80:00:00:40:00
DEBUG: [ 408029] >> TV (0) -> Broadcast (F): routing change (80)
TRAFFIC: [ 408389] >> 5f:81:43:00
DEBUG: [ 408389] making Recorder 1 (1) the active source
DEBUG: [ 408389] marking TV (0) as inactive source
NOTICE: [ 408389] >> source activated: Recorder 1 (1)
DEBUG: [ 408389] sending active source message for 'Recorder 1'
NOTICE: [ 408389] << powering on 'TV' (0)
DEBUG: [ 408389] >> Audio (5) -> Broadcast (F): routing information (81)
TRAFFIC: [ 408389] << 10:04
NOTICE: [ 408509] << Recorder 1 (1) -> broadcast (F): active source (4300)
TRAFFIC: [ 408509] << 1f:82:43:00
WARNING: [ 408629] unhandled response received: opcode=4 initiator=1 destination=0 response=0
DEBUG: [ 408779] << Recorder 1 (1) -> TV (0): menu state 'activated'
TRAFFIC: [ 408779] << 10:8e:00
WARNING: [ 408932] unhandled response received: opcode=82 initiator=1 destination=f response=0
WARNING: [ 409172] unhandled response received: opcode=8e initiator=1 destination=0 response=0
DEBUG: [ 409417] GetPhysicalAddress - physical address = 4300
DEBUG: [ 409417] physical address unchanged (4300)
TRAFFIC: [ 410496] >> 5f:84:40:00:05
DEBUG: [ 410496] >> Audio (5) -> Broadcast (F): report physical address (84)
TRAFFIC: [ 410711] >> 4f:84:42:00:04
DEBUG: [ 410711] >> Playback 1 (4) -> Broadcast (F): report physical address (84)
TRAFFIC: [ 410786] >> 01:83
DEBUG: [ 410786] << Recorder 1 (1) -> broadcast (F): physical address 4300
TRAFFIC: [ 410786] << 1f:84:43:00:01
DEBUG: [ 410786] >> TV (0) -> Recorder 1 (1): give physical address (83)
WARNING: [ 411482] unhandled response received: opcode=84 initiator=1 destination=f response=0
TRAFFIC: [ 411483] >> 0f:a0:08:00:46:00:13:00:10:80:00:01:00:00:00:00
DEBUG: [ 411483] >> TV (0) -> Broadcast (F): vendor command with id (A0)
TRAFFIC: [ 412218] >> 01:46
DEBUG: [ 412218] << Recorder 1 (1) -> TV (0): OSD name 'CECTester'
TRAFFIC: [ 412218] << 10:47:43:45:43:54:65:73:74:65:72
DEBUG: [ 412218] >> TV (0) -> Recorder 1 (1): give osd name (46)
DEBUG: [ 412218] GetPhysicalAddress - physical address = 4300
DEBUG: [ 412399] physical address unchanged (4300)
WARNING: [ 412731] unhandled response received: opcode=47 initiator=1 destination=0 response=0
TRAFFIC: [ 412993] >> 5f:87:00:09:b0
DEBUG: [ 412993] >> Audio (5) -> Broadcast (F): device vendor id (87)
TRAFFIC: [ 413316] >> 5f:84:40:00:05
DEBUG: [ 413316] >> Audio (5) -> Broadcast (F): report physical address (84)
TRAFFIC: [ 413477] >> 4f:a6:06:10:56:10
DEBUG: [ 413477] >> Playback 1 (4) -> Broadcast (F): UNKNOWN (A6)
TRAFFIC: [ 413626] >> 4f:84:42:00:04
DEBUG: [ 413626] >> Playback 1 (4) -> Broadcast (F): report physical address (84)
TRAFFIC: [ 413704] >> 4f:85
DEBUG: [ 413704] >> 4 requests active source
DEBUG: [ 413704] Playback 1 (4): power status changed from 'standby' to 'on'
NOTICE: [ 413704] << Recorder 1 (1) -> broadcast (F): active source (4300)
TRAFFIC: [ 413704] << 1f:82:43:00
DEBUG: [ 413704] >> Playback 1 (4) -> Broadcast (F): request active source (85)
WARNING: [ 414036] unhandled response received: opcode=82 initiator=1 destination=f response=0
TRAFFIC: [ 414037] >> 4f:90:01
DEBUG: [ 414037] Playback 1 (4): power status changed from 'on' to 'standby'
DEBUG: [ 414037] >> Playback 1 (4) -> Broadcast (F): report power status (90)
TRAFFIC: [ 414453] >> 0f:84:00:00:00
DEBUG: [ 414453] << Recorder 1 (1) -> broadcast (F): physical address 4300
TRAFFIC: [ 414453] << 1f:84:43:00:01
DEBUG: [ 414454] >> TV (0) -> Broadcast (F): report physical address (84)
WARNING: [ 414850] unhandled response received: opcode=84 initiator=1 destination=f response=0
TRAFFIC: [ 415362] >> 0f:87:08:00:46
DEBUG: [ 415362] << Recorder 1 (1) -> Broadcast (F): vendor id Pulse Eight (1582)
TRAFFIC: [ 415362] << 1f:87:00:15:82
DEBUG: [ 415362] >> TV (0) -> Broadcast (F): device vendor id (87)
WARNING: [ 415752] unhandled response received: opcode=87 initiator=1 destination=f response=0
TRAFFIC: [ 415999] >> 5f:84:40:00:05
DEBUG: [ 415999] >> Audio (5) -> Broadcast (F): report physical address (84)
TRAFFIC: [ 416135] >> 4f:87:00:10:fa
DEBUG: [ 416136] >> Playback 1 (4) -> Broadcast (F): device vendor id (87)
TRAFFIC: [ 416364] >> 01:8c
DEBUG: [ 416364] << Recorder 1 (1) -> TV (0): vendor id Pulse Eight (1582)
TRAFFIC: [ 416364] << 1f:87:00:15:82
DEBUG: [ 416364] >> TV (0) -> Recorder 1 (1): give device vendor id (8C)
WARNING: [ 416822] unhandled response received: opcode=87 initiator=1 destination=f response=0
TRAFFIC: [ 416822] >> 4f:87:00:10:fa
DEBUG: [ 416823] >> Playback 1 (4) -> Broadcast (F): device vendor id (87)
TRAFFIC: [ 416974] >> 01:8f
DEBUG: [ 416974] << Recorder 1 (1) -> TV (0): on
TRAFFIC: [ 416974] << 10:90:00
DEBUG: [ 416975] >> TV (0) -> Recorder 1 (1): give device power status (8F)
WARNING: [ 417245] unhandled response received: opcode=90 initiator=1 destination=0 response=0
TRAFFIC: [ 417512] >> 5f:87:00:09:b0
DEBUG: [ 417513] >> Audio (5) -> Broadcast (F): device vendor id (87)
TRAFFIC: [ 418408] >> 5f:72:01
DEBUG: [ 418408] >> Audio (5) -> Broadcast (F): set system audio mode (72)
TRAFFIC: [ 476569] >> 01:8f
DEBUG: [ 476569] << Recorder 1 (1) -> TV (0): on
TRAFFIC: [ 476569] << 10:90:00
DEBUG: [ 476569] >> TV (0) -> Recorder 1 (1): give device power status (8F)
WARNING: [ 476839] unhandled response received: opcode=90 initiator=1 destination=0 response=0
Quote:CEC bus information
===================
device #0: TV
address: 0.0.0.0
active source: no
vendor: Sony
osd string: TV
CEC version: 1.4
power status: on
language: eng
device #1: Recorder 1
address: 4.3.0.0
active source: no
vendor: Pulse Eight
osd string: CECTester
CEC version: 1.4
power status: on
language: eng
device #4: Playback 1
address: 4.2.0.0
active source: yes
vendor: Unknown
osd string: Apple TV
CEC version: unknown
power status: on
language:
device #5: Audio
address: 4.0.0.0
active source: no
vendor: Onkyo
osd string: TX-NR414
CEC version: 1.4
power status: on
language:
The difference between OSMC and OpenELEC seems to be the following in the OSMC log:
Quote:TRAFFIC: [ 1132810] >> 4f:85
DEBUG: [ 1132811] >> 4 requests active source
DEBUG: [ 1132811] Playback 1 (4): power status changed from 'standby' to 'on'
NOTICE: [ 1132811] << Recorder 1 (1) -> broadcast (F): active source (4300)
TRAFFIC: [ 1132811] << 1f:82:43:00
From what I can work out, the Apple TV is requesting the active source after I turn off the TV. With OSMC, Kodi responds with a message saying it is the active source, and I suspect this is causing my AVR to turn back on.
I tested this theory by setting the Apple TV as the active source, and turning off the TV. In this case the AVR stayed off, and the logs looked similar to the OpenELEC ones, where Kodi did not respond that it was the active source.
I also tried copying the libCEC.so from OpenELEC and OSMC, and that also fixed the issue. No more AVR turning itself back on.
Based on this hunch, I looked at the libCEC code, and worked out how to compile libCEC as per the instructions here:
https://github.com/Pulse-Eight/libcec/bl...berrypi.md
https://github.com/Pulse-Eight/libcec/issues/373
I edited the code as follows:
cpp:
--- a/src/libcec/implementations/CECCommandHandler.cpp
+++ b/src/libcec/implementations/CECCommandHandler.cpp
@@ -37,6 +37,7 @@
#include "devices/CECBusDevice.h"
#include "devices/CECAudioSystem.h"
#include "devices/CECPlaybackDevice.h"
+#include "devices/CECTV.h"
#include "CECClient.h"
#include "CECProcessor.h"
#include "LibCEC.h"
@@ -548,9 +549,17 @@ int CCECCommandHandler::HandleRequestActiveSource(const cec_command &command)
LIB_CEC->AddLog(CEC_LOG_DEBUG, ">> %i requests active source", (uint8_t) command.initiator);
m_processor->GetDevice(command.initiator)->SetPowerStatus(CEC_POWER_STATUS_ON);
- std::vector<CCECBusDevice *> devices;
- for (size_t iDevicePtr = 0; iDevicePtr < GetMyDevices(devices); iDevicePtr++)
- devices[iDevicePtr]->TransmitActiveSource(true);
+ // Do not transmit active source if TV is off, to prevent AVR from turning back on
+ // after TV is powered off
+ cec_power_status tv_state = m_processor->GetTV()->GetCurrentPowerStatus();
+ LIB_CEC->AddLog(CEC_LOG_DEBUG, "Got TV power status: %i", (uint8_t) tv_state);
+
+ if (tv_state == CEC_POWER_STATUS_ON)
+ {
+ std::vector<CCECBusDevice *> devices;
+ for (size_t iDevicePtr = 0; iDevicePtr < GetMyDevices(devices); iDevicePtr++)
+ devices[iDevicePtr]->TransmitActiveSource(true);
+ }
}
return COMMAND_HANDLED;
After that I replaced the OSMC libcec.so with the compiled one (sudo cp ~/libcec/build/src/libcec/libcec.so.4.0.2 /usr/osmc/lib/libcec.so.4.0.2).
I’ve been testing this for the last few weeks, and it is rock solid. I have not had my AVR turn back on once.
What I am wondering is where the real issue lies. Is it a problem with the AVR, with the Apple TV 4K, or with Kodi? I am also curious why OpenELEC behaves differently from all the other Kodi distributions on RPi.
While I am happy to keep recompiling libCEC to fix this issue, it would also be great if this could be fixed somehow.
Can anyone explain why this is happening with libCEC in OSMC?
