scottyphillips / pychonet

A simple to use library for interfacing with the ECHONETlite protocol
GNU General Public License v3.0
19 stars 17 forks source link

Something in pychonet causes crashes in HA front end #33

Closed ChirpyTurnip closed 2 years ago

ChirpyTurnip commented 2 years ago

Hello Again!

I have found a new bug I think though I can only vaguely describe the symptoms.

I’ve recently noticed that if we’re away from home for more than a day the HA front end crashes…this never seems to happen when we are at home. Needless to say this is a very hard thing to work on as I have to leave home for a long time to see if I can get the error to occur…

Last night it crashed again and I’ve pulled the logs…they look entirely normal until just before the crash and then there are references to exceptions, loops, and bunch of other stuff...but much of it is centered on pychonet. I don't know what causes the crash except it happens when we're not at home....it might be possible for it to happen when we are home too, but I can't say I've ever noticed it.

Below is what I see in the log, but the important part to note is that for whatever reason when the echonet module gets an error the backend library it uses issues a quit() command and that makes the whole Home Assistant exit.

2021-11-18 19:16:13 ERROR (stream_worker) [root] Uncaught thread exception Traceback (most recent call last): File “/usr/local/lib/python3.9/threading.py”, line 973, in _bootstrap_inner self.run() File “/usr/local/lib/python3.9/threading.py”, line 910, in run self._target(*self._args, self._kwargs) File “/usr/src/homeassistant/homeassistant/components/stream/init.py”, line 284, in _run_worker stream_worker( File “/usr/src/homeassistant/homeassistant/components/stream/worker.py”, line 489, in stream_worker segment_buffer.mux_packet(packet) File “/usr/src/homeassistant/homeassistant/components/stream/worker.py”, line 175, in mux_packet self.flush(packet, last_part=True) File “/usr/src/homeassistant/homeassistant/components/stream/worker.py”, line 247, in flush self._hass.loop.call_soon_threadsafe( File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 791, in call_soon_threadsafe self._check_closed() File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 510, in _check_closed raise RuntimeError(‘Event loop is closed’) RuntimeError: Event loop is closed 2021-11-18 19:16:13 ERROR (stream_worker) [root] Uncaught thread exception Traceback (most recent call last): File “/usr/local/lib/python3.9/threading.py”, line 973, in _bootstrap_inner self.run() File “/usr/local/lib/python3.9/threading.py”, line 910, in run self._target(*self._args, *self._kwargs) File “/usr/src/homeassistant/homeassistant/components/stream/init.py”, line 284, in _run_worker stream_worker( File “/usr/src/homeassistant/homeassistant/components/stream/worker.py”, line 489, in stream_worker segment_buffer.mux_packet(packet) File “/usr/src/homeassistant/homeassistant/components/stream/worker.py”, line 175, in mux_packet self.flush(packet, last_part=True) File “/usr/src/homeassistant/homeassistant/components/stream/worker.py”, line 247, in flush self._hass.loop.call_soon_threadsafe( File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 791, in call_soon_threadsafe self._check_closed() File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 510, in _check_closed raise RuntimeError(‘Event loop is closed’) RuntimeError: Event loop is closed 2021-11-18 19:16:14 ERROR (Thread-3) [paho.mqtt.client] Caught exception in on_message: Event loop is closed 2021-11-18 19:16:14 ERROR (Thread-3) [root] Uncaught thread exception Traceback (most recent call last): File “/usr/local/lib/python3.9/threading.py”, line 973, in _bootstrap_inner self.run() File “/usr/local/lib/python3.9/threading.py”, line 910, in run self._target(self._args, self._kwargs) File “/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py”, line 3591, in _thread_main self.loop_forever(retry_first_connection=True) File “/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py”, line 1756, in loop_forever rc = self._loop(timeout) File “/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py”, line 1164, in _loop rc = self.loop_read() File “/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py”, line 1556, in loop_read rc = self._packet_read() File “/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py”, line 2439, in _packet_read rc = self._packet_handle() File “/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py”, line 3033, in _packet_handle return self._handle_publish() File “/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py”, line 3327, in _handle_publish self._handle_on_message(message) File “/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py”, line 3570, in _handle_on_message on_message(self, self._userdata, message) File “/usr/src/homeassistant/homeassistant/components/mqtt/init.py”, line 850, in _mqtt_on_message self.hass.add_job(self._mqtt_handle_message, msg) File “/usr/src/homeassistant/homeassistant/core.py”, line 333, in add_job self.loop.call_soon_threadsafe(self.async_add_job, target, args) File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 791, in call_soon_threadsafe self._check_closed() File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 510, in _check_closed raise RuntimeError(‘Event loop is closed’) RuntimeError: Event loop is closed 2021-11-18 19:16:15 ERROR (stream_worker) [root] Uncaught thread exception Traceback (most recent call last): File “/usr/local/lib/python3.9/threading.py”, line 973, in _bootstrap_inner self.run() File “/usr/local/lib/python3.9/threading.py”, line 910, in run self._target(self._args, **self._kwargs) File “/usr/src/homeassistant/homeassistant/components/stream/init.py”, line 284, in _run_worker stream_worker( File “/usr/src/homeassistant/homeassistant/components/stream/worker.py”, line 489, in stream_worker segment_buffer.mux_packet(packet) File “/usr/src/homeassistant/homeassistant/components/stream/worker.py”, line 175, in mux_packet self.flush(packet, last_part=True) File “/usr/src/homeassistant/homeassistant/components/stream/worker.py”, line 247, in flush self._hass.loop.call_soon_threadsafe( File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 791, in call_soon_threadsafe self._check_closed() File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 510, in _check_closed raise RuntimeError(‘Event loop is closed’) RuntimeError: Event loop is closed 2021-11-18 19:16:17 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending! 2021-11-18 19:16:17 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending! 2021-11-18 19:16:17 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending! 2021-11-18 19:16:17 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending! 2021-11-18 19:16:17 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending! 2021-11-18 19:16:17 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending! 2021-11-18 19:16:17 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending! 2021-11-18 19:16:17 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending! 2021-11-18 19:16:17 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending! 2021-11-18 19:16:17 ERROR (MainThread) [homeassistant] Error doing job: Task was destroyed but it is pending! 2021-11-18 19:16:17 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved Traceback (most recent call last): File “/usr/local/lib/python3.9/site-packages/pychonet/lib/functions.py”, line 60, in buildEchonetMsg raise ValueError(‘Transaction ID is larger then 2 bytes.’) ValueError: Transaction ID is larger then 2 bytes.

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File “/usr/src/homeassistant/homeassistant/runner.py”, line 121, in run return loop.run_until_complete(setup_and_run_hass(runtime_config)) File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 629, in run_until_complete self.run_forever() File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 596, in run_forever self._run_once() File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 1890, in _run_once handle._run() File “/usr/local/lib/python3.9/asyncio/events.py”, line 80, in _run self._context.run(self._callback, *self._args) File “/config/custom_components/echonetlite/sensor.py”, line 159, in async_update await self._instance.async_update() File “/config/custom_components/echonetlite/init.py”, line 247, in async_update batch_data = await self._instance.update(flags) File “/usr/local/lib/python3.9/site-packages/pychonet/EchonetInstance.py”, line 110, in update response = await self._api.echonetMessage(self._host, self._eojgc, self._eojcc, self._eojci, GET, opc) File “/usr/local/lib/python3.9/site-packages/pychonet/echonetapiclient.py”, line 59, in echonetMessage payload = buildEchonetMsg({ File “/usr/local/lib/python3.9/site-packages/pychonet/lib/functions.py”, line 105, in buildEchonetMsg quit() File “/usr/local/lib/python3.9/_sitebuiltins.py”, line 26, in call raise SystemExit(code) SystemExit: None

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File “/usr/local/lib/python3.9/site-packages/pychonet/lib/functions.py”, line 60, in buildEchonetMsg raise ValueError(‘Transaction ID is larger then 2 bytes.’) ValueError: Transaction ID is larger then 2 bytes.

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File “/usr/src/homeassistant/homeassistant/main.py”, line 318, in main exit_code = runner.run(runtime_conf) File “/usr/src/homeassistant/homeassistant/runner.py”, line 124, in run _cancel_all_tasks_with_timeout(loop, TASK_CANCELATION_TIMEOUT) File “/usr/src/homeassistant/homeassistant/runner.py”, line 145, in _cancel_all_tasks_with_timeout loop.run_until_complete(asyncio.wait(to_cancel, timeout=timeout)) File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 629, in run_until_complete self.run_forever() File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 596, in run_forever self._run_once() File “/usr/local/lib/python3.9/asyncio/base_events.py”, line 1890, in _run_once handle._run() File “/usr/local/lib/python3.9/asyncio/events.py”, line 80, in _run self._context.run(self._callback, *self._args) File “/config/custom_components/echonetlite/sensor.py”, line 159, in async_update await self._instance.async_update() File “/config/custom_components/echonetlite/init.py”, line 247, in async_update batch_data = await self._instance.update(flags) File “/usr/local/lib/python3.9/site-packages/pychonet/EchonetInstance.py”, line 110, in update response = await self._api.echonetMessage(self._host, self._eojgc, self._eojcc, self._eojci, GET, opc) File “/usr/local/lib/python3.9/site-packages/pychonet/echonetapiclient.py”, line 59, in echonetMessage payload = buildEchonetMsg({ File “/usr/local/lib/python3.9/site-packages/pychonet/lib/functions.py”, line 105, in buildEchonetMsg quit() File “/usr/local/lib/python3.9/_sitebuiltins.py”, line 26, in call raise SystemExit(code) SystemExit: None

After that there is nothing until the system restarts…which I can do via SSH to the console and issuing a ha core restart command...but the system really is down - for example in this case there is a seventeen hour gap in my power consumption data so it's really dead....

Thanks!

CP.

scottyphillips commented 2 years ago

Another TID rollover bug 🤦🏼‍♂️ sorry. Surprised it hasn't surfaced sooner tbh. Ive never noticed because my system reboots once a day. ive got a bug fix version on the way..

ChirpyTurnip commented 2 years ago

These things happen...been like that for a while just had to get the ducks lined up to capture the log. No idea why it only happens when we are away....but that part is pretty darn consistent.... ;-)

I'll keep an eye out for the fix.

Cheers!

On Mon, 22 Nov 2021 at 12:52, Scott Phillips @.***> wrote:

Another TID rollover bug 🤦🏼‍♂️ sorry. Surprised it hasn't surfaced sooner tbh. Ive never noticed because my system reboots once a day. ive got a bug fix version on the way..

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/scottyphillips/pychonet/issues/33#issuecomment-974923286, or unsubscribe https://github.com/notifications/unsubscribe-auth/AUIP7ZUTTVX2W44STTCVFCTUNGA4JANCNFSM5IMZAOHQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

scottyphillips commented 2 years ago

The custom component now uses 2.0.20, which hopefully fixes your issue. can you pull or update the manifest and let me know. Thanks for bringing to my attention.

ChirpyTurnip commented 2 years ago

All good - I've gone HACS and hit re-download......I presume that's all I have to do....let me know if not. :-)

On Mon, 22 Nov 2021 at 13:02, Scott Phillips @.***> wrote:

The custom component now uses 2.0.20, which hopefully fixes your issue. can you pull or update the manifest and let me know. Thanks for bringing to my attention.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/scottyphillips/pychonet/issues/33#issuecomment-974924959, or unsubscribe https://github.com/notifications/unsubscribe-auth/AUIP7ZQRBGBZM2NVTIFZUPDUNGCANANCNFSM5IMZAOHQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

scottyphillips commented 2 years ago

Hey, have you seen this issue re-emerge since I pushed the update?

ChirpyTurnip commented 2 years ago

No... but then to be fair I haven't been away from home much either since logging the issue. So far I've only seen it when we're away (which was weird all on its own). I'll be away again for a few days after Christmas so that will be the time that I notice...

I'm optimistic. ;-)

Cheers!

On Mon, 20 Dec. 2021, 21:50 Scott Phillips, @.***> wrote:

Hey, have you seen this issue re-emerge since I pushed the update?

— Reply to this email directly, view it on GitHub https://github.com/scottyphillips/pychonet/issues/33#issuecomment-997718897, or unsubscribe https://github.com/notifications/unsubscribe-auth/AUIP7ZQE2JH7RDML5WJOEEDUR3U5PANCNFSM5IMZAOHQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you authored the thread.Message ID: @.***>

ChirpyTurnip commented 2 years ago

Hi,

Happy New Year!

So the verdict is in....we are still crashing - every 24-36 hours the core crashes and I need to restart it via the SSH console. The error message is different however....so I don't know if it is pychonet or not as I don't think this no longer features in the log (by name at least)....it might even be different HACS component now as there are several mentions of the Samsung TV Smart and MQTT add-ins. This is what I'm getting:

2021-12-31 23:53:28 WARNING (MainThread) [homeassistant.components.websocket_api.http.connection] [139976213419152] Disconnected: Did not receive auth message within 10 seconds 2022-01-01 00:23:58 ERROR (MainThread) [pyenvisalink.dsc_client] The previous command resulted in a checksum failure. 2022-01-01 00:46:04 ERROR (MainThread) [pyenvisalink.dsc_client] The previous command resulted in a checksum failure. 2022-01-01 01:09:37 ERROR (MainThread) [pyenvisalink.dsc_client] The previous command resulted in a checksum failure. 2022-01-01 01:20:01 ERROR (MainThread) [pyenvisalink.dsc_client] The previous command resulted in a checksum failure. 2022-01-01 01:32:43 ERROR (MainThread) [pyenvisalink.envisalink_base_client] Received invalid message. Skipping. 2022-01-01 01:47:40 ERROR (MainThread) [pyenvisalink.dsc_client] The previous command resulted in a checksum failure. 2022-01-01 01:56:39 WARNING (MainThread) [homeassistant.runner] Task could not be canceled and was still running after shutdown: <Task pending name='Task-500' coro=<BaseIoT.connect() running at /usr/local/lib/python3.9/site-packages/hass_nabucasa/iot_base.py:108> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f4ee73cb970>()]>> 2022-01-01 01:56:39 WARNING (MainThread) [homeassistant.runner] Task could not be canceled and was still running after shutdown: <Task pending name='Task-11287' coro=<BaseIoT.connect() running at /usr/local/lib/python3.9/site-packages/hass_nabucasa/iot_base.py:108> wait_for=<Future pending cb=[shield.._outer_done_callback() at /usr/local/lib/python3.9/asyncio/tasks.py:905, <TaskWakeupMethWrapper object at 0x7f4ecc1ff5e0>()]>> 2022-01-01 01:56:39 WARNING (Thread-17) [homeassistant.util.executor] Thread[SyncWorker_1] is still running at shutdown: File "/usr/local/lib/python3.9/threading.py", line 930, in _bootstrap self._bootstrap_inner() File "/usr/local/lib/python3.9/threading.py", line 973, in _bootstrap_inner self.run() File "/usr/local/lib/python3.9/threading.py", line 910, in run self._target(*self._args, self._kwargs) File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 77, in _worker work_item.run() File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 52, in run result = self.fn(*self.args, *self.kwargs) File "/config/custom_components/samsungtv_smart/media_player.py", line 463, in _ping_device result = self._ws.ping_device() File "/config/custom_components/samsungtv_smart/api/samsungws.py", line 680, in ping_device result = self._ping.ping() File "/config/custom_components/samsungtv_smart/api/samsungws.py", line 114, in ping out = pinger.communicate() File "/usr/local/lib/python3.9/subprocess.py", line 1134, in communicate stdout, stderr = self._communicate(input, endtime, timeout) File "/usr/local/lib/python3.9/subprocess.py", line 1979, in _communicate ready = selector.select(timeout) File "/usr/local/lib/python3.9/selectors.py", line 416, in select fd_event_list = self._selector.poll(timeout) 2022-01-01 01:56:39 WARNING (Thread-17) [homeassistant.util.executor] Thread[SyncWorker_7] is still running at shutdown: File "/usr/local/lib/python3.9/threading.py", line 930, in _bootstrap self._bootstrap_inner() File "/usr/local/lib/python3.9/threading.py", line 973, in _bootstrap_inner self.run() File "/usr/local/lib/python3.9/threading.py", line 910, in run self._target(self._args, self._kwargs) File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 77, in _worker work_item.run() File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 52, in run result = self.fn(*self.args, *self.kwargs) File "/config/custom_components/samsungtv_smart/media_player.py", line 463, in _ping_device result = self._ws.ping_device() File "/config/custom_components/samsungtv_smart/api/samsungws.py", line 680, in ping_device result = self._ping.ping() File "/config/custom_components/samsungtv_smart/api/samsungws.py", line 114, in ping out = pinger.communicate() File "/usr/local/lib/python3.9/subprocess.py", line 1134, in communicate stdout, stderr = self._communicate(input, endtime, timeout) File "/usr/local/lib/python3.9/subprocess.py", line 1979, in _communicate ready = selector.select(timeout) File "/usr/local/lib/python3.9/selectors.py", line 416, in select fd_event_list = self._selector.poll(timeout) 2022-01-01 01:56:39 ERROR (SyncWorker_7) [concurrent.futures] exception calling callback for <Future at 0x7f4ecbdbaca0 state=finished raised SystemExit> Traceback (most recent call last): File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 52, in run result = self.fn(self.args, **self.kwargs) File "/config/custom_components/samsungtv_smart/media_player.py", line 463, in _ping_device result = self._ws.ping_device() File "/config/custom_components/samsungtv_smart/api/samsungws.py", line 680, in ping_device result = self._ping.ping() File "/config/custom_components/samsungtv_smart/api/samsungws.py", line 114, in ping out = pinger.communicate() File "/usr/local/lib/python3.9/subprocess.py", line 1134, in communicate stdout, stderr = self._communicate(input, endtime, timeout) File "/usr/local/lib/python3.9/subprocess.py", line 1979, in _communicate ready = selector.select(timeout) File "/usr/local/lib/python3.9/selectors.py", line 416, in select fd_event_list = self._selector.poll(timeout) SystemExit

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.9/concurrent/futures/_base.py", line 329, in _invoke_callbacks callback(self) File "/usr/local/lib/python3.9/asyncio/futures.py", line 398, in _call_set_state dest_loop.call_soon_threadsafe(_set_state, destination, source) File "/usr/local/lib/python3.9/asyncio/base_events.py", line 791, in call_soon_threadsafe self._check_closed() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 510, in _check_closed raise RuntimeError('Event loop is closed') RuntimeError: Event loop is closed 2022-01-01 01:56:39 ERROR (Thread-17) [root] Uncaught thread exception Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/runner.py", line 173, in _do_shutdown loop.call_soon_threadsafe(future.set_result, None) File "/usr/local/lib/python3.9/asyncio/base_events.py", line 791, in call_soon_threadsafe self._check_closed() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 510, in _check_closed raise RuntimeError('Event loop is closed') RuntimeError: Event loop is closed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.9/threading.py", line 973, in _bootstrap_inner self.run() File "/usr/local/lib/python3.9/threading.py", line 910, in run self._target(*self._args, self._kwargs) File "/usr/src/homeassistant/homeassistant/runner.py", line 175, in _do_shutdown loop.call_soon_threadsafe(future.set_exception, ex) File "/usr/local/lib/python3.9/asyncio/base_events.py", line 791, in call_soon_threadsafe self._check_closed() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 510, in _check_closed raise RuntimeError('Event loop is closed') RuntimeError: Event loop is closed 2022-01-01 01:56:41 ERROR (Thread-3) [paho.mqtt.client] Caught exception in on_message: Event loop is closed 2022-01-01 01:56:41 ERROR (Thread-3) [root] Uncaught thread exception Traceback (most recent call last): File "/usr/local/lib/python3.9/threading.py", line 973, in _bootstrap_inner self.run() File "/usr/local/lib/python3.9/threading.py", line 910, in run self._target(*self._args, self._kwargs) File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 3591, in _thread_main self.loop_forever(retry_first_connection=True) File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 1756, in loop_forever rc = self._loop(timeout) File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 1164, in _loop rc = self.loop_read() File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 1556, in loop_read rc = self._packet_read() File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 2439, in _packet_read rc = self._packet_handle() File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 3033, in _packet_handle return self._handle_publish() File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 3327, in _handle_publish self._handle_on_message(message) File "/usr/local/lib/python3.9/site-packages/paho/mqtt/client.py", line 3570, in _handle_on_message on_message(self, self._userdata, message) File "/usr/src/homeassistant/homeassistant/components/mqtt/init.py", line 897, in _mqtt_on_message self.hass.add_job(self._mqtt_handle_message, msg) File "/usr/src/homeassistant/homeassistant/core.py", line 333, in add_job self.loop.call_soon_threadsafe(self.async_add_job, target, args) File "/usr/local/lib/python3.9/asyncio/base_events.py", line 791, in call_soon_threadsafe self._check_closed() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 510, in _check_closed raise RuntimeError('Event loop is closed') RuntimeError: Event loop is closed 2022-01-01 01:56:43 ERROR (stream_worker) [root] Uncaught thread exception Traceback (most recent call last): File "/usr/local/lib/python3.9/threading.py", line 973, in _bootstrap_inner self.run() File "/usr/local/lib/python3.9/threading.py", line 910, in run self._target(self._args, self._kwargs) File "/usr/src/homeassistant/homeassistant/components/stream/init.py", line 298, in _run_worker stream_worker( File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 537, in stream_worker muxer.mux_packet(packet) File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 221, in mux_packet self.flush(packet, last_part=True) File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 293, in flush self._hass.loop.call_soon_threadsafe( File "/usr/local/lib/python3.9/asyncio/base_events.py", line 791, in call_soon_threadsafe self._check_closed() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 510, in _check_closed raise RuntimeError('Event loop is closed') RuntimeError: Event loop is closed 2022-01-01 01:56:44 ERROR (stream_worker) [root] Uncaught thread exception Traceback (most recent call last): File "/usr/local/lib/python3.9/threading.py", line 973, in _bootstrap_inner self.run() File "/usr/local/lib/python3.9/threading.py", line 910, in run self._target(*self._args, self._kwargs) File "/usr/src/homeassistant/homeassistant/components/stream/init.py", line 298, in _run_worker stream_worker( File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 537, in stream_worker muxer.mux_packet(packet) File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 221, in mux_packet self.flush(packet, last_part=True) File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 293, in flush self._hass.loop.call_soon_threadsafe( File "/usr/local/lib/python3.9/asyncio/base_events.py", line 791, in call_soon_threadsafe self._check_closed() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 510, in _check_closed raise RuntimeError('Event loop is closed') RuntimeError: Event loop is closed 2022-01-01 01:56:44 ERROR (stream_worker) [root] Uncaught thread exception Traceback (most recent call last): File "/usr/local/lib/python3.9/threading.py", line 973, in _bootstrap_inner self.run() File "/usr/local/lib/python3.9/threading.py", line 910, in run self._target(*self._args, *self._kwargs) File "/usr/src/homeassistant/homeassistant/components/stream/init.py", line 298, in _run_worker stream_worker( File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 537, in stream_worker muxer.mux_packet(packet) File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 221, in mux_packet self.flush(packet, last_part=True) File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 293, in flush self._hass.loop.call_soon_threadsafe( File "/usr/local/lib/python3.9/asyncio/base_events.py", line 791, in call_soon_threadsafe self._check_closed() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 510, in _check_closed raise RuntimeError('Event loop is closed') RuntimeError: Event loop is closed 2022-01-01 01:56:44 ERROR (stream_worker) [root] Uncaught thread exception Traceback (most recent call last): File "/usr/local/lib/python3.9/threading.py", line 973, in _bootstrap_inner self.run() File "/usr/local/lib/python3.9/threading.py", line 910, in run self._target(self._args, **self._kwargs) File "/usr/src/homeassistant/homeassistant/components/stream/init.py", line 298, in _run_worker stream_worker( File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 537, in stream_worker muxer.mux_packet(packet) File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 221, in mux_packet self.flush(packet, last_part=True) File "/usr/src/homeassistant/homeassistant/components/stream/worker.py", line 293, in flush self._hass.loop.call_soon_threadsafe( File "/usr/local/lib/python3.9/asyncio/base_events.py", line 791, in call_soon_threadsafe self._check_closed() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 510, in _check_closed raise RuntimeError('Event loop is closed') RuntimeError: Event loop is closed

This is the last line in the log....and then she's dead Jim.....

If you could venture an opinion on possible causes then we can clear pychonet and go pester another developer. The thing for me that remains super weird is that this only happens when we are away....in all the time since I logged the ticket this sort of error never happened once while we were home....

Cheers!

CP.

On Mon, 20 Dec 2021 at 22:22, Bart Teekman @.***> wrote:

No... but then to be fair I haven't been away from home much either since logging the issue. So far I've only seen it when we're away (which was weird all on its own). I'll be away again for a few days after Christmas so that will be the time that I notice...

I'm optimistic. ;-)

Cheers!

On Mon, 20 Dec. 2021, 21:50 Scott Phillips, @.***> wrote:

Hey, have you seen this issue re-emerge since I pushed the update?

— Reply to this email directly, view it on GitHub https://github.com/scottyphillips/pychonet/issues/33#issuecomment-997718897, or unsubscribe https://github.com/notifications/unsubscribe-auth/AUIP7ZQE2JH7RDML5WJOEEDUR3U5PANCNFSM5IMZAOHQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you authored the thread.Message ID: @.***>

scottyphillips commented 2 years ago

I cannot see any error log messages related to the Echonetlite or the pychonet python code that I maintain. I would consider your Samsung TV custom component the prime suspect too - especially since when you are at home you are likely turning your TV on and off daily which is likely causing something to continue to work (as opposed to your TV sitting idle).

At this stage I would recommend disabling your Samsung TV custom component and testing again. I'll leave this issue open for now, but I don't expect any more issues from the pychonet library.

ChirpyTurnip commented 2 years ago

I thought you might say that.... And that's a good suggestion re TV being on at least once a day.... We have two of them but the one in the dining is on at least once a day... so it may well be that action that keeps it running....

Cheers!

On Sun, 2 Jan 2022, 20:42 Scott Phillips, @.***> wrote:

I cannot see any error log messages related to the Echonetlite or the pychonet python code that I maintain. I would consider your Samsung TV custom component the prime suspect too - especially since when you are at home you are likely turning your TV on and off daily which is likely causing something to continue to work (as opposed to your TV sitting idle).

At this stage I would recommend disabling your Samsung TV custom component and testing again. I'll leave this issue open for now, but I don't expect any more issues from the pychonet library.

— Reply to this email directly, view it on GitHub https://github.com/scottyphillips/pychonet/issues/33#issuecomment-1003676264, or unsubscribe https://github.com/notifications/unsubscribe-auth/AUIP7ZSACZ3QBE7ZWZLLM3TUT76VRANCNFSM5IMZAOHQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you authored the thread.Message ID: @.***>

khcnz commented 2 years ago

I'd had a crash and thought maybe i wasn't on latest version.. but i forced downloaded the latest version and got another crash today

`2022-01-11 08:30:36 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback None() Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/pychonet/lib/functions.py", line 60, in buildEchonetMsg raise ValueError('Transaction ID is larger then 2 bytes.') ValueError: Transaction ID is larger then 2 bytes.

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/runner.py", line 121, in run return loop.run_until_complete(setup_and_run_hass(runtime_config)) File "/usr/local/lib/python3.9/asyncio/base_events.py", line 629, in run_until_complete self.run_forever() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 596, in run_forever self._run_once() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 1890, in _run_once handle._run() File "/usr/local/lib/python3.9/asyncio/events.py", line 80, in _run self._context.run(self._callback, *self._args) File "/config/custom_components/echonetlite/sensor.py", line 159, in async_update await self._instance.async_update() File "/config/custom_components/echonetlite/init.py", line 247, in async_update batch_data = await self._instance.update(flags) File "/usr/local/lib/python3.9/site-packages/pychonet/EchonetInstance.py", line 110, in update response = await self._api.echonetMessage(self._host, self._eojgc, self._eojcc, self._eojci, GET, opc) File "/usr/local/lib/python3.9/site-packages/pychonet/echonetapiclient.py", line 59, in echonetMessage payload = buildEchonetMsg({ File "/usr/local/lib/python3.9/site-packages/pychonet/lib/functions.py", line 105, in buildEchonetMsg quit() File "/usr/local/lib/python3.9/_sitebuiltins.py", line 26, in call raise SystemExit(code) SystemExit: None

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.9/asyncio/events.py", line 80, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.9/site-packages/aioudp/server.py", line 67, in _sock_recv fut.set_result((data, addr))`

scottyphillips commented 2 years ago

There shouldn’t be any reason in the latest code for that error to be invoked under normal operating conditions. That buildechonetmessage function is only invoked by ‘echonetmessage’ in the API client class, and that is where the TID is tested and rolled over from 0xFFFF to 0x0001 (as well as where it is incremented). So it shouldn’t really be possible for that ValueError exception to be raised.


From: khcnz @.> Sent: Tuesday, 11 January 2022 7:05 AM To: scottyphillips/pychonet @.> Cc: Scott Phillips @.>; Comment @.> Subject: Re: [scottyphillips/pychonet] Something in pychonet causes crashes in HA front end (Issue #33)

I'd had a crash and thought maybe i wasn't on latest version.. but i forced downloaded the latest version and got another crash today

`2022-01-11 08:30:36 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback None() Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/pychonet/lib/functions.py", line 60, in buildEchonetMsg raise ValueError('Transaction ID is larger then 2 bytes.') ValueError: Transaction ID is larger then 2 bytes.

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/runner.py", line 121, in run return loop.run_until_complete(setup_and_run_hass(runtime_config)) File "/usr/local/lib/python3.9/asyncio/base_events.py", line 629, in run_until_complete self.run_forever() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 596, in run_forever self._run_once() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 1890, in _run_once handle._run() File "/usr/local/lib/python3.9/asyncio/events.py", line 80, in _run self._context.run(self._callback, *self._args) File "/config/custom_components/echonetlite/sensor.py", line 159, in async_update await self._instance.async_update() File "/config/custom_components/echonetlite/init.py", line 247, in async_update batch_data = await self._instance.update(flags) File "/usr/local/lib/python3.9/site-packages/pychonet/EchonetInstance.py", line 110, in update response = await self._api.echonetMessage(self._host, self._eojgc, self._eojcc, self._eojci, GET, opc) File "/usr/local/lib/python3.9/site-packages/pychonet/echonetapiclient.py", line 59, in echonetMessage payload = buildEchonetMsg({ File "/usr/local/lib/python3.9/site-packages/pychonet/lib/functions.py", line 105, in buildEchonetMsg quit() File "/usr/local/lib/python3.9/_sitebuiltins.py", line 26, in call raise SystemExit(code) SystemExit: None

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.9/asyncio/events.py", line 80, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.9/site-packages/aioudp/server.py", line 67, in _sock_recv fut.set_result((data, addr))`

— Reply to this email directly, view it on GitHubhttps://github.com/scottyphillips/pychonet/issues/33#issuecomment-1009297722, or unsubscribehttps://github.com/notifications/unsubscribe-auth/AGHQNDCCMEU5JHW6CJVMF2TUVM3ZLANCNFSM5IMZAOHQ. Triage notifications on the go with GitHub Mobile for iOShttps://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Androidhttps://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub. You are receiving this because you commented.Message ID: @.***>

scottyphillips commented 2 years ago

I’ll just build in another layer of exception handling to prevent any further crashing.


From: khcnz @.> Sent: Tuesday, 11 January 2022 7:05 AM To: scottyphillips/pychonet @.> Cc: Scott Phillips @.>; Comment @.> Subject: Re: [scottyphillips/pychonet] Something in pychonet causes crashes in HA front end (Issue #33)

I'd had a crash and thought maybe i wasn't on latest version.. but i forced downloaded the latest version and got another crash today

`2022-01-11 08:30:36 ERROR (MainThread) [homeassistant] Error doing job: Exception in callback None() Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/pychonet/lib/functions.py", line 60, in buildEchonetMsg raise ValueError('Transaction ID is larger then 2 bytes.') ValueError: Transaction ID is larger then 2 bytes.

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/runner.py", line 121, in run return loop.run_until_complete(setup_and_run_hass(runtime_config)) File "/usr/local/lib/python3.9/asyncio/base_events.py", line 629, in run_until_complete self.run_forever() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 596, in run_forever self._run_once() File "/usr/local/lib/python3.9/asyncio/base_events.py", line 1890, in _run_once handle._run() File "/usr/local/lib/python3.9/asyncio/events.py", line 80, in _run self._context.run(self._callback, *self._args) File "/config/custom_components/echonetlite/sensor.py", line 159, in async_update await self._instance.async_update() File "/config/custom_components/echonetlite/init.py", line 247, in async_update batch_data = await self._instance.update(flags) File "/usr/local/lib/python3.9/site-packages/pychonet/EchonetInstance.py", line 110, in update response = await self._api.echonetMessage(self._host, self._eojgc, self._eojcc, self._eojci, GET, opc) File "/usr/local/lib/python3.9/site-packages/pychonet/echonetapiclient.py", line 59, in echonetMessage payload = buildEchonetMsg({ File "/usr/local/lib/python3.9/site-packages/pychonet/lib/functions.py", line 105, in buildEchonetMsg quit() File "/usr/local/lib/python3.9/_sitebuiltins.py", line 26, in call raise SystemExit(code) SystemExit: None

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/usr/local/lib/python3.9/asyncio/events.py", line 80, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.9/site-packages/aioudp/server.py", line 67, in _sock_recv fut.set_result((data, addr))`

— Reply to this email directly, view it on GitHubhttps://github.com/scottyphillips/pychonet/issues/33#issuecomment-1009297722, or unsubscribehttps://github.com/notifications/unsubscribe-auth/AGHQNDCCMEU5JHW6CJVMF2TUVM3ZLANCNFSM5IMZAOHQ. Triage notifications on the go with GitHub Mobile for iOShttps://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Androidhttps://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub. You are receiving this because you commented.Message ID: @.***>

scottyphillips commented 2 years ago

I worked out why it was causing HA to crash - there was some really early (like day 1) exception handling code which invoked quit() when the ValueError was raised.

I thought I could code around so it would never be raised, but I am assuming some sort of race condition is allowing TIDs > 0xFFFF to be parsed to BuildEchonetMessage... So onto plan B.

Anyways, I've decided that rather then try to ignore the exception, or try to avoid it; that I will allow it to fire, PROPERLY catch the exception (rather then quit() lol) and then reset the TID to 1 when the exception occurs. So I have rewrote that code and it now will be correctly handled hopefully without any more crashes...