Error logged each time scan interval happens

[rcdailey]

I get the exception below each time the scan_interval is triggered (15s). I'm not sure what the issue is. I double checked my NZ7 password and IP address. I ensured that, on my projector, DHCP Client and Control4 SDDP are set to "On".

My configuration.yaml currently has this:

remote:
  - platform: jvc_projectors
    name: nz7
    password: snip
    host: '192.168.1.163'
    scan_interval: 15

Currently using v3.5.3 of JVC Projectors in HACS. My JVC NZ7 FW is at v2.0.

If there's further diagnostic I can provide, please let me know. Thank you.

This error originated from a custom integration.

Logger: homeassistant.helpers.entity
Source: custom_components/jvc_projectors/remote.py:217
Integration: jvc_projectors
First occurred: 4:24:28 PM (13 occurrences)
Last logged: 4:27:28 PM

Update for remote.nz7 fails
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 538, in async_update_ha_state
    await self.async_device_update()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 736, in async_device_update
    raise exc
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/config/custom_components/jvc_projectors/remote.py", line 217, in update
    self.jvc_client.get_theater_optimizer_state()
  File "/usr/local/lib/python3.10/site-packages/jvc_projector/jvc_projector.py", line 554, in get_theater_optimizer_state
    state, _ = self._do_reference_op("theater_optimizer", ACKs.picture_ack)
  File "/usr/local/lib/python3.10/site-packages/jvc_projector/jvc_projector.py", line 447, in _do_reference_op
    msg, success = self._send_command(
  File "/usr/local/lib/python3.10/site-packages/jvc_projector/jvc_projector.py", line 222, in _send_command
    result, success = self._do_command(send_command, ack, command_type)
  File "/usr/local/lib/python3.10/site-packages/jvc_projector/jvc_projector.py", line 330, in _do_command
    message = self.client.recv(1000)
TimeoutError: timed out

[iloveicedgreentea]

self.jvc_client.get_theater_optimizer_state()

Have you ever configured theater optimizer? Is it set to off? Problem with JVC commands is when they fail, they just timeout because there is no error returned. I suspect its something due to that. Also a lot of the functionality is undocumented i.e in this case if you never configured it, maybe it will just fail instead of sending a null value or something. I will add some sanity checking for that command. In the meantime can you try to configure theater optimizer and see if that fixes the issue?

[iloveicedgreentea]

Actually before you do that in HACS can you go to redownload and pull from master? I put a catch for the timeout exception which should catch this in the future. And once you see TO set to 'not set', you can try to configure TO and check again.

[rcdailey]

Yes I've used the theater optimizer in the past. I was testing in SDR which has it disabled / inaccessible. According to the user manual, it's only available in HDR content modes, specifically with Frame Adapt HDR enabled.

I'm working on an automation to automatically change picture modes based on roku activity + content type, and there will be situations where Theater Optimizer likely isn't available and I'll need to test it.

Yes I will redownload and try again and report back. Thanks for the quick reply.

[rcdailey]

Strange, it's working fine now and I'm not able to reproduce. I'm also seeing entity events and events for my automation in logbook now whereas it wasn't before. Maybe I had something weird going on. Should I stick to master or hop back to the latest tag?

[iloveicedgreentea]

That TO check should only trigger if the content type contains HDR or HLG. Did you manually change the content type attribute or something? What do your attributes say? If it happens again, take a screenshot of all the attributes.

Also for your automation, I have something similar based on my madvr envy, might save you some time

alias: JVC - Envy picture mode HDR
description: ""
trigger:
  - platform: state
    entity_id:
      - remote.envy
    attribute: hdr_flag
  - platform: time_pattern
    seconds: "20"
    enabled: true
condition: []
action:
  - if:
      - condition: and
        conditions:
          - condition: state
            entity_id: remote.nz7
            attribute: picture_mode
            state: user1
          - condition: state
            entity_id: remote.envy
            attribute: hdr_flag
            state: true
    then:
      - service: remote.send_command
        data:
          command: picture_mode,user2
          num_repeats: 1
          delay_secs: 0.4
          hold_secs: 0
        target:
          entity_id: remote.nz7
  - if:
      - condition: and
        conditions:
          - condition: state
            entity_id: remote.nz7
            attribute: picture_mode
            state: user2
          - condition: state
            entity_id: remote.envy
            attribute: hdr_flag
            state: false
    then:
      - service: remote.send_command
        data:
          command: picture_mode,user1
          num_repeats: 1
          delay_secs: 0.4
          hold_secs: 0
        target:
          entity_id: remote.nz7
mode: single

[rcdailey]

I'm just cycling left/right through Content Type in the JVC on-screen menu as I test my automation. Next time this happens I'll screenshot the attributes. As of right now it seems to be working fine. Sorry for the false alarm!

[rcdailey]

What is hold_secs and delay_secs? I wasn't able to find documentation on these properties.

[rcdailey]

@iloveicedgreentea I've got an automation that works, but I'm having timing issues when I switch between activities and content types. I test these scenarios in different ways:

• Go from Gaming activity -> non gaming activity (and vice versa)
• From a gaming activity, turn my playstation on/off (this triggers going between SDR and HDR10 content types)

Some transitions are quick. Others take a long time, mostly due to a combination of the Harmony Hub taking a while and the JVC projector going "blank" for about 2-4 seconds between content type and picture mode changes.

I'll provide my automation & script below. There's several places I can put delays. I'm not sure the best place to do that. I think if I had a better understanding of what hold_secs and delay_secs do, that might help.

The Automation:

- alias: "JVC: Set Picture Mode"
  id: 85a1b949-f61b-425e-95e3-60bdfc9d1c1d
  trigger:
  - platform: state
    entity_id: remote.nz7
    attribute: content_type
  - platform: template
    # Watch for `starting_activity` to be set to `null`. Based on my observations, this only happens
    # when an activity is *done starting*, which is what we want (we do not want to do anything to
    # the projector until the activity has finished starting)
    value_template: "{{ state_attr('remote.harmony_media_room', 'activity_starting') == none }}"
    # for: "00:00:08"
  condition:
  action:
  - choose:

    # GAMING ACTIVITIES
    - conditions: >
        {{ state_attr('remote.harmony_media_room', 'current_activity') in
           ['Play PS4', 'Nintendo Switch'] }}
      sequence:
      - service: script.set_expected_picture_modes
        data:
          hdr_mode: user4 # "Games" picture mode
          sdr_mode: user1 # "Gaming" picture mode

    # SHIELD ACTIVITY
    - conditions: >
        {{ state_attr('remote.harmony_media_room', 'current_activity') == 'Shield' }}
      sequence:
      - service: script.set_expected_picture_modes
        data:
          hdr_mode: frame_adapt_hdr
          sdr_mode: natural

The Script:

set_expected_picture_modes:
  variables:
    hdr_mode:
    sdr_mode:
  sequence:
  - choose:
    - conditions: >
        {{ state_attr('remote.nz7', 'content_type') == 'hdr10' and
           state_attr('remote.nz7', 'picture_mode') != hdr_mode }}
      sequence:
      - service: remote.send_command
        data:
          command: "picture_mode,{{ hdr_mode }}"
          num_repeats: 1
          delay_secs: 1
          hold_secs: 0
        target:
          entity_id: remote.nz7
    - conditions: >
        {{ state_attr('remote.nz7', 'content_type') == 'sdr' and
           state_attr('remote.nz7', 'picture_mode') != sdr_mode }}
      sequence:
      - service: remote.send_command
        data:
          command: "picture_mode,{{ sdr_mode }}"
          num_repeats: 1
          delay_secs: 1
          hold_secs: 0
        target:
          entity_id: remote.nz7

[rcdailey]

Ok I'm going to give up for the night. I'm noticing a lot more errors during transitions. I think those are due to some timing issues. The real issue is that because of these errors (I think), the jvc_projectors integration stops updating the entity state/attributes (Observed in the developer tools state tab). Attached logs. Also will show you a screenshot too.

Logs: home-assistant_2023-02-05T02-56-39.323Z.log

Sorry to throw so much at you. Thanks for your support.

[iloveicedgreentea]

Can you turn on debug logs, restart, and then reproduce? First need to find whats causing the failure. Most likely commands running too quickly or at once but I want the integration to be able to handle it

Ill digest the other stuff tomorrow

Add this to your configuration.yaml

logger:
  default: critical
  logs:
    custom_components.jvc_projectors: debug

[rcdailey]

I was able to reproduce it getting stuck on sdr when I was in HDR10 mode after starting a film in Plex. My automation didn't kick off because the JVC integration is stuck. Hopefully this helps. Debug logs were enabled using your YAML above.

home-assistant_2023-02-05T03-46-13.474Z.log

[iloveicedgreentea]

Okay thanks I am going to investigate this

[iloveicedgreentea]

Im still looking into this. Working on some library updates that might fix this incidentally

[rcdailey]

Thanks for the update! I really appreciate everything you're doing. I'm happy to give this another hammering when you make a new release. Just let me know!

[iloveicedgreentea]

can you check if 3.5.7 solves this issue

[rcdailey]

I'm sorry that I forgot to report back! I have been running the latest version for all this time and it's very solid. I haven't seen any errors in the logs. Thank you for the fix!