Jump to content

Error when changing device state


glarsen

Recommended Posts

I have an odd error occurring when changing state of a relay on my TP-Link power strip.  It looks like the error occurs and the nodeserver recovers, because the programmed function continues to work.  ISY 5.3.4, Polyglot 2.2.13, Kasa 2.5.0. For your review as time permits....

2021-12-29 09:27:45,851 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=3c846a0c2bf703 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027b1a60> self.address=tplkasactl
2021-12-29 09:27:45,852 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Plug 3:check_st: is_on=False
2021-12-29 09:27:45,852 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=68ff7bc5382f01 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027c83a0> self.address=tplkasactl
2021-12-29 09:27:45,853 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Camera 5:check_st: is_on=True
2021-12-29 09:27:45,854 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=68ff7bc5382f02 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027c8730> self.address=tplkasactl
2021-12-29 09:27:45,855 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Vacuum:check_st: is_on=False
2021-12-29 09:27:45,856 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: done
2021-12-29 09:28:03,711 Controller polyinterface      DEBUG    SmartStripPlugNode:cmd_set_off: Plug 1:cmd_set_off: is_on=True
2021-12-29 09:28:03,712 Controller polyinterface      INFO     polyinterface:reportDriver: Updating Driver 3c846a0c2bf701 - ST: 0, uom: 78
2021-12-29 09:28:03,723 Controller polyinterface      ERROR    polyinterface:_parseInput: _parseInput: failed 3c846a0c2bf701.runCmd(DOF) Communication error on system:set_relay_state
Traceback (most recent call last):
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/protocol.py", line 138, in _query
    return await asyncio.wait_for(
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 494, in wait_for
    return fut.result()
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/protocol.py", line 99, in _execute_query
    packed_block_size = await self.reader.readexactly(self.BLOCK_SIZE)
  File "/usr/local/lib/python3.8/asyncio/streams.py", line 723, in readexactly
    await self._wait_for_data('readexactly')
  File "/usr/local/lib/python3.8/asyncio/streams.py", line 517, in _wait_for_data
    await self._waiter
RuntimeError: Task <Task pending name='Task-47' coro=<TPLinkSmartHomeProtocol._execute_query() running at /var/polyglot/.local/lib/python3.8/site-packages/kasa/protocol.py:99> cb=[_release_waiter(<Future pendi...8026768b0>()]>)() at /usr/local/lib/python3.8/asyncio/tasks.py:429]> got Future <Future pending> attached to a different loop
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/smartdevice.py", line 237, in _query_helper
    response = await self.protocol.query(request=request)
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/protocol.py", line 71, in query
    return await self._query(request, retry_count, timeout)
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/protocol.py", line 142, in _query
    await self.close()
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/protocol.py", line 115, in close
    writer.close()
  File "/usr/local/lib/python3.8/asyncio/streams.py", line 353, in close
    return self._transport.close()
  File "/usr/local/lib/python3.8/asyncio/selector_events.py", line 692, in close
    self._loop.call_soon(self._call_connection_lost, None)
  File "/usr/local/lib/python3.8/asyncio/base_events.py", line 719, in call_soon
    self._check_closed()
  File "/usr/local/lib/python3.8/asyncio/base_events.py", line 508, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/var/polyglot/.local/lib/python3.8/site-packages/polyinterface/polyinterface.py", line 842, in _parseInput
    self.nodes[input[key]['address']].runCmd(input[key])
  File "/var/polyglot/.local/lib/python3.8/site-packages/polyinterface/polyinterface.py", line 745, in runCmd
    fun(self, command)
  File "/var/polyglot/nodeservers/Kasa/nodes/SmartStripPlugNode.py", line 57, in cmd_set_off
    asyncio.run(self.dev.turn_off())
  File "/usr/local/lib/python3.8/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/usr/local/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/smartplug.py", line 57, in turn_off
    return await self._query_helper("system", "set_relay_state", {"state": 0})
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/smartstrip.py", line 268, in _query_helper
    return await self.parent._query_helper(
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/smartdevice.py", line 239, in _query_helper
    raise SmartDeviceException(f"Communication error on {target}:{cmd}") from ex
kasa.exceptions.SmartDeviceException: Communication error on system:set_relay_state
2021-12-29 09:28:15,711 Controller polyinterface      DEBUG    Controller:shortPoll: thread=<Thread(shortPoll, started daemon 34408083456)> event=<threading.Event object at 0x8026766a0>
2021-12-29 09:28:15,713 Controller polyinterface      DEBUG    Controller:shortPoll: calling event.set
2021-12-29 09:28:15,713 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: start
2021-12-29 09:28:15,714 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=controller node.address=<nodes.Controller.Controller object at 0x8026602b0> self.address=tplkasactl
2021-12-29 09:28:15,715 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=tplkasactl node.address=<nodes.Controller.Controller object at 0x8026602b0> self.address=tplkasactl
2021-12-29 09:28:15,716 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=3c846a0c2bf7 node.address=<nodes.SmartStripNode.SmartStripNode object at 0x802676f70> self.address=tplkasactl
2021-12-29 09:28:15,718 shortPoll  kasa.protocol      WARNING  protocol:_detect_event_loop_change: Detected protocol reuse between different event loop
2021-12-29 09:28:15,744 shortPoll  polyinterface      INFO     polyinterface:reportDriver: Updating Driver 3c846a0c2bf7 - ST: 0, uom: 78
2021-12-29 09:28:15,746 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=68ff7bc5382f node.address=<nodes.SmartStripNode.SmartStripNode object at 0x802676eb0> self.address=tplkasactl
2021-12-29 09:28:15,755 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=3c846a0c2bf701 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027b1a30> self.address=tplkasactl
2021-12-29 09:28:15,757 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Plug 1:check_st: is_on=False
2021-12-29 09:28:15,758 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=3c846a0c2bf702 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027b1af0> self.address=tplkasactl
2021-12-29 09:28:15,758 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Plug 2:check_st: is_on=False
2021-12-29 09:28:15,759 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=3c846a0c2bf703 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027b1a60> self.address=tplkasactl
2021-12-29 09:28:15,760 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Plug 3:check_st: is_on=False
2021-12-29 09:28:15,761 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=68ff7bc5382f01 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027c83a0> self.address=tplkasactl
2021-12-29 09:28:15,761 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Camera 5:check_st: is_on=True
2021-12-29 09:28:15,762 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=68ff7bc5382f02 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027c8730> self.address=tplkasactl
2021-12-29 09:28:15,763 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Vacuum:check_st: is_on=False
2021-12-29 09:28:15,764 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: done
2021-12-29 09:28:43,729 Controller polyinterface      DEBUG    SmartStripPlugNode:cmd_set_on: Plug 1:cmd_set_on: is_on=False
2021-12-29 09:28:43,730 Controller polyinterface      INFO     polyinterface:reportDriver: Updating Driver 3c846a0c2bf701 - ST: 100, uom: 78
2021-12-29 09:28:43,741 Controller polyinterface      ERROR    polyinterface:_parseInput: _parseInput: failed 3c846a0c2bf701.runCmd(DON) Communication error on system:set_relay_state
Traceback (most recent call last):
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/protocol.py", line 138, in _query
    return await asyncio.wait_for(
  File "/usr/local/lib/python3.8/asyncio/tasks.py", line 494, in wait_for
    return fut.result()
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/protocol.py", line 99, in _execute_query
    packed_block_size = await self.reader.readexactly(self.BLOCK_SIZE)
  File "/usr/local/lib/python3.8/asyncio/streams.py", line 723, in readexactly
    await self._wait_for_data('readexactly')
  File "/usr/local/lib/python3.8/asyncio/streams.py", line 517, in _wait_for_data
    await self._waiter
RuntimeError: Task <Task pending name='Task-57' coro=<TPLinkSmartHomeProtocol._execute_query() running at /var/polyglot/.local/lib/python3.8/site-packages/kasa/protocol.py:99> cb=[_release_waiter(<Future pendi...8027d02e0>()]>)() at /usr/local/lib/python3.8/asyncio/tasks.py:429]> got Future <Future pending> attached to a different loop
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/smartdevice.py", line 237, in _query_helper
    response = await self.protocol.query(request=request)
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/protocol.py", line 71, in query
    return await self._query(request, retry_count, timeout)
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/protocol.py", line 142, in _query
    await self.close()
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/protocol.py", line 115, in close
    writer.close()
  File "/usr/local/lib/python3.8/asyncio/streams.py", line 353, in close
    return self._transport.close()
  File "/usr/local/lib/python3.8/asyncio/selector_events.py", line 692, in close
    self._loop.call_soon(self._call_connection_lost, None)
  File "/usr/local/lib/python3.8/asyncio/base_events.py", line 719, in call_soon
    self._check_closed()
  File "/usr/local/lib/python3.8/asyncio/base_events.py", line 508, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/var/polyglot/.local/lib/python3.8/site-packages/polyinterface/polyinterface.py", line 842, in _parseInput
    self.nodes[input[key]['address']].runCmd(input[key])
  File "/var/polyglot/.local/lib/python3.8/site-packages/polyinterface/polyinterface.py", line 745, in runCmd
    fun(self, command)
  File "/var/polyglot/nodeservers/Kasa/nodes/SmartStripPlugNode.py", line 52, in cmd_set_on
    asyncio.run(self.dev.turn_on())
  File "/usr/local/lib/python3.8/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/usr/local/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/smartplug.py", line 53, in turn_on
    return await self._query_helper("system", "set_relay_state", {"state": 1})
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/smartstrip.py", line 268, in _query_helper
    return await self.parent._query_helper(
  File "/var/polyglot/.local/lib/python3.8/site-packages/kasa/smartdevice.py", line 239, in _query_helper
    raise SmartDeviceException(f"Communication error on {target}:{cmd}") from ex
kasa.exceptions.SmartDeviceException: Communication error on system:set_relay_state
2021-12-29 09:28:45,735 Controller polyinterface      DEBUG    Controller:shortPoll: thread=<Thread(shortPoll, started daemon 34408083456)> event=<threading.Event object at 0x8026766a0>
2021-12-29 09:28:45,736 Controller polyinterface      DEBUG    Controller:shortPoll: calling event.set
2021-12-29 09:28:45,737 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: start
2021-12-29 09:28:45,738 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=controller node.address=<nodes.Controller.Controller object at 0x8026602b0> self.address=tplkasactl
2021-12-29 09:28:45,739 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=tplkasactl node.address=<nodes.Controller.Controller object at 0x8026602b0> self.address=tplkasactl
2021-12-29 09:28:45,739 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=3c846a0c2bf7 node.address=<nodes.SmartStripNode.SmartStripNode object at 0x802676f70> self.address=tplkasactl
2021-12-29 09:28:45,742 shortPoll  kasa.protocol      WARNING  protocol:_detect_event_loop_change: Detected protocol reuse between different event loop
2021-12-29 09:28:45,768 shortPoll  polyinterface      INFO     polyinterface:reportDriver: Updating Driver 3c846a0c2bf7 - ST: 100, uom: 78
2021-12-29 09:28:45,771 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=68ff7bc5382f node.address=<nodes.SmartStripNode.SmartStripNode object at 0x802676eb0> self.address=tplkasactl
2021-12-29 09:28:45,775 shortPoll  kasa.protocol      WARNING  protocol:_detect_event_loop_change: Detected protocol reuse between different event loop
2021-12-29 09:28:45,941 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=3c846a0c2bf701 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027b1a30> self.address=tplkasactl
2021-12-29 09:28:45,942 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Plug 1:check_st: is_on=True
2021-12-29 09:28:45,943 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=3c846a0c2bf702 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027b1af0> self.address=tplkasactl
2021-12-29 09:28:45,944 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Plug 2:check_st: is_on=False
2021-12-29 09:28:45,944 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=3c846a0c2bf703 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027b1a60> self.address=tplkasactl
2021-12-29 09:28:45,945 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Plug 3:check_st: is_on=False
2021-12-29 09:28:45,946 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=68ff7bc5382f01 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027c83a0> self.address=tplkasactl
2021-12-29 09:28:45,947 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Camera 5:check_st: is_on=True
2021-12-29 09:28:45,948 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: node=68ff7bc5382f02 node.address=<nodes.SmartStripPlugNode.SmartStripPlugNode object at 0x8027c8730> self.address=tplkasactl
2021-12-29 09:28:45,948 shortPoll  polyinterface      DEBUG    SmartStripPlugNode:check_st: Vacuum:check_st: is_on=False
2021-12-29 09:28:45,949 shortPoll  polyinterface      DEBUG    Controller:_shortPoll: done

 

Link to comment
Share on other sites

Thanks, I can improve the code to catch that error, but looks like it's having issues communicating with the device:

kasa.exceptions.SmartDeviceException: Communication error on system:set_relay_state

Has this ever worked on this device?  It will hopefully work better with the newer version of the python-kasa library used on the PG3 nodeserver.

There is also this warning which I spent a lot of time improving how that works for the PG3 version:

2021-12-29 09:28:15,718 shortPoll  kasa.protocol      WARNING  protocol:_detect_event_loop_change: Detected protocol reuse between different event loop
 

 

Link to comment
Share on other sites

Archived

This topic is now archived and is closed to further replies.


×
×
  • Create New...