Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Receiving SMS is causing crash of HomeAssistant #54876

Closed
glith opened this issue Aug 19, 2021 · 34 comments · Fixed by #56552
Closed

Receiving SMS is causing crash of HomeAssistant #54876

glith opened this issue Aug 19, 2021 · 34 comments · Fixed by #56552

Comments

@glith
Copy link

glith commented Aug 19, 2021

The problem

When I receive a SMS, HomeAssistant crashes and restarts.

What is version of Home Assistant Core has the issue?

core-2021.8.8

What was the last working version of Home Assistant Core?

core-2021.6.6

What type of installation are you running?

Home Assistant OS

Integration causing the issue

SMS notifications via GSM-modem

Link to integration documentation on our website

https://www.home-assistant.io/integrations/sms/

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

@probot-home-assistant
Copy link

Hey there @ocalvo, mind taking a look at this issue as it has been labeled with an integration (sms) you are listed as a code owner for? Thanks!
(message by CodeOwnersMention)


sms documentation
sms source
(message by IssueLinks)

@glith
Copy link
Author

glith commented Aug 19, 2021

I'm using a "Teltonika TRM240" as a modem if that information can be of any use, and it has been working fine in both receiving and sending SMS in Core 2021.6.6. ( https://teltonika-networks.com/product/trm240/ )

After sending an SMS I usually get the balance of the account back as an SMS from the service provider and it causes Home Assistant to crash.
I'm also using SMS to remotely do a check if my network is unavailable.

@ocalvo
Copy link
Contributor

ocalvo commented Aug 19, 2021

Can you paste the debug logs?

@glith
Copy link
Author

glith commented Aug 19, 2021

Maybe silly question.. But how do I do that?
I did:

"logger:
default: debug"

However.. It deleted everything up until the restart. couldnt see anything before that.

@glith
Copy link
Author

glith commented Aug 19, 2021

Did these:
logger:
default: info
logs:
homeassistant.components.sms.gateway: debug
homeassistant.components.sms.notify: debug

and tail -f homeassistant.log

And nothing is logged before the Core reboot when it receives the SMS.

@glith
Copy link
Author

glith commented Aug 19, 2021

The supervisor log is writing this right after the crash.. Maybe normal at reboot?
:
21-08-19 17:21:19 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Received message 257:None is not str
21-08-19 17:21:19 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API connection is closed
21-08-19 17:21:24 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state CoreState.RUNNING
21-08-19 17:21:24 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
21-08-19 17:21:37 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
21-08-19 17:21:37 INFO (MainThread) [supervisor.api.proxy] WebSocket access from a0d7b954_nodered
21-08-19 17:21:37 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running

@glith
Copy link
Author

glith commented Aug 27, 2021

Any progress in reproducing this?

@ocalvo
Copy link
Contributor

ocalvo commented Aug 27, 2021

Any progress in reproducing this?

I think I have. But very hard to tell without logs.

@glith
Copy link
Author

glith commented Sep 4, 2021

Upgraded to core-2021.9.2 and the problem persists.

@glith
Copy link
Author

glith commented Sep 11, 2021

Still same problem with core-2021.9.5

Is there anything I can do to assist? The logs are purged at each crash.

@ocalvo
Copy link
Contributor

ocalvo commented Sep 11, 2021

Still same problem with core-2021.9.5

Is there anything I can do to assist? The logs are purged at each crash.

The fix is submitted but you need to wait until October

@ocalvo
Copy link
Contributor

ocalvo commented Sep 11, 2021

@balloob @pvizeli Can we include the fix in the next service release?

@ocalvo
Copy link
Contributor

ocalvo commented Sep 11, 2021

This should be closed by #54237

@TazUk
Copy link

TazUk commented Sep 19, 2021

Running 2021.9.7 (which includes #54237) in Docker on Ubuntu 18.04 using a Huawei USB Modem E220 (sim unlocked) this continues to be an issue.

Note: I have the GSM signal strength indicator enabled via the integration.

logger:
  default: warn
  logs:
    homeassistant.components.sms.gateway: debug

Logged before crash:

2021-09-19 14:38:47 DEBUG (Thread-3) [homeassistant.components.sms.gateway] SMS entries:[]
2021-09-19 14:39:07 DEBUG (Thread-3) [homeassistant.components.sms.gateway] Pulling modem
2021-09-19 14:39:07 DEBUG (Thread-3) [homeassistant.components.sms.gateway] Start remaining:0
2021-09-19 14:39:07 DEBUG (Thread-3) [homeassistant.components.sms.gateway] SMS entries:[]

Logged after crash / restart:

2021-09-19 14:39:28 WARNING (Recorder) [homeassistant.components.recorder.util] The system could not validate that the sqlite3 database at //config/home-assistant_v2.db was shutdown cleanly
2021-09-19 14:39:28 WARNING (Recorder) [homeassistant.components.recorder.util] Ended unfinished session (id=52 from 2021-09-19 14:28:02.431167)
2021-09-19 14:39:47 WARNING (MainThread) [homeassistant.components.sms.gateway] GSM error, falling back to pulling method for SMS notifications
2021-09-19 14:39:47 WARNING (MainThread) [homeassistant.setup] Setup of input_text is taking over 10 seconds.
2021-09-19 14:39:47 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds.
2021-09-19 14:39:47 WARNING (MainThread) [homeassistant.setup] Setup of input_number is taking over 10 seconds.
2021-09-19 14:39:47 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds.
2021-09-19 14:39:47 WARNING (MainThread) [homeassistant.setup] Setup of input_datetime is taking over 10 seconds.
2021-09-19 14:39:47 WARNING (MainThread) [homeassistant.setup] Setup of input_select is taking over 10 seconds.
2021-09-19 14:39:47 WARNING (MainThread) [homeassistant.components.alarm_control_panel] Setup of alarm_control_panel platform manual is taking over 10 seconds.
2021-09-19 14:39:47 WARNING (MainThread) [homeassistant.components.cover] Setup of cover platform opengarage is taking over 10 seconds.
2021-09-19 14:39:47 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform updater is taking over 10 seconds.
2021-09-19 14:39:47 ERROR (MainThread) [snitun.client.client_peer] Challenge/Response error with SniTun server
2021-09-19 14:39:47 ERROR (MainThread) [hass_nabucasa.remote] Connection problem to snitun server
2021-09-19 14:39:48 DEBUG (Thread-3) [homeassistant.components.sms.gateway] Pulling modem
2021-09-19 14:39:48 DEBUG (Thread-3) [homeassistant.components.sms.gateway] Start remaining:1
2021-09-19 14:39:48 DEBUG (Thread-3) [homeassistant.components.sms.gateway] All parts:0
2021-09-19 14:39:48 DEBUG (Thread-3) [homeassistant.components.sms.gateway] Part Number:-1
2021-09-19 14:39:48 DEBUG (Thread-3) [homeassistant.components.sms.gateway] Remaining:1
2021-09-19 14:39:48 DEBUG (Thread-3) [homeassistant.components.sms.gateway] Start all_parts_arrived:True
2021-09-19 14:39:48 DEBUG (Thread-3) [homeassistant.components.sms.gateway] Deleting message
2021-09-19 14:39:48 DEBUG (Thread-3) [homeassistant.components.sms.gateway] SMS entries:[[{'SMSC': {'Location': 0, 'Name': '', 'Format': 'Text', 'Validity': 'NA', 'Number': 'redacted', 'DefaultNumber': ''}, 'UDH': {'Type': 'NoUDH', 'Text': b'', 'ID8bit': 0, 'ID16bit': 0, 'PartNumber': -1, 'AllParts': 0}, 'Folder': 1, 'InboxFolder': 1, 'Memory': 'SM', 'Location': 0, 'Name': '', 'Number': 'redacted', 'Text': '..\rMains: OK\rBattery: OK\rPhone.Line: OK', 'Type': 'Deliver', 'Coding': 'Default_No_Compression', 'DateTime': datetime.datetime(2021, 9, 19, 15, 39, 3), 'SMSCDateTime': datetime.datetime(2021, 9, 19, 14, 39, 48), 'DeliveryStatus': 0, 'ReplyViaSameSMSC': 0, 'State': 'UnRead', 'Class': -1, 'MessageReference': 0, 'ReplaceMessage': 0, 'RejectDuplicates': 0, 'Length': 39}]]
2021-09-19 14:39:48 DEBUG (Thread-3) [homeassistant.components.sms.gateway] Processing sms:{'SMSC': {'Location': 0, 'Name': '', 'Format': 'Text', 'Validity': 'NA', 'Number': 'redacted', 'DefaultNumber': ''}, 'UDH': {'Type': 'NoUDH', 'Text': b'', 'ID8bit': 0, 'ID16bit': 0, 'PartNumber': -1, 'AllParts': 0}, 'Folder': 1, 'InboxFolder': 1, 'Memory': 'SM', 'Location': 0, 'Name': '', 'Number': 'redacted', 'Text': '..\rMains: OK\rBattery: OK\rPhone.Line: OK', 'Type': 'Deliver', 'Coding': 'Default_No_Compression', 'DateTime': datetime.datetime(2021, 9, 19, 15, 39, 3), 'SMSCDateTime': datetime.datetime(2021, 9, 19, 14, 39, 48), 'DeliveryStatus': 0, 'ReplyViaSameSMSC': 0, 'State': 'UnRead', 'Class': -1, 'MessageReference': 0, 'ReplaceMessage': 0, 'RejectDuplicates': 0, 'Length': 39},decoded:None
2021-09-19 14:39:48 DEBUG (Thread-3) [homeassistant.components.sms.gateway] SMS state:UnRead
2021-09-19 14:39:48 DEBUG (Thread-3) [homeassistant.components.sms.gateway] Append event data:{'phone': 'redacted', 'date': '2021-09-19 15:39:03', 'message': '..\rMains: OK\rBattery: OK\rPhone.Line: OK'}

As can be seen in the logs, the SMS is retrieved and processed correctly on restart.

@ocalvo
Copy link
Contributor

ocalvo commented Sep 19, 2021

None of this suggests a problem with the SMS integration.
Do you have an event handler for incoming SMS?
Can you describe it?

@TazUk
Copy link

TazUk commented Sep 19, 2021

None of this suggests a problem with the SMS integration.
Do you have an event handler for incoming SMS?
Can you describe it?

I have an automation using the incoming sms event:

# receiving SMS messages
# data: phone, date, text
# log receipt, record datetime and act on specific valid triggers.
- id: sms_received
  alias: "SMS Received"
  mode: queued
  trigger:
    - platform: event
      event_type: sms.incoming_sms
  condition: []
  action:

it runs after the SMS is collected by polling after the crash / restart occurs.

I'm aware that nothing in the logs indicates the core issue , however the only time that I have this issue is when an SMS is received in any version after 2021.6.6 (which I remained on until today). I can replicate this at will simply by sending my system an SMS message, which is obviously less than ideal.

@ocalvo
Copy link
Contributor

ocalvo commented Sep 19, 2021

What is in the action?

Do you see any of the actions getting executed?

@TazUk
Copy link

TazUk commented Sep 19, 2021

The actions are executed after restart when the sms is collected.

image

@TazUk
Copy link

TazUk commented Sep 19, 2021

I've just quickly tested after :

  • Removing and re-adding the integration
  • Disabling signal strength.
    HA (not the docker container) still restarts when sent an SMS
    Whether the SMS is processed seems to depend on timings - in my last test the SMS was not successfully processed (presumably because of the restart and automations being unavailable)

I should have some time available to run some further tests tomorrow if there's anything in particular to look for with my limited knowledge. I wonder whether @glith is also seeing this on 2021.9.7 and whether there's some common hardware at play?.

@TazUk
Copy link

TazUk commented Sep 19, 2021

I've run one last final test using debug as the logger default and checked the log.1 file.
This shows nothing related to the crash after an SMS was sent at 19:28GMT, just what appears to be normal operations. The last few lines of this log are below.

2021-09-19 18:28:11 DEBUG (MainThread) [homeassistant.components.gogogate2.common] Finished fetching gogogate2 data in 0.159 seconds (success: True)
2021-09-19 18:28:11 DEBUG (MainThread) [pyunifiprotect.unifi_protect_server] Skipping device update
2021-09-19 18:28:11 DEBUG (MainThread) [pyunifiprotect.unifi_protect_server] Skipping update since websocket is active
2021-09-19 18:28:13 DEBUG (MainThread) [pyunifiprotect.unifi_protect_server] Skipping device update
2021-09-19 18:28:13 DEBUG (MainThread) [pyunifiprotect.unifi_protect_server] Skipping update since websocket is active
2021-09-19 18:28:14 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2021-09-19 18:28:14 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 6.220609 seconds.

Initial head entries from log after restart show that it was a crash:

2021-09-19 18:28:24 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration smartthinq_sensors which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-09-19 18:28:24 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration kia_uvo which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-09-19 18:28:24 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration deepstack_object which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-09-19 18:28:24 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration unifiprotect which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-09-19 18:28:24 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration sureha which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-09-19 18:28:24 WARNING (SyncWorker_2) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2021-09-19 18:28:25 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=logger, service=set_default_level>
2021-09-19 18:28:25 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=logger, service=set_level>
2021-09-19 18:28:25 INFO (MainThread) [homeassistant.setup] Setup of domain logger took 0.0 seconds
2021-09-19 18:28:25 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=logger>
2021-09-19 18:28:25 INFO (MainThread) [homeassistant.setup] Setting up http
2021-09-19 18:28:25 WARNING (Recorder) [homeassistant.components.recorder.util] The system could not validate that the sqlite3 database at //config/home-assistant_v2.db was shutdown cleanly
2021-09-19 18:28:26 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Created new connection <sqlite3.Connection object at 0x7fa2d04d83f0>
2021-09-19 18:28:26 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7fa2d04d83f0> checked out from pool
2021-09-19 18:28:26 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7fa2d04d83f0> being returned to pool
2021-09-19 18:28:26 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7fa2d04d83f0> rollback-on-return
2021-09-19 18:28:26 DEBUG (Recorder) [homeassistant.components.recorder] Connected to recorder database
2021-09-19 18:28:26 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7fa2d04d83f0> checked out from pool
2021-09-19 18:28:26 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7fa2d04d83f0> being returned to pool
2021-09-19 18:28:26 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7fa2d04d83f0> rollback-on-return
2021-09-19 18:28:26 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7fa2d04d83f0> checked out from pool
2021-09-19 18:28:26 WARNING (Recorder) [homeassistant.components.recorder.util] Ended unfinished session (id=58 from 2021-09-19 18:27:07.769520)

The unfinished recorder session was from the startup prior to the message (after enabling debugging) - section from that log:

2021-09-19 18:27:06 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=logger, service=set_default_level>
2021-09-19 18:27:06 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=logger, service=set_level>
2021-09-19 18:27:06 INFO (MainThread) [homeassistant.setup] Setup of domain logger took 0.0 seconds
2021-09-19 18:27:06 DEBUG (MainThread) [homeassistant.setup] Dependency system_log will wait for dependencies ['http']
2021-09-19 18:27:07 INFO (MainThread) [homeassistant.setup] Setting up recorder
2021-09-19 18:27:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=recorder, service=purge>
2021-09-19 18:27:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=recorder, service=purge_entities>
2021-09-19 18:27:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=recorder, service=enable>
2021-09-19 18:27:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=recorder, service=disable>
2021-09-19 18:27:07 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=logger>
2021-09-19 18:27:07 INFO (MainThread) [homeassistant.setup] Setting up http
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder.util] The last run ended at: 2021-09-19 18:26:47.962162+00:00 (now: 2021-09-19 18:27:07.788480+00:00)
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder.util] The system was restarted cleanly and passed the basic sanity check
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Created new connection <sqlite3.Connection object at 0x7f9567493e40>
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f9567493e40> checked out from pool
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f9567493e40> being returned to pool
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f9567493e40> rollback-on-return
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder] Connected to recorder database
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f9567493e40> checked out from pool
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f9567493e40> being returned to pool
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f9567493e40> rollback-on-return
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f9567493e40> checked out from pool
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f9567493e40> being returned to pool
2021-09-19 18:27:07 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f9567493e40> rollback-on-return
2021-09-19 18:27:08 DEBUG (MainThread) [homeassistant.bootstrap] Running timeout Zones: {'system_log': <system_log: 0 / 1>, 'recorder': <recorder: 1 / 0>, 'http': <http: 1 / 0>}
2021-09-19 18:27:08 DEBUG (MainThread) [homeassistant.bootstrap] Integration remaining: {'recorder': 0.792505, 'http': 0.774966}

I'm out of my depth here - this feels like it must be related to the docker change between 2021.6.6 and 2021.7.x but it is clearly tied to the receipt of an SMS.

@ocalvo
Copy link
Contributor

ocalvo commented Sep 19, 2021

I suspect that the gammu worker thread is crashing and then tearing down the entire python process.
@pvizeli Do you know how to enable diagnostics to observer if a python thread is crashing?

@ocalvo
Copy link
Contributor

ocalvo commented Sep 19, 2021

@TazUk just to clarify:

  1. Does the GSM signal sensor works? If yes, what is the signal strength?, If not, what happens when you enable it?
  2. While not sending any SMS, can you receive more than one SMS without crashing the core?
  3. While not receiving any SMS, can you send more than one SMS without crashing the core?

@TazUk
Copy link

TazUk commented Sep 19, 2021

@TazUk just to clarify:

  1. Does the GSM signal sensor works? If yes, what is the signal strength?, If not, what happens when you enable it?
  2. While not sending any SMS, can you receive more than one SMS without crashing the core?
  3. While not receiving any SMS, can you send more than one SMS without crashing the core?
  1. Signal strength steady at 42% (consistent value over the last few weeks)
  2. Any single received SMS causes a crash
  3. Sending SMS functions normally (tested multiple messages one after the other).

@pvizeli
Copy link
Member

pvizeli commented Sep 20, 2021

I suspect that the gammu worker thread is crashing and then tearing down the entire python process.
@pvizeli Do you know how to enable diagnostics to observer if a python thread is crashing?

Should not. Maybe a function from the external library calls exit(0) on an error or misleading handling. Maybe the dmesg will show you why it got killed ha host logs

@glith
Copy link
Author

glith commented Sep 21, 2021

core-2021.9.7 is still having the problem. Sending works. Receiving crashes.

@ocalvo
Copy link
Contributor

ocalvo commented Sep 21, 2021

@TazUk just to clarify:

  1. Does the GSM signal sensor works? If yes, what is the signal strength?, If not, what happens when you enable it?
  2. While not sending any SMS, can you receive more than one SMS without crashing the core?
  3. While not receiving any SMS, can you send more than one SMS without crashing the core?
  1. Signal strength steady at 42% (consistent value over the last few weeks)
  2. Any single received SMS causes a crash
  3. Sending SMS functions normally (tested multiple messages one after the other).

Can you try running ha host logs?

@TazUk
Copy link

TazUk commented Sep 21, 2021

That command isn't recognised when I run it within the container - I'm using HA Container in docker. Should I be running it within a particular path?

@ocalvo
Copy link
Contributor

ocalvo commented Sep 22, 2021

I have updated the docs to reflect that modem SIM800C does not work at the moment.

@glith
Copy link
Author

glith commented Sep 22, 2021

A positive change in 2021.9.7... I do now receive the SMS.. But core keeps crashing.

ha host logs from it happens:
`ha host logs:
[347953.320316] audit: type=1701 audit(1632299899.675:578): auid=4294967295 uid=0 gid=0 ses=4294967295 subj==unconfined pid=100246 comm="python3" exe="/usr/local/bin/python3.9" sig=11 res=1

[347953.331691] audit: type=1334 audit(1632299899.683:579): prog-id=205 op=LOAD

[347953.331738] audit: type=1334 audit(1632299899.683:580): prog-id=206 op=LOAD

[347953.524072] audit: type=1334 audit(1632299899.879:581): prog-id=206 op=UNLOAD

[347953.524084] audit: type=1334 audit(1632299899.879:582): prog-id=205 op=UNLOAD`

@pvizeli
Copy link
Member

pvizeli commented Sep 22, 2021

SIGSEGV - means there is a pointer memory issue in the library

@ocalvo
Copy link
Contributor

ocalvo commented Sep 22, 2021

SIGSEGV - means there is a pointer memory issue in the library

@pvizeli It seems the core does not enable the python fault handler. Is there a reason why not?
This will help in this instance.

@glith Can you set the environment variable PYTHONFAULTHANDLER and try to run again?

@ocalvo ocalvo mentioned this issue Sep 23, 2021
22 tasks
@ocalvo
Copy link
Contributor

ocalvo commented Sep 23, 2021

I was able to repro this in my development environment. As suspected the ReadDevice() call is crashing the process. This is a bug in gammu. I will be following up with a new issue against gammu.

Fatal Python error: Segmentation fault

Current thread 0x00007fd295440700 (most recent call first):
  File "/mnt/s/dd/Repos/ha/core/homeassistant/components/sms/gateway.py", line 44 in sms_pull
  File "/mnt/s/dd/Repos/ha/core/venv/lib/python3.8/site-packages/python_gammu-3.2.3-py3.8-linux-x86_64.egg/gammu/worker.py", line 247 in run
  File "/usr/lib/python3.8/threading.py", line 932 in _bootstrap_inner
  File "/usr/lib/python3.8/threading.py", line 890 in _bootstrap

Thread 0x00007fd296380700 (most recent call first):
  File "/usr/lib/python3.8/concurrent/futures/thread.py", line 78 in _worker
  File "/usr/lib/python3.8/threading.py", line 870 in run
  File "/usr/lib/python3.8/threading.py", line 932 in _bootstrap_inner
  File "/usr/lib/python3.8/threading.py", line 890 in _bootstrap

Thread 0x00007fd296b90700 (most recent call first):
  File "/usr/lib/python3.8/concurrent/futures/thread.py", line 78 in _worker
  File "/usr/lib/python3.8/threading.py", line 870 in run
  File "/usr/lib/python3.8/threading.py", line 932 in _bootstrap_inner
  File "/usr/lib/python3.8/threading.py", line 890 in _bootstrap

Thread 0x00007fd2aa9d0700 (most recent call first):
  File "/usr/lib/python3.8/logging/handlers.py", line 1431 in dequeue
  File "/usr/lib/python3.8/logging/handlers.py", line 1482 in _monitor
  File "/usr/lib/python3.8/threading.py", line 870 in run
  File "/usr/lib/python3.8/threading.py", line 932 in _bootstrap_inner
  File "/usr/lib/python3.8/threading.py", line 890 in _bootstrap

Thread 0x00007fd2ab2e0700 (most recent call first):
  File "/mnt/s/dd/Repos/ha/core/homeassistant/components/recorder/__init__.py", line 647 in _run_event_loop
  File "/mnt/s/dd/Repos/ha/core/homeassistant/components/recorder/__init__.py", line 640 in run
  File "/usr/lib/python3.8/threading.py", line 932 in _bootstrap_inner
  File "/usr/lib/python3.8/threading.py", line 890 in _bootstrap

Thread 0x00007fd2abff0700 (most recent call first):
  File "/usr/lib/python3.8/concurrent/futures/thread.py", line 78 in _worker
  File "/usr/lib/python3.8/threading.py", line 870 in run
  File "/usr/lib/python3.8/threading.py", line 932 in _bootstrap_inner
  File "/usr/lib/python3.8/threading.py", line 890 in _bootstrap

Thread 0x00007fd2b8ec0700 (most recent call first):
  File "/usr/lib/python3.8/concurrent/futures/thread.py", line 78 in _worker
  File "/usr/lib/python3.8/threading.py", line 870 in run
  File "/usr/lib/python3.8/threading.py", line 932 in _bootstrap_inner
  File "/usr/lib/python3.8/threading.py", line 890 in _bootstrap

Thread 0x00007fd2b9750700 (most recent call first):
  File "/usr/lib/python3.8/concurrent/futures/thread.py", line 78 in _worker
  File "/usr/lib/python3.8/threading.py", line 870 in run
  File "/usr/lib/python3.8/threading.py", line 932 in _bootstrap_inner
  File "/usr/lib/python3.8/threading.py", line 890 in _bootstrap

Thread 0x00007fd2b9fa0700 (most recent call first):
  File "/usr/lib/python3.8/concurrent/futures/thread.py", line 78 in _worker
  File "/usr/lib/python3.8/threading.py", line 870 in run
  File "/usr/lib/python3.8/threading.py", line 932 in _bootstrap_inner
  File "/usr/lib/python3.8/threading.py", line 890 in _bootstrap

Thread 0x00007fd2ba7b0700 (most recent call first):
  File "/usr/lib/python3.8/logging/handlers.py", line 1431 in dequeue
  File "/usr/lib/python3.8/logging/handlers.py", line 1482 in _monitor
  File "/usr/lib/python3.8/threading.py", line 870 in run
  File "/usr/lib/python3.8/threading.py", line 932 in _bootstrap_inner
  File "/usr/lib/python3.8/threading.py", line 890 in _bootstrap

Thread 0x00007fd2bd8c0740 (most recent call first):
  File "/usr/lib/python3.8/selectors.py", line 468 in select
  File "/usr/lib/python3.8/asyncio/base_events.py", line 1823 in _run_once
  File "/usr/lib/python3.8/asyncio/base_events.py", line 570 in run_forever
  File "/usr/lib/python3.8/asyncio/base_events.py", line 603 in run_until_complete
  File "/mnt/s/dd/Repos/ha/core/homeassistant/runner.py", line 115 in run
  File "/mnt/s/dd/Repos/ha/core/homeassistant/__main__.py", line 315 in main
  File "/mnt/s/dd/Repos/ha/core/venv/bin/hass", line 33 in <module>
Segmentation fault (core dumped)

@ocalvo
Copy link
Contributor

ocalvo commented Sep 23, 2021

Good new, I have a fix and it is very simple. Please review the change.

@ocalvo
Copy link
Contributor

ocalvo commented Sep 23, 2021

Gammu issue

@github-actions github-actions bot locked and limited conversation to collaborators Oct 23, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants