unhandled response received

LuckyLukert commented 4 years ago

Hi, I'm using

a fresh installation of Kodi with LibreElec 9.2.1
on a Raspberry Pi 4
with this newly bought cable: https://www.amazon.de/gp/product/B014I8TVLI (which claims to support CEC)
and a Sony HT-XF9000 with enabled CEC
the sound bar gets the Raspberry as input and outputs to a projector (Acer H6535i DLP)

CEC does not seem to work (Pressing buttons on the Sony remote has no effect)

I tried turning everything off
I did not yet have CEC working. Do I have to enable some setting or should it work out-of-the-box?

My cec-client gives the following messages:

No device type given. Using 'recording device'
CEC Parser created - libCEC version 4.0.4
no serial port given. trying autodetect: 
 path:     Raspberry Pi
 com port: RPI

opening a connection to the CEC adapter...
DEBUG:   [             237] Broadcast (F): osd name set to 'Broadcast'
DEBUG:   [             238] Open - vc_cec initialised
DEBUG:   [             238] logical address changed to Free use (e)
NOTICE:  [             238] connection opened
DEBUG:   [             238] processor thread started
DEBUG:   [             238] << Broadcast (F) -> TV (0): POLL
DEBUG:   [             239] initiator 'Broadcast' is not supported by the CEC adapter. using 'Free use' instead
TRAFFIC: [             239] << e0
DEBUG:   [             329] initiator 'Broadcast' is not supported by the CEC adapter. using 'Free use' instead
TRAFFIC: [             329] << e0
DEBUG:   [             419] >> POLL not sent
DEBUG:   [             419] TV (0): device status changed into 'not present'
NOTICE:  [             419] registering new CEC client - v4.0.4
DEBUG:   [             420] detecting logical address for type 'recording device'
DEBUG:   [             420] trying logical address 'Recorder 1'
DEBUG:   [             420] << Recorder 1 (1) -> Recorder 1 (1): POLL
TRAFFIC: [             420] << 11
TRAFFIC: [             690] << 11
DEBUG:   [             960] >> POLL not sent
DEBUG:   [             961] using logical address 'Recorder 1'
DEBUG:   [             961] Recorder 1 (1): device status changed into 'handled by libCEC'
DEBUG:   [             961] Recorder 1 (1): power status changed from 'unknown' to 'on'
DEBUG:   [             961] Recorder 1 (1): vendor = Pulse Eight (001582)
DEBUG:   [             961] Recorder 1 (1): CEC version 1.4
DEBUG:   [             961] AllocateLogicalAddresses - device '0', type 'recording device', LA '1'
DEBUG:   [             961] logical address changed to Recorder 1 (1)
DEBUG:   [             961] Recorder 1 (1): osd name set to 'CECTester'
DEBUG:   [             962] Recorder 1 (1): menu language set to 'eng'
DEBUG:   [             962] GetPhysicalAddress - physical address = 1100
DEBUG:   [             962] AutodetectPhysicalAddress - autodetected physical address '1100'
DEBUG:   [             962] Recorder 1 (1): physical address changed from ffff to 1100
DEBUG:   [             962] << Recorder 1 (1) -> broadcast (F): physical address 1100
TRAFFIC: [             962] << 1f:84:11:00:01
NOTICE:  [            1113] CEC client registered: libCEC version = 4.0.4, client version = 4.0.4, firmware version = 1, logical address(es) = Recorder 1 (1) , physical address: 1.1.0.0,  compiled on Tue Mar  3 22:13:47 UTC 2020 by jenkins@leda.us.nss.net on Linux 4.19.0-6-amd64 (x86_64), features: P8_USB, DRM, P8_detect, RPi
DEBUG:   [            1113] << Recorder 1 (1) -> TV (0): OSD name 'CECTester'
DEBUG:   [            1113] << Recorder 1 (1) -> TV (0): POLL
TRAFFIC: [            1113] << 10
TRAFFIC: [            1203] << 10
DEBUG:   [            1295] >> POLL not sent
DEBUG:   [            1295] not sending command 'set osd name': destination device 'TV' marked as not present
DEBUG:   [            1295] << requesting power status of 'TV' (0)
DEBUG:   [            1295] << Recorder 1 (1) -> TV (0): POLL
TRAFFIC: [            1295] << 10
TRAFFIC: [            1385] << 10
waiting for input
DEBUG:   [            1475] >> POLL not sent
DEBUG:   [            1475] not sending command 'give device power status': destination device 'TV' marked as not present
WARNING: [            1565] unhandled response received: opcode=0 initiator=1 destination=0 response=1

The last line repeats twice every ~1s and spams my log.
I do not see any effect (in the log) when pressing buttons on the Sony remote control.

Somewhere between all the unhandled response messages, I found:

TRAFFIC: [         1269158] >> 5f:72:00
DEBUG:   [         1269158] >> Audio (5): system audio mode status changed from on to off
DEBUG:   [         1269158] device Audio (5) status changed to present after command set system audio mode
DEBUG:   [         1269158] >> Audio (5) -> Broadcast (F): set system audio mode (72)

I guess that was the point when the Sony sound bar went to sleep. (When it is off, it simply forwards the HDMI to the projector without playing sound)

Do you have some hints what these messages mean? Where could be the problem?

jivf commented 4 years ago

Hi,

The rpi adapter is working good, but the following:

DEBUG: [ 1113] << Recorder 1 (1) -> TV (0): POLL TRAFFIC:[ 1113] << 10 TRAFFIC:[ 1203] << 10 DEBUG: [ 1295] >> POLL not sent

Indicates that a communication between your rpi and the tv is not working. This is because at least one of the following reasons:

The tv is not plug in to an electrical source.
The tv has not the hdmi-cec feature.
The tv has not the hdmi-cec feature enable.
The hdmi cable in use is not a correct one. Use a cable of version 1.4+.
May be other(s).

The following:

TRAFFIC: [ 1269158] >> 5f:72:00 DEBUG: [ 1269158] >> Audio (5): system audio mode status changed from on to off DEBUG: [ 1269158] device Audio (5) status changed to present after command set system audio mode DEBUG: [ 1269158] >> Audio (5) -> Broadcast (F): set system audio mode (72)

Indicates that a systems audio of logical address 05 give notice to all devices a change in its mode status.

Regards.

LuckyLukert commented 4 years ago

Hi, thanks for your comprehensive and fast answer!

I had really trouble reading that log. Your answer helped a lot!

I am not sure what TV (0) is. I don't have a TV connected. My setup is:

RPI4 ---(cable1)--- Soundbar ---(cable2)--- Projector

I'm only interested in CEC for cable1, i.e., controlling the RPI with the remote of the soundbar.

As an overview my understanding now - please confirm or deny:

Recorder 1 is the RPI (inferred from your answer)
The RPI makes a POLL to TV which is not answered as TV not exist.
As I guess that the soundbar went to sleep when the Audio (5) message came in, I assume that the the soundbar has address 5.
At least cable1 supports CEC as otherwise the Audio (5) message could not have arrived.

Regarding your list of possible reasons:

The soundbar was plugged in and turned on.
The soundbar supports CEC.
I checked that CEC is enabled for the soundbar.
I would like to avoid buying a new HDMI cable if my understanding 4 is correct.

My questions leading towards a possible solution:

Do you have a better reference for POLL than this?
Could it be that this POLL to the unknown TV (0) should actually go to address 5 (the soundbar)
Could it be that the soundbar never receives a POLL and thus thinks that forwarding the play/pause/... key presses is not necessary as no one is listening?
Can I somehow configure that the POLL goes to address 5 and not 0?

Best, Philip

p.s. sorry for the late reaction, I somehow didn't get a notification and you were amazingly fast!

Pulse-Eight / libcec