Exception: Operation already in progress: please wait when try to operate the lock

[qbasasa]

I have some weird issue when i try to open/close lock i get: Logger: homeassistant.components.websocket_api.http.connection Source: custom_components/airbnk_mqtt/cover.py:125 Integration: Home Assistant WebSocket API (documentation, issues) First occurred: 17:01:14 (3 occurrences) Last logged: 20:33:38

[140529707573008] Operation already in progress: please wait Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 185, in handle_call_service await hass.services.async_call( File "/usr/src/homeassistant/homeassistant/core.py", line 1495, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1530, in _execute_service await handler.job.target(service_call) File "/usr/src/homeassistant/homeassistant/components/script/init.py", line 273, in service_handler await script_entity.async_turn_on( File "/usr/src/homeassistant/homeassistant/components/script/init.py", line 377, in async_turn_on await coro File "/usr/src/homeassistant/homeassistant/components/script/init.py", line 403, in _async_run return await self.script.async_run(script_vars, context) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1260, in async_run await asyncio.shield(run.async_run()) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 363, in async_run await self._async_step(log_exceptions=False) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 381, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 584, in _async_call_service_step await service_task File "/usr/src/homeassistant/homeassistant/core.py", line 1495, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1530, in _execute_service await handler.job.target(service_call) File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 209, in handle_service await self.hass.helpers.service.entity_service_call( File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 663, in entity_service_call future.result() # pop exception if have File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 896, in async_request_call await coro File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 700, in _handle_entity_call await result File "/config/custom_components/airbnk_mqtt/cover.py", line 125, in async_close_cover raise Exception("Operation already in progress: please wait") Exception: Operation already in progress: please wait

And in Integration i get something like that it looks as it's the cause:

Logger: custom_components.airbnk_mqtt.custom_device Source: custom_components/airbnk_mqtt/custom_device.py:269 Integration: Airbnk lock (MQTT-based) (documentation, issues) First occurred: 17:00:48 (1 occurrences) Last logged: 17:00:48

Wrong lockStatus msg: AA00040000060600000000000000000000000000

Only way to fix this is to restart Homeassistant, rebooting the BLE dongle doesnt help.

Ha version i have is: Home Assistant 2021.12.8

Sorry its me again :(

[rospogrigio]

Don't worry @qbasasa , it's good to find problems and to solve them! I also had entered such a situation several days ago, and with your debug messages I might have understood what's wrong: can you please try PR #15 and let me know if it fixes the issue? Assuming that your behavior can be repeatable of course. Let me know, thanks!

[qbasasa]

Thanks, i will try. I've updated the integration now.

[qbasasa]

It still sometime freezes but, it recovers after some time without rebooting everything. Maybe below will help some other new error :) It was in between: Unexpected error for device at pos 1: Operation already in progress: please wait and No more retries: command FAILED Wrong lockStatus msg: AA00040000060600000000000000000000000000

` Logger: homeassistant.util.logging Source: util/logging.py:105 First occurred: 16:21:51 (4 occurrences) Last logged: 16:22:52

Exception in operation_msg_received when handling msg on 'airbnk_lock/command_result': '{"success":true,"error":"","sign":123,"mac":"1234","lockStatus":"AA00040000060600000000000000000000000000"}' Traceback (most recent call last): File "/config/custom_components/airbnk_mqtt/custom_device.py", line 150, in operation_msg_received self.parse_operation_message(_p0.payload) File "/config/custom_components/airbnk_mqtt/custom_device.py", line 238, in parse_operation_message self.parse_new_lockStatus(payload["lockStatus"]) File "/config/custom_components/airbnk_mqtt/custom_device.py", line 285, in parse_new_lockStatus raise Exception( Exception: ('Failed sending command: received status %s', 'AA00040000060600000000000000000000000000') Exception in operation_msg_received when handling msg on 'airbnk_lock/command_result': '{"success":true,"error":"","sign":1234,"mac":"1234","lockStatus":"AA00040000060600000000000000000000000000"}' Traceback (most recent call last): File "/config/custom_components/airbnk_mqtt/custom_device.py", line 150, in operation_msg_received self.parse_operation_message(_p0.payload) File "/config/custom_components/airbnk_mqtt/custom_device.py", line 238, in parse_operation_message self.parse_new_lockStatus(payload["lockStatus"]) File "/config/custom_components/airbnk_mqtt/custom_device.py", line 285, in parse_new_lockStatus raise Exception( Exception: ('Failed sending command: received status %s', 'AA00040000060600000000000000000000000000') Exception in operation_msg_received when handling msg on 'airbnk_lock/command_result': '{"success":true,"error":"","sign":1234,"mac":"1234","lockStatus":"AA00040000060600000000000000000000000000"}' Traceback (most recent call last): File "/config/custom_components/airbnk_mqtt/custom_device.py", line 150, in operation_msg_received self.parse_operation_message(_p0.payload) File "/config/custom_components/airbnk_mqtt/custom_device.py", line 238, in parse_operation_message self.parse_new_lockStatus(payload["lockStatus"]) File "/config/custom_components/airbnk_mqtt/custom_device.py", line 285, in parse_new_lockStatus raise Exception( Exception: ('Failed sending command: received status %s', 'AA00040000060600000000000000000000000000') Exception in operation_msg_received when handling msg on 'airbnk_lock/command_result': '{"success":true,"error":"","sign":1234,"mac":"1234","lockStatus":"AA00040000060600000000000000000000000000"}' Traceback (most recent call last): File "/config/custom_components/airbnk_mqtt/custom_device.py", line 150, in operation_msg_received self.parse_operation_message(_p0.payload) File "/config/custom_components/airbnk_mqtt/custom_device.py", line 238, in parse_operation_message self.parse_new_lockStatus(payload["lockStatus"]) File "/config/custom_components/airbnk_mqtt/custom_device.py", line 285, in parse_new_lockStatus raise Exception( Exception: ('Failed sending command: received status %s', 'AA00040000060600000000000000000000000000')`

[formatBCE]

It happens because lock didn't set correct status after opening in time. Gateway tries several times to receive non-zero status from lock after sending the command to it. But after few tries, it just sends zero-status as is. Integration, however, relies on that status heavily, so it gives an error. After receiving status from next lock advertisement (it's second way to get the data) it recovers.

[qbasasa]

It worked fine but now for some reason again its getting the same problems. Again restarting HASS.IO solves the problem instantly. Does below help in any way?

---

`Logger: homeassistant.components.script.otworz_drzwi Source: custom_components/airbnk_mqtt/cover.py:125 Integration: Skrypt (documentation, issues) First occurred: 13:22:37 (7 occurrences) Last logged: 17:54:22

Otwórz Drzwi: Error executing script. Unexpected error for call_service at pos 1: Operation already in progress: please wait Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 381, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 584, in _async_call_service_step await service_task File "/usr/src/homeassistant/homeassistant/core.py", line 1495, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1530, in _execute_service await handler.job.target(service_call) File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 209, in handle_service await self.hass.helpers.service.entity_service_call( File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 663, in entity_service_call future.result() # pop exception if have File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 896, in async_request_call await coro File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 700, in _handle_entity_call await result File "/config/custom_components/airbnk_mqtt/cover.py", line 125, in async_close_cover raise Exception("Operation already in progress: please wait") Exception: Operation already in progress: please wait`

---

`Logger: homeassistant.components.script.otworz_drzwi Source: custom_components/airbnk_mqtt/cover.py:125 Integration: Skrypt (documentation, issues) First occurred: 13:22:37 (7 occurrences) Last logged: 17:54:22

Otwórz Drzwi: Error executing script. Unexpected error for call_service at pos 1: Operation already in progress: please wait Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 381, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 584, in _async_call_service_step await service_task File "/usr/src/homeassistant/homeassistant/core.py", line 1495, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1530, in _execute_service await handler.job.target(service_call) File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 209, in handle_service await self.hass.helpers.service.entity_service_call( File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 663, in entity_service_call future.result() # pop exception if have File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 896, in async_request_call await coro File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 700, in _handle_entity_call await result File "/config/custom_components/airbnk_mqtt/cover.py", line 125, in async_close_cover raise Exception("Operation already in progress: please wait") Exception: Operation already in progress: please wait`

---

`Logger: homeassistant.components.websocket_api.http.connection Source: custom_components/airbnk_mqtt/cover.py:115 Integration: Home Assistant WebSocket API (documentation, issues) First occurred: 22 stycznia 2022, 14:55:58 (4 occurrences) Last logged: 17:50:48

[140000061328880] Operation already in progress: please wait [139999872629968] Operation already in progress: please wait Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 185, in handle_call_service await hass.services.async_call( File "/usr/src/homeassistant/homeassistant/core.py", line 1495, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1530, in _execute_service await handler.job.target(service_call) File "/usr/src/homeassistant/homeassistant/components/script/init.py", line 273, in service_handler await script_entity.async_turn_on( File "/usr/src/homeassistant/homeassistant/components/script/init.py", line 377, in async_turn_on await coro File "/usr/src/homeassistant/homeassistant/components/script/init.py", line 403, in _async_run return await self.script.async_run(script_vars, context) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1260, in async_run await asyncio.shield(run.async_run()) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 363, in async_run await self._async_step(log_exceptions=False) File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 381, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 584, in _async_call_service_step await service_task File "/usr/src/homeassistant/homeassistant/core.py", line 1495, in async_call task.result() File "/usr/src/homeassistant/homeassistant/core.py", line 1530, in _execute_service await handler.job.target(service_call) File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 209, in handle_service await self.hass.helpers.service.entity_service_call( File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 663, in entity_service_call future.result() # pop exception if have File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 896, in async_request_call await coro File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 700, in _handle_entity_call await result File "/config/custom_components/airbnk_mqtt/cover.py", line 115, in async_open_cover raise Exception("Operation already in progress: please wait") Exception: Operation already in progress: please wait`

[formatBCE]

@rospogrigio I still have this issue time to time. What's worse - I have to reboot HA to get it to working state. For some integrations, there's "reload" function in options, that can reload integration without rebooting. But it's not the case for Airbnk. Reboot required.

Could you maybe make it reloadable? Then I'd make automation to reload it, if it's in "Operating" status for more than certain time. It would be workaround at least :)

Thanks.

[rospogrigio]

OK that's a nice idea, I thought I had already done it but looks like I didn't. Give me some time 'cause I'm pretty busy at work at the moment.... bye!

[rospogrigio]

I think I have done something that could be working, could you try it? It's PR #18 . Let me know!

[formatBCE]

Will do! It's a bit hard to reproduce - random thing. But solution seems cool, according to the code. Thank you!

[rospogrigio]

Well just wait for it to happen again, and when it does just try to reload and see what happens... let me know!

[chrisbakr]

Testing on M500 and the lock/unlock controls are inverted. Also if it enters into "failed" status open/close commands don't work anymore. I need to use the mobile app to open/close then the HA status updates to locked/unlocked and it works again. Any hints on how to fix this?

[chrisbakr]

It enters the "failed" status if lock is locked and I try to lock it, or unlocked and I try to unlock it.

[rospogrigio]

@cristi9flavors have you tried PR #18? Does reloading the integration solve your problem when it is in the Failed status?

[chrisbakr]

No, unfortunately reloading doesn't solve the issue

[formatBCE]

Does manual lock open/close fix it, maybe?

[royco2]

I have a similar problem, but different error;

Logger: homeassistant.components.websocket_api.http.connection Source: custom_components/airbnk_mqtt/cover.py:125 Integration: Home Assistant WebSocket API (documentation, issues) First occurred: August 9, 2023 at 8:50:33 AM (6 occurrences) Last logged: 10:38:07 PM

[140213416340304] Operation already in progress: please wait [140212985453328] Operation already in progress: please wait [140213086525264] Operation already in progress: please wait Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 205, in handle_call_service await hass.services.async_call( File "/usr/src/homeassistant/homeassistant/core.py", line 1965, in async_call response_data = await coro ^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/core.py", line 2005, in _execute_service return await cast( ^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 235, in handle_service return await service.entity_service_call( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 848, in entity_service_call response_data = task.result() # pop exception if have ^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1192, in async_request_call return await coro ^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 892, in _handle_entity_call result = await task ^^^^^^^^^^ File "/config/custom_components/airbnk_mqtt/cover.py", line 125, in async_close_cover raise Exception("Operation already in progress: please wait") Exception: Operation already in progress: please wait

[TheDescender]

@rospogrigio Hi there, I'm actually running into this same issue. The integration will either get stuck on sensor status "Failed" or "Operating". When stuck on "Failed", the integration still allows for a new command push and that will resolve the problem, but when stuck on "Operating" it won't allow for any new command to be sent, claiming an operation is already in progress.

As @formatBCE indicated, an HA reload does fix that problem, but the PR #18 update you merged into master to support integration reloading seems to not work for me on v.1.6.0. So I can't even reload the integration specifically to fix this issue.

Is there any chance you could look into this?

Here's the integeration reload log error if that helps:

Logger: homeassistant.config_entries
Source: config_entries.py:565
First occurred: 9:52:40 AM (1 occurrences)
Last logged: 9:52:40 AM

Error unloading entry Airbnk for airbnk_mqtt
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 565, in async_unload
    result = await component.async_unload_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/airbnk_mqtt/__init__.py", line 149, in async_unload_entry
    await asyncio.wait(
  File "/usr/local/lib/python3.11/asyncio/tasks.py", line 415, in wait
    raise TypeError("Passing coroutines is forbidden, use tasks explicitly.")
TypeError: Passing coroutines is forbidden, use tasks explicitly.

[rospogrigio]

Sorry but I'm not experiencing this problem since a lot of time and I won't have much time to look into this for the near future... I am sorry, but if anyone can propose a PR that fixes this I'll be happy to merge it. Sorry for not being able to be more helpful but I am undergoing a tough personal period, thank you for your understanding.

[TheDescender]

Ah ok. That's unfortunate to hear. I hope things get better for you soon. If it's not too much of a bother, @rospogrigio @formatBCE could either of you let me know if you are at least able to reload the integration without rebooting HA on your end? That way I know it's a problem specific to me and I can go from there.

[rospogrigio]

Thank you for your words, much appreciated. I have tried and there actually seems to be a problem, the first time I call the reload service nothing seems to happen, and in subsequent attempts I get the error that "the entry cannot be unloaded because it is not in a recoverable state". Probably something changed in HA since when I had introduced the reload service and we need to catch up in some way. Hope it helps debugging and finding a solution, I cannot work on this now. Thank you again

[formatBCE]

Hi @TheDescender . Sorry to hear it degraded...

I moved to new home recently, and changed the lock to Z-wave Yale. Sold Airbnk, and now don't have this integration installed, unfortunately, and no possibility to reproduce that in practice... I'm sorry, but looks like the only thing I can help with is theory. :(

[formatBCE]

@rospogrigio damn, man, I hope you recover soon. The community needs such a brilliant devs! It was pleasure working with you.

[TheDescender]

@rospogrigio Seems it was likely due to a change to the asyncio.wait function in Python 3.11. I encountered multiple other projects with the same issue. https://github.com/home-assistant/core/issues/92341 https://github.com/home-assistant/core/issues/88990

I rewrote your async_unload_entry function to this:

async def async_unload_entry(hass, config_entry):
    """Unload a config entry."""
    _LOGGER.debug("Unloading %s %s", config_entry.entry_id, config_entry.data)

    # Create a list of coroutines to be awaited
    tasks = [
        hass.config_entries.async_forward_entry_unload(config_entry, component)
        for component in COMPONENT_TYPES
    ]

    # Await each coroutine individually
    await asyncio.gather(*tasks)

    for dev_id, device in hass.data[DOMAIN][AIRBNK_DEVICES].items():
        _LOGGER.debug("Unsubscribing %s", dev_id)
        await device.mqtt_unsubscribe()

    hass.data[DOMAIN].pop(AIRBNK_DEVICES)
    # if not hass.data[DOMAIN]:
    #     hass.data.pop(DOMAIN)
    _LOGGER.debug("...done")
    return True

Instead of providing the coroutines as a list in the wait function, it assembles the list seperately and uses asyncio.gather to await all coroutines concurrently before continuing. Not sure if this has the potential to cause issues with waiting for individual list items since its a higher level wait procedure, but HA integration reloading works for me now locally.

I made a PR #37 here. Please test this yourself real quick as well if you find 5 minutes. This is literally my first time using GitHub for a project xD. Again, hope your situation improves. @formatBCE is right, would be a shame to lose you. Keep trying to find the positive moments where you can!

[rospogrigio]

Sorry guys, I just realized that I have been using for months the code in the master branch of formatBCE's repository but never merged it into my master, and that probably fixes this! I'll merge it now, then we need to update TheDescender's PR with the new changes, test everything and produce a new release. Will let you know when done.

[formatBCE]

Right, that's why I couldn't reproduce that issue for half of year...

[rospogrigio]

Sorry, too many repos, too much work... OK @TheDescender , I have done, please merge back from my master and let's check that everything is working fine.

[TheDescender]

Just so people are aware, I provided the above fix to the independent reload functionality of this integration. The fix was merged into master on 17-11-23, see PR #37 .

If you have any issues, you can @mention me, but don't expect a full solution unless I can reproduce and am bothered by the same issue.