search

FutureTense / keymaster

Home Assistant integration for managing Z-Wave enabled locks
MIT License
229 stars 43 forks source link

ISSUE: Does not attempt to set codes #25

Closed mcowger closed 3 years ago

mcowger commented 3 years ago

Describe the bug After adding a code, the integration does not attempt to set the code

Environment (please complete the following information):

Logs

2021-01-11 18:31:00 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.014 seconds
2021-01-11 18:31:00 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.015 seconds
2021-01-11 18:31:05 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.002 seconds
2021-01-11 18:31:05 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.003 seconds
2021-01-11 18:31:10 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.005 seconds
2021-01-11 18:31:10 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.006 seconds
2021-01-11 18:31:15 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.002 seconds
2021-01-11 18:31:15 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.003 seconds
2021-01-11 18:31:20 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.004 seconds
2021-01-11 18:31:20 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.005 seconds
2021-01-11 18:31:25 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.002 seconds
2021-01-11 18:31:25 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.003 seconds
2021-01-11 18:31:30 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.005 seconds
2021-01-11 18:31:30 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.006 seconds
2021-01-11 18:31:35 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.003 seconds
2021-01-11 18:31:35 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.004 seconds
2021-01-11 18:31:40 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.030 seconds
2021-01-11 18:31:40 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.031 seconds
2021-01-11 18:31:45 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.002 seconds
2021-01-11 18:31:45 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.003 seconds
2021-01-11 18:31:50 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.011 seconds
2021-01-11 18:31:50 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.014 seconds
2021-01-11 18:31:55 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.009 seconds
2021-01-11 18:31:55 DEBUG (MainThread) [custom_components.keymaster] Finished fetching keymaster data in 0.010 seconds

Screenshots

Additional context I configured the integration, and made sure that allow_automation_execution and system_ready are both on. However after adding a code and enabling it, the integration doesn't appear to even attempt to set the code, and the PIn Status stays 'Connecting'. I dont see anything in the logs.

firstof9 commented 3 years ago

@raman325 shouldn't there be more debug messages?

raman325 commented 3 years ago

yes there should. @mcowger are you using ozw or zwave? I'm guessing zwave because looking at the code you may not see additional debug messages for that code path.

Do you have usercodes already set? If so, can you also check the created sensors (sensor._codeslot<slot#>) and verify whether or not they are showing anything for the usercodes that you've already set?

mcowger commented 3 years ago

zwave.

I know the docs prefer ozw, but ozw is not stable for me, nor does it support my devices.

I do have user codes set, but the integration did not pick them up.

Looking at the OZW logs, I see no attempts to communicate with the locks besides ones that I manually initiated.

Is there an automation or something I can execute to make key master try to do something?

raman325 commented 3 years ago

I'm confused by your statement. You are using zwave but you are checking OZW logs. The zwave integration doesn't require a separate OZW instance, so any logging would be done directly to the Home Assistant log. Is what what you are referring to?

The primary problem is that the integration is not picking up your user codes, so the automations won't do anything. The fact that you are only seeing the debug logs for fetching the data means that the integration is not able to query the lock entity. I have been primarily testing the OZW version of the integration because that's what I use, but I will try to switch to the zwave integration to see if I can reproduce. In the meantime, can you confirm that zwave is enabled and ozw is disabled?

raman325 commented 3 years ago

also can you try running the lock.clear_usercode service on the code slot before you attempt to set it? Or use a code slot that hasn't been set already.

mcowger commented 3 years ago

I am using the zwave integration, not the ozw/mqtt design. The zwave integration still uses OpenZwave under the hood (1.4), and still produces a OZW_Log.txt file, which is what I’m references.

I ran a quick test with a never before used code slot, and the behavior is not different.

As a hint, I am seeing some errors from the automation logs about not being able to Concat an int with a str, but it doesn’t narrow it down to a specific automation. That being said I’ve never had that error on my own automations, and I know that some of the states in ozw are integers rather than strings. Not sure if that helps.

raman325 commented 3 years ago

Thanks for the clarification.

That does help, I just pushed a fix for that (I hope) here: https://github.com/FutureTense/keymaster/pull/27. Try updating to the latest version of keymaster, regenerating your package files using the keymaster.generate_packages service, and then restarting your HA instance to pick up the change and see if that resolves things, although I don't think it's related to the primary issue you are having

mcowger commented 3 years ago

I updated last night - I dont think the concat issue is fixed, as I still have errors:

2021-01-13 08:35:55 ERROR (MainThread) [homeassistant.helpers.condition] Error during template condition: TypeError: can only concatenate str (not "int") to str

raman325 commented 3 years ago

At some point you commented about a KeyError but it looks like it's deleted. Are you still seeing that error?

Regarding the string concatenation error, I can't see any other places where this error could occur. Can you confirm that you regenerated the package files and restarted HA to pick up the new package templates? Keep in mind that you need to pass lockname in as a parameter during the service call, otherwise the service won't work

mcowger commented 3 years ago

The KeyError was due to not having the zwave stick properly attached. Disappeared when I put it back on the machine 🤪.

I did regen and restart.

On Wed, Jan 13, 2021 at 9:55 AM Raman Gupta notifications@github.com wrote:

At some point you commented about a KeyError but it looks like it's deleted. Are you still seeing that error?

Regarding the string concatenation error, I can't see any other places where this error could occur. Can you confirm that you regenerated the package files and restarted HA to pick up the new package templates?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/FutureTense/keymaster/issues/25#issuecomment-759616462, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAOXCTDLKXNT3RHWB3OL7MTSZXNBZANCNFSM4V6QWG3Q .

-- -- Matt

raman325 commented 3 years ago

Keep in mind that you need to pass lockname in as a parameter during the service call, otherwise the service won't work.

I didn't have time to try getting the zwave integration up yesterday. Will hopefully have time today so I can try to reproduce.

mcowger commented 3 years ago

Yea, I passed in the lock name to the service call for both locks I have.

On Wed, Jan 13, 2021 at 10:04 AM Raman Gupta notifications@github.com wrote:

Keep in mind that you need to pass lockname in as a parameter during the service call, otherwise the service won't work.

I didn't have time to try getting the zwave integration up yesterday. Will hopefully have time today so I can try to reproduce.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/FutureTense/keymaster/issues/25#issuecomment-759621656, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAOXCTGDJXDB235MFQRO57DSZXOB7ANCNFSM4V6QWG3Q .

-- -- Matt

raman325 commented 3 years ago

damn, I was hoping I'd find an easy fix that would get us past this. Will let you know what I find when I've had time to try to test this myself

raman325 commented 3 years ago

try the latest update. It looks like the service logic was wrong

mcowger commented 3 years ago

Does not appear to have corrected the issue.

I'm still seeing concatenation errors (after rerunning generate packages and restarting HA)

Screen Shot 2021-01-13 at 2 43 23 PM

and it still isn't setting lock codes. I clicked the 'enable' button on a net new code/untouched code slot where it says "HERE" in the logs:

Screen Shot 2021-01-13 at 2 44 25 PM
firstof9 commented 3 years ago

What lock brand/model are you using? When you enable the slot does the OZW_Log.txt show any SetUserCode_Cmd or any kind of lock commands?

mcowger commented 3 years ago

https://shopyalehome.com/collections/keypad-locks/products/yale-assure-lock-touchscreen?variant=28400473079908

^^ That lock (the Zwave Plus Variant). Setting user codes via the standard method (Integrations Panel|Configure Zwave) works fine, and results in a flurry of messages about setting the code (as expected).

Upon enabling or disabling a code via keymaster (through the Enabled check in lovelace), no messages are generated in OZW_Log.txt, nor any indication in home_assistant.log that anything is being attempted even.

firstof9 commented 3 years ago

All right, that helps narrow it down, thanks.

firstof9 commented 3 years ago

When you have debugging enabled do you see a entry: Attempting to call set_usercode... ?

mcowger commented 3 years ago

I do not:

config $ grep -c "Attempting to call" home-assistant.log
0
config $ grep -c "keymaster" home-assistant.log
67688
config $
firstof9 commented 3 years ago

Thank you.

mcowger commented 3 years ago

Some additional information:

If I manually run the syncronize_codeslot automation, the errors show up:

2021-01-18 08:56:43 INFO (MainThread) [homeassistant.components.automation.synchronize_codeslot_frontdoor_1] synchronize_codeslot_frontdoor_1: Running automation actions
2021-01-18 08:56:43 INFO (MainThread) [homeassistant.components.automation.synchronize_codeslot_frontdoor_1] synchronize_codeslot_frontdoor_1: Choose at step 1: choice 1: Running automation actions
2021-01-18 08:56:43 INFO (MainThread) [homeassistant.components.automation.synchronize_codeslot_frontdoor_1] synchronize_codeslot_frontdoor_1: Choose at step 1: choice 1: Executing step call service
2021-01-18 08:56:43 DEBUG (MainThread) [custom_components.keymaster] Add Code service: <ServiceCall keymaster.add_code (c:e8b77b437967ab2e0ae5fe8508123bb1): entity_id=lock.front_door_lock_new_frontdoor, code_slot=1, usercode=XXXX>
2021-01-18 08:56:43 DEBUG (MainThread) [custom_components.keymaster.services] Attempting to call set_usercode...
2021-01-18 08:56:43 ERROR (MainThread) [homeassistant.components.automation.synchronize_codeslot_frontdoor_1] synchronize_codeslot_frontdoor_1: Choose at step 1: choice 1: Error executing script. Unexpected error for call_service at pos 1: A Z-Wave integration has not been configured for this Home Assistant instance
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 250, in _async_step
    await getattr(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 457, in _async_call_service_step
    await service_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1445, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1480, in _execute_service
    await handler.job.target(service_call)
  File "/config/custom_components/keymaster/__init__.py", line 157, in _add_code
    await add_code(hass, entity_id, code_slot, usercode)
  File "/config/custom_components/keymaster/services.py", line 99, in add_code
    raise ZWaveIntegrationNotConfiguredError
custom_components.keymaster.exceptions.ZWaveIntegrationNotConfiguredError: A Z-Wave integration has not been configured for this Home Assistant instance
2021-01-18 08:56:43 ERROR (MainThread) [homeassistant.components.automation.synchronize_codeslot_frontdoor_1] synchronize_codeslot_frontdoor_1: Error executing script. Unexpected error for choose at pos 1: A Z-Wave integration has not been configured for this Home Assistant instance
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 250, in _async_step
    await getattr(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 596, in _async_choose_step
    await self._async_run_script(script)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 670, in _async_run_script
    await self._async_run_long_action(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 419, in _async_run_long_action
    long_task.result()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1026, in async_run
    await asyncio.shield(run.async_run())
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 242, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 250, in _async_step
    await getattr(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 457, in _async_call_service_step
    await service_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1445, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1480, in _execute_service
    await handler.job.target(service_call)
  File "/config/custom_components/keymaster/__init__.py", line 157, in _add_code
    await add_code(hass, entity_id, code_slot, usercode)
  File "/config/custom_components/keymaster/services.py", line 99, in add_code
    raise ZWaveIntegrationNotConfiguredError
custom_components.keymaster.exceptions.ZWaveIntegrationNotConfiguredError: A Z-Wave integration has not been configured for this Home Assistant instance
2021-01-18 08:56:43 ERROR (MainThread) [homeassistant.components.automation.synchronize_codeslot_frontdoor_1] While executing automation automation.synchronize_codeslot_frontdoor_1
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/automation/__init__.py", line 404, in async_trigger
    await self.action_script.async_run(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1026, in async_run
    await asyncio.shield(run.async_run())
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 242, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 250, in _async_step
    await getattr(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 596, in _async_choose_step
    await self._async_run_script(script)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 670, in _async_run_script
    await self._async_run_long_action(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 419, in _async_run_long_action
    long_task.result()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1026, in async_run
    await asyncio.shield(run.async_run())
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 242, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 250, in _async_step
    await getattr(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 457, in _async_call_service_step
    await service_task
  File "/usr/src/homeassistant/homeassistant/core.py", line 1445, in async_call
    task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1480, in _execute_service
    await handler.job.target(service_call)
  File "/config/custom_components/keymaster/__init__.py", line 157, in _add_code
    await add_code(hass, entity_id, code_slot, usercode)
  File "/config/custom_components/keymaster/services.py", line 99, in add_code
    raise ZWaveIntegrationNotConfiguredError
custom_components.keymaster.exceptions.ZWaveIntegrationNotConfiguredError: A Z-Wave integration has not been configured for this Home Assistant instance
tankdeer commented 3 years ago

Chiming in to say I am getting the same exceptions as the OP. Using the OG zwave integration as well

firstof9 commented 3 years ago

So you both are getting A Z-Wave integration has not been configured for this Home Assistant instance ?

tankdeer commented 3 years ago

Yes. To add to that, I just did a restart, and saw this in my log:

2021-01-18 10:45:44 ERROR (MainThread) [custom_components.keymaster] Unexpected error fetching keymaster data: 'node_id'
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 144, in async_refresh
    self.data = await self._async_update_data()
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 132, in _async_update_data
    return await self.update_method()
  File "/config/custom_components/keymaster/__init__.py", line 420, in async_update_usercodes
    return await self.hass.async_add_executor_job(self.update_usercodes)
  File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/config/custom_components/keymaster/__init__.py", line 435, in update_usercodes
    node_id = get_node_id(self.hass, self._lock.lock_entity_id)
  File "/config/custom_components/keymaster/helpers.py", line 58, in get_node_id
    return state.attributes[ATTR_NODE_ID]
KeyError: 'node_id'
2021-01-18 10:45:44 ERROR (MainThread) [custom_components.keymaster] Unexpected error fetching keymaster data: 'node_id'
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 144, in async_refresh
    self.data = await self._async_update_data()
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 132, in _async_update_data
    return await self.update_method()
  File "/config/custom_components/keymaster/__init__.py", line 420, in async_update_usercodes
    return await self.hass.async_add_executor_job(self.update_usercodes)
  File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/config/custom_components/keymaster/__init__.py", line 435, in update_usercodes
    node_id = get_node_id(self.hass, self._lock.lock_entity_id)
  File "/config/custom_components/keymaster/helpers.py", line 58, in get_node_id
    return state.attributes[ATTR_NODE_ID]
KeyError: 'node_id'

Based on the timestamp it seems like zwave hadn't fully started yet. The allow_automation input boolean was not set until nearly 5 minutes afterwards

mcowger commented 3 years ago

I get those same errors until zwave starts up.

On Mon, Jan 18, 2021 at 11:11 AM tankdeer notifications@github.com wrote:

Yes. To add to that, I just did a restart, and saw this in my log:

2021-01-18 10:45:44 ERROR (MainThread) [custom_components.keymaster] Unexpected error fetching keymaster data: 'node_id' Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 144, in async_refresh self.data = await self._async_update_data() File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 132, in _async_update_data return await self.update_method() File "/config/custom_components/keymaster/init.py", line 420, in async_update_usercodes return await self.hass.async_add_executor_job(self.update_usercodes) File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 57, in run result = self.fn(*self.args, *self.kwargs) File "/config/custom_components/keymaster/init.py", line 435, in update_usercodes node_id = get_node_id(self.hass, self._lock.lock_entity_id) File "/config/custom_components/keymaster/helpers.py", line 58, in get_node_id return state.attributes[ATTR_NODE_ID] KeyError: 'node_id' 2021-01-18 10:45:44 ERROR (MainThread) [custom_components.keymaster] Unexpected error fetching keymaster data: 'node_id' Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 144, in async_refresh self.data = await self._async_update_data() File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 132, in _async_update_data return await self.update_method() File "/config/custom_components/keymaster/init.py", line 420, in async_update_usercodes return await self.hass.async_add_executor_job(self.update_usercodes) File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 57, in run result = self.fn(self.args, **self.kwargs) File "/config/custom_components/keymaster/init.py", line 435, in update_usercodes node_id = get_node_id(self.hass, self._lock.lock_entity_id) File "/config/custom_components/keymaster/helpers.py", line 58, in get_node_id return state.attributes[ATTR_NODE_ID] KeyError: 'node_id'

Based on the timestamp it seems like zwave hadn't fully started yet. The allow_automation input boolean was not set until nearly 5 minutes afterwards

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/FutureTense/keymaster/issues/25#issuecomment-762426897, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAOXCTAVUSJKER2LZWPLTYLS2SBU3ANCNFSM4V6QWG3Q .

-- -- Matt

firstof9 commented 3 years ago

Does the problem persist after zwave has fully loaded?

mcowger commented 3 years ago

The node_id errors disappear after the zwave integration becomes ready.

On Tue, Jan 19, 2021 at 1:53 PM Chris notifications@github.com wrote:

Does the problem persist after zwave has fully loaded?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/FutureTense/keymaster/issues/25#issuecomment-763165813, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAOXCTFRCPAUKLAKQ2H7SR3S2X5O7ANCNFSM4V6QWG3Q .

-- -- Matt

firstof9 commented 3 years ago

And after zwave has become ready are you able to add/remove codes?

tankdeer commented 3 years ago

In my case, no.

The node_id errors appear during startup. The ZWaveIntegrationNotConfiguredError errors appear when trying to synchronize the code slots (after zwave has started).

I've only had it installed a few days but at no point have I ever been able to add/remove/sync codes.

firstof9 commented 3 years ago

The node_id errors appear during startup. The ZWaveIntegrationNotConfiguredError errors appear when trying to synchronize the code slots (after zwave has started).

Your issue is different, please create a separate issue. Thanks.

tankdeer commented 3 years ago

The node_id errors appear during startup. The ZWaveIntegrationNotConfiguredError errors appear when trying to synchronize the code slots (after zwave has started).

Your issue is different, please create a separate issue. Thanks.

You sure? I am receiving the same exceptions that the OP is, and I can't set any codes

holman commented 3 years ago

I'm in this boat, too. I have a Schlage, and I'm getting the same errors:

Unexpected error fetching keymaster data:

In my case, it's just blank after data:; the node_id part isn't there for me. After zwave starts up, it appears to not print that warning for me anymore (I get the regular Finished fetching keymaster data in 0.001 seconds messages.)

If I try a manual code synchronization, I also get the instance error:

Choose at step 1: choice 1: Error executing script. Unexpected error for call_service at pos 1: A Z-Wave integration has not been configured for this Home Assistant instance

Doesn't look like I can set or reset any codes. The state of each code is always in either a "Connecting" or "Disconnecting" status.

firstof9 commented 3 years ago

@raman325 perhaps there's a status in zwave we could monitor to assure the network's ready as well? I'll have a look in the morning myself as well.

raman325 commented 3 years ago

we can watch this event: https://github.com/home-assistant/core/blob/dev/homeassistant/components/zwave/__init__.py#L588

holman commented 3 years ago

For what it's worth, I updated to the latest changes and regenerated everything and I'm still getting the same errors and I'm still not able to set a usercode.

raman325 commented 3 years ago

I think I figured out the issue (or at least one of them). We check for if the zwave domain is in hass.data but I don't see any logic in the zwave integration that sets that. We can check for another key to figure out if zwave is set. PR linked below

raman325 commented 3 years ago

Please note when you update to the latest version of keymaster that some things have changed. In addition to regenerating your package files, you will need to re-add the pre-installation file from here: https://github.com/FutureTense/keymaster/wiki/Pre-Installation-Steps-(IMPORTANT) since the automation names have changed. Apologies for all the changes, it's meant to make things easier to maintain going forward

holman commented 3 years ago

Okay- it's looking a lot closer!

I'm seeing a lot more debug in the logs than I did before, so that's great. It also looks like I can reset my user code; toggling "reset code slot" correctly moves me into the Disconnected status as well as setting "PIN synchronized with lock" to true.

Setting/changing the user code doesn't seem to work yet, though. Status still stays as Connecting, and it generates an error in the logs:

2021-01-21 00:41:28 ERROR (MainThread) [homeassistant.helpers.condition] Error during template condition: TypeError: can only concatenate str (not "list") to str

...but that's way more promising than what I had before! :)

raman325 commented 3 years ago

can you check the user code sensors? are you getting any data for them?

holman commented 3 years ago

Doesn't look like it:

2021-01-21 01:26:15 DEBUG (MainThread) [custom_components.keymaster] Add Code service: <ServiceCall keymaster.add_code (c:efdbc9f35346f22e742857278f78d76b): entity_id=lock.front_door, code_slot=1, usercode=1234>
2021-01-21 01:26:15 DEBUG (MainThread) [custom_components.keymaster.services] Attempting to call set_usercode...

...then it seems to retrieve what the current code in that slot is:

2021-01-21 01:26:23 DEBUG (SyncWorker_5) [custom_components.keymaster] DEBUG: Code slot 1 value: <CURRENT_CODE>
holman commented 3 years ago

(And when I try to set it I still get the error:)

2021-01-21 01:29:23 ERROR (MainThread) [homeassistant.helpers.condition] Error during template condition: TypeError: can only concatenate str (not "list") to str
raman325 commented 3 years ago

sorry, so are you saying that sensor._code_slot_1 does have a value set for it? Or does it not? The debug statement that logs the current code implies that its set, but if you aren't seeing it in the sensor (check Dev Tools > States) then perhaps there is an issue with the data being passed to the sensor.

raman325 commented 3 years ago

I made progress on the template error. Pushing a fix.

holman commented 3 years ago

Oooh, I see what you mean now. Yes, since the recent changes it does have a value now.

raman325 commented 3 years ago

OK try clicking on "Update Information" action on the keymaster card in HACS so it grabs the latest update, then try pulling it down and regenerating package files, then restarting - it should eliminate the template error. Then try disabling the slot so it gets cleared, then re-enabling it, and see if it will show as connected.

raman325 commented 3 years ago

the action I am referring to: image

holman commented 3 years ago

Yes! It basically works!

The code gets reset, set, changed, and everything correctly. The only reason I include "basically" is because when I initially set the code it correctly sets the "PIN synchronized" bool to on, and I think that does everything correctly (and is in the Disconnected state). When I flip the toggle to enable the new code, it stays in the Connecting state. But again, it seems to be updating the code correctly, so that's all good- just the UI confusion now.

(Also thanks to you and everyone who works on this- all the smart locks are really complicated, and trying to shoehorn all the support in one plugin is a big feat; much appreciated!)

tankdeer commented 3 years ago

Ok. I think I am in the same boat. Re: basically working. Same UI issues as @holman, and it did actually set the PIN

I did have some issues with the generation though. I am not sure if they are related to the most recent submissions or not. I have two locks. One appeared to generate fine, the other didn't. None of the yaml for the second was generated at all. In fact, it hasn't changed since installation. No errors or debug in the log when doing so

Upon restarting, I still seem to get one error regarding node_id. I can only assume it's for the lock that I can't regenerate code for:

2021-01-20 18:11:28 ERROR (MainThread) [custom_components.keymaster] Unexpected error fetching keymaster data: 'node_id'
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 144, in async_refresh
    self.data = await self._async_update_data()
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 132, in _async_update_data
    return await self.update_method()
  File "/config/custom_components/keymaster/__init__.py", line 427, in async_update_usercodes
    return await self.hass.async_add_executor_job(self.update_usercodes)
  File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/config/custom_components/keymaster/__init__.py", line 442, in update_usercodes
    node_id = get_node_id(self.hass, self._lock.lock_entity_id)
  File "/config/custom_components/keymaster/helpers.py", line 58, in get_node_id
    return state.attributes[ATTR_NODE_ID]
KeyError: 'node_id'

Right after, I receive these errors, which are definitely new

2021-01-20 18:14:57 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/config/custom_components/keymaster/__init__.py", line 221, in async_entity_state_listener
    handle_state_change(hass, config_entry, changed_entity, old_state, new_state)
  File "/config/custom_components/keymaster/helpers.py", line 201, in handle_state_change
    and dt.utcnow() - alarm_type_state.last_changed.replace(tzinfo=None)
TypeError: can't subtract offset-naive and offset-aware datetimes
2021-01-20 18:15:19 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/config/custom_components/keymaster/__init__.py", line 221, in async_entity_state_listener
    handle_state_change(hass, config_entry, changed_entity, old_state, new_state)
  File "/config/custom_components/keymaster/helpers.py", line 201, in handle_state_change
    and dt.utcnow() - alarm_type_state.last_changed.replace(tzinfo=None)
TypeError: can't subtract offset-naive and offset-aware datetimes
2021-01-20 18:15:20 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/config/custom_components/keymaster/__init__.py", line 221, in async_entity_state_listener
    handle_state_change(hass, config_entry, changed_entity, old_state, new_state)
  File "/config/custom_components/keymaster/helpers.py", line 201, in handle_state_change
    and dt.utcnow() - alarm_type_state.last_changed.replace(tzinfo=None)
TypeError: can't subtract offset-naive and offset-aware datetimes
2021-01-20 18:15:54 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/config/custom_components/keymaster/__init__.py", line 221, in async_entity_state_listener
    handle_state_change(hass, config_entry, changed_entity, old_state, new_state)
  File "/config/custom_components/keymaster/helpers.py", line 201, in handle_state_change
    and dt.utcnow() - alarm_type_state.last_changed.replace(tzinfo=None)
TypeError: can't subtract offset-naive and offset-aware datetimes
2021-01-20 18:15:55 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/config/custom_components/keymaster/__init__.py", line 221, in async_entity_state_listener
    handle_state_change(hass, config_entry, changed_entity, old_state, new_state)
  File "/config/custom_components/keymaster/helpers.py", line 201, in handle_state_change
    and dt.utcnow() - alarm_type_state.last_changed.replace(tzinfo=None)
TypeError: can't subtract offset-naive and offset-aware datetimes

Lastly, I was testing the lock that does work, and figured I would test the notifications. Looks like maybe the codegen for that one didn't fully work either, as the script is in fact missing:

2021-01-20 18:35:38 ERROR (MainThread) [homeassistant.components.automation.garage_side_door_user_notifications] garage_side_door User Notifications: Error executing script. Service not found for call_service at pos 1: Unable to find service script.garage_side_door_manual_notify
2021-01-20 18:35:38 ERROR (MainThread) [homeassistant.components.automation.garage_side_door_user_notifications] While executing automation automation.garage_side_door_user_notifications
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/automation/__init__.py", line 404, in async_trigger
    await self.action_script.async_run(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1026None, in async_run
    await asyncio.shield(run.async_run())
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 242, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 250, in _async_step
    await getattr(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 460, in _async_call_service_step
    await self._async_run_long_action(service_task)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 419, in _async_run_long_action
    long_task.result()
  File "/usr/src/homeassistant/homeassistant/core.py", line 1395, in async_call
    raise ServiceNotFound(domain, service) from None
homeassistant.exceptions.ServiceNotFound: Unable to find service script.garage_side_door_manual_notify

Good progress though, and as mentioned, it's definitely appreciated.

raman325 commented 3 years ago

I need to look more into why your sensor never gets to the "Connected" state like mine does. The good news it appears that everything is functional except the status which is just there for your peace of mind.

@tankdeer - Issue 1 - do you see this error over and over or just at the beginning? There appears to be a timing issue with when we attempt to get data and when the zwave data becomes available, but that should be OK and it should recover quickly and stop failing once HA has started.

Issue 2 - I think I have a fix for this which i am pushing shortly I just pushed. Let me know if it helps because I don't have this error on my system so it must be a difference in our configs.

Issue 3 - this is expected, see here for an example of how to create the manual_notify script for your needs: https://github.com/FutureTense/keymaster/wiki/Notification-Example-Script. The crux of the problem with notify is that you need to specify the notify service and payload since they differ depending on what you use.

Finally, regarding the file generation, you will need to trigger the generation manually using the keymaster.generate_packages service as the integration isn't smart enough to know when it needs to regenerate them. When you call that service, be sure to pass the lock name (all lowercase and with underscores instead of spaces, basically what you see in the entity names). Let me know if that helps or if you are still having issues with this and we can try to troubleshoot further