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

HA non-responsive with LIRC enabled #2266

Closed
kaustubhphatak opened this issue Jun 10, 2016 · 17 comments
Closed

HA non-responsive with LIRC enabled #2266

kaustubhphatak opened this issue Jun 10, 2016 · 17 comments

Comments

@kaustubhphatak
Copy link
Contributor

Home Assistant release (hass --version):
hass --version
0.21.0

Python release (python3 --version):
python3 --version
Python 3.4.2

Component/platform:
lirc

Description of problem:
With LIRC enabled, the HA instance completely freezes. Even 'systemctl restart home-assistant' doesn't work and it ends up killing the instance after a timeout waiting for the process to end graciously.

Jun 10 00:39:48 pi2 hass[446]: INFO:homeassistant.components.recorder:Closing database
Jun 10 00:40:55 pi2 systemd[1]: home-assistant.service stop-sigterm timed out. Killing.
Jun 10 00:40:56 pi2 systemd[1]: home-assistant.service: main process exited, code=killed, status=9/KILL
Jun 10 00:40:56 pi2 systemd[1]: Unit home-assistant.service entered failed state.

However, in case you keep pressing some button on the IR remote, the HA instance doesn't freeze. ex:

Froze for 4 minutes at the below line:
Jun 10 00:31:10 pi2 hass[446]: INFO:homeassistant.components.mysensors:Adding new devices: <Entity Thermostat 8 0: None>
After I pressed a key on my IR remote, it started up again for some seconds and froze again.

Jun 10 00:35:46 pi2 hass[446]: INFO:homeassistant.core:Timer:starting
Jun 10 00:35:46 pi2 hass[446]: INFO:mysensors.mysensors:/dev/ttyUSB0 is open...
Jun 10 00:35:46 pi2 hass[446]: INFO:mysensors.mysensors:Connected to /dev/ttyUSB0
Jun 10 00:35:46 pi2 hass[446]: INFO:homeassistant.components.lirc:Got new LIRC code KEY_POWER
Jun 10 00:35:46 pi2 hass[446]: INFO:homeassistant.core:Bus:Handling <Event state_changed[L]: entity_id=sensor.thermostat_8_0, new_state=<state sensor.thermostat_8_0=unavailable; friendly_name=Thermostat 8 0 @ 2016-06-10T00:31:10.555563+05:30>, old_state=None>
Jun 10 00:35:46 pi2 hass[446]: WARNING:mysensors.mysensors:Error decoding message from gateway, probably received bad byte.
Jun 10 00:35:46 pi2 hass[446]: INFO:homeassistant.core:Bus:Handling <Event state_changed[L]: entity_id=sensor.thermostat_8_0, new_state=<state sensor.thermostat_8_0=30.5; node_id=8, device=/dev/ttyUSB0, battery_level=0, unit_of_measurement=°C, V_TEMP=30.5, friendly_name=Thermostat 8 0, child_id=0 @ 2016-06-10T00:35:46.137893+05:30>, old_state=<state sensor.thermostat_8_0=unavailable; friendly_name=Thermostat 8 0 @ 2016-06-10T00:31:10.555563+05:30>>
Jun 10 00:35:46 pi2 hass[446]: INFO:homeassistant.components.mysensors:Adding new devices: <Entity Temperature Sensor 1 0: None>
Jun 10 00:35:46 pi2 hass[446]: INFO:homeassistant.core:Bus:Handling <Event ir_command_received[L]: button_name=KEY_POWER>

I had to keep the IR remote key depressed for a long time to successfully start and then stop the ha instance and remove lirc from the config.

Expected:
HA instance doesn't freeze with LIRC enabled.

Problem-relevant configuration.yaml entries and steps to reproduce:

# LIRC Component
lirc:
cat ~/.lircrc 
begin
    remote = hathway
    button = KEY_MUTE
    prog = home-assistant
    config = KEY_MUTE
end
begin
    remote = hathway
    button = KEY_POWER
    prog = home-assistant
    config = KEY_POWER
end

Traceback (if applicable):
N/A

Additional info:

@balloob
Copy link
Member

balloob commented Jun 10, 2016

CC @partofthething

@partofthething
Copy link
Contributor

Yikes. Sorry about that. I'm not sure why that would happen. I did an unrelated error handling PR just a minute ago (#2267) but that would only help if you saw an exception in the log related to a lirc.NextCodeError exception, which I encountered a few times on my Pi2 with a similar setup. But that just stops LIRC from responding, it didn't crash or freeze the whole system.

The whole LIRC component is in its own separate thread so it's indeed surprising that this happened. Are there any other useful log files? Does LIRC work well if you just shut down home-assistant and use the irexec -n home-assistant command?

@kaustubhphatak
Copy link
Contributor Author

There is actually no exception in the log file related to the lirc.NextCodeError.

lirc is working well with the irexec -n home-assistant. It is properly recognising the IR key presses.

Also, there doesn't seem to be any other logs generated which can indicate any issue.

@partofthething
Copy link
Contributor

Fascinating. Can you attach the output of grep -i lirc home-assistant.log?

@partofthething
Copy link
Contributor

Also, output from ps aux | grep lirc might be useful.

@kaustubhphatak
Copy link
Contributor Author

Here it is...

pi@pi2:~/.homeassistant$ grep -i lirc home-assistant.log
pi@pi2:~/.homeassistant$ 

pi@pi2:~/.homeassistant$ ps aux | grep lirc
root       604  0.0  0.1   3904  1600 ?        Ss   10:17   0:00 /usr/sbin/lircd --driver=default --device=/dev/lirc0 --uinput
pi        2092  0.0  0.1   4284  1844 pts/0    S+   10:30   0:00 grep lirc

@partofthething
Copy link
Contributor

partofthething commented Jun 10, 2016

Ok I think the home-assistant.log here was truncated after you removed lirc: from your config file and restarted. Can you put it back in there, replicate the issue again, post the results of the grep command again, and maybe save the entire log of the session in case we need to dig in further? Maybe reboot the Pi before doing all that just in case.

@kaustubhphatak
Copy link
Contributor Author

Actually I put back the lirc: in the configuration.yaml and restarted ha
before checking the log file.
If you want I can send you the output of the journalctl post startup with
lirc: enabled in sometime.

Rgds/KP

On 10 June 2016 at 19:40, Nick Touran [email protected] wrote:

Ok I think the home-assistant.log here was truncated after you removed
lirc: from your config file and restarted. Can you put it back in there,
replicate the issue again, post the results of the grep command again, and
maybe save the entire log of the session in case we need to dig in further?
Maybe reboot the Pi before doing all that just in case.


You are receiving this because you authored the thread.
Reply to this email directly, view it on GitHub
#2266 (comment),
or mute the thread
https://github.com/notifications/unsubscribe/AEPj_gfmDZkGyjIHfwiRnuAL7QIb8Qirks5qKXBOgaJpZM4IymbS
.

@partofthething
Copy link
Contributor

partofthething commented Jun 10, 2016

Very strange. In that case lirc isn't even starting up at all for you.

Here's what mine gives after starting hass, pressing some buttons, and stopping hass, so this is the expected behavior

 $ grep -i lirc home-assistant.log
INFO:homeassistant.loader:Loaded lirc from homeassistant.components.lirc
INFO:homeassistant.core:Bus:Handling <Event component_loaded[L]: component=lirc>
INFO:homeassistant.components.lirc:Got new LIRC code KEY_2
INFO:homeassistant.components.lirc:Got new LIRC code KEY_1
INFO:homeassistant.components.lirc:LIRC interface thread stopped

The log you mention would be helpful.

UPDATE: I accidentally included this line but that's in my unpushed code. You won't have this:

INFO:homeassistant.components.lirc:LIRC interface thread started

Also, it's clear that when you go to the command line stop it it doesn't stop. But just to clarify, you're saying that HA freezes on start completely? No UI, nothing?

@kaustubhphatak
Copy link
Contributor Author

Hi,

I have now performed the following steps:

  1. Deleted the old home-assistant.log
  2. Enabled lirc: in configuration.yaml
  3. Restart pi.
  4. Started home-assistant using systemctl (I had disabled autostart to be able to catch the logs properly)
  5. Monitored the journal logs using sudo journalctl -f -u home-assistant

Now if you check the journal, HA process is stuck at Jun 10 15:59:46 pi2 hass[11986]: INFO:mysensors.mysensors:Trying to connect to /dev/ttyUSB0 . Nothing is taking place. And as soon as I press a key on my IR remote, all the threads are brought to life again.

Jun 10 16:01:34 pi2 hass[11986]: INFO:homeassistant.core:Timer:starting
Jun 10 16:01:34 pi2 hass[11986]: INFO:homeassistant.components.mysensors:Adding new devices: <Entity Thermostat 8 0: None>
Jun 10 16:01:34 pi2 hass[11986]: INFO:homeassistant.components.lirc:Got new LIRC code KEY_POWER
Jun 10 16:01:34 pi2 hass[11986]: INFO:homeassistant.core:Bus:Handling <Event state_changed[L]: entity_id=sensor.thermostat_8_0, new_state=<state sensor.thermostat_8_0=unavailable; friendly_name=Thermostat 8 0 @ 2016-06-10T16:01:34.613715+05:30>, old_state=None>
Jun 10 16:01:34 pi2 hass[11986]: INFO:mysensors.mysensors:/dev/ttyUSB0 is open...
Jun 10 16:01:34 pi2 hass[11986]: INFO:mysensors.mysensors:Connected to /dev/ttyUSB0
Jun 10 16:01:34 pi2 hass[11986]: INFO:homeassistant.core:Bus:Handling <Event ir_command_received[L]: button_name=KEY_POWER>
Jun 10 16:03:21 pi2 hass[11986]: INFO:homeassistant.core:Bus:Handling <Event state_changed[L]: entity_id=sensor.thermostat_8_0, new_state=<state sensor.thermostat_8_0=30.5; V_TEMP=30.5, friendly_name=Thermostat 8 0, unit_of_measurement=°C, device=/dev/ttyUSB0, battery_level=0, node_id=8, child_id=0 @ 2016-06-10T16:01:34.659010+05:30>, old_state=<state sensor.thermostat_8_0=unavailable; friendly_name=Thermostat 8 0 @ 2016-06-10T16:01:34.613715+05:30>>
Jun 10 16:03:21 pi2 hass[11986]: INFO:homeassistant.components.lirc:Got new LIRC code KEY_POWER
Jun 10 16:03:21 pi2 hass[11986]: INFO:homeassistant.components.mysensors:Adding new devices: <Entity Temperature Sensor 1 0: None>
Jun 10 16:03:22 pi2 hass[11986]: INFO:homeassistant.core:Bus:Handling <Event state_changed[L]: entity_id=sensor.temperature_sensor_1_0, new_state=<state sensor.temperature_sensor_1_0=unavailable; icon=mdi:thermometer, friendly_name=Outdoor Temperature @ 2016-06-10T16:03:21.986024+05:30>, old_state=None>
Jun 10 16:03:22 pi2 hass[11986]: INFO:homeassistant.core:Bus:Handling <Event ir_command_received[L]: button_name=KEY_POWER>

It stops again at 16:03:22 till I press another key. Finally when I repeatedly keep pressing the keys on the IR remote, the interface is able to do something, but most of the processes are already timed out.

Finally I issued a sudo systemctl restart home-assistant at 16:07:13 which also is not responded by the HA process till i press a key on my remote.

I have attached the log and the journalctl output as per below links.

home-assistant.journal.lirc.txt

home-assistant.lirc.log.txt

@kaustubhphatak
Copy link
Contributor Author

Also to add, you are right, when i say HA is frozen it means no UI or anything till i press a key on the IR. If i keep pressing keys on my remote, i can get HA to work, it will stop responding as soon as i stop pressing any key!

What i feel is, somehow in my HA installation, LIRC is starting up, but its not being forked in its own thread somehow!

@partofthething
Copy link
Contributor

Check this out: tompreston/python-lirc#2 (comment). In the python-lirc dependency there was an issue just like this:

Every thread seems to be put on hold unless I hold down a button on the remote. I'm sure this isn't on purpose.

This was apparently fixed in python-lirc 1.2.1. What version of that library do you have?

$ pip3 show python-lirc
---
Metadata-Version: 1.1
Name: python-lirc
Version: 1.2.1

If you have an older version, run pip3 install --upgrade python-lirc and your issue will be fixed.

NOTE: The dependency system of hass should have caught this but we put it as a non-forced installation because not everyone has the lirc libraries required to build this module. If this fixes your problem I will add a step to the installation instructions to ensure people have the proper version.

@kaustubhphatak
Copy link
Contributor Author

You are right.. Its seems to be the same issue, however its not being fixed by the pip3 install --upgrade python-lirc.

Looks like it was installed in my system using a debian package and its now conflicting with the installation in python somehow. Trying to clean the package mess now! Will let know the update so that other might not face similar fate.

Thanks a lot for your help :) Cheers Mate !

@partofthething
Copy link
Contributor

Awesome. Yeah try uninstalling the package through debian and then installing with the pip3 line. Throw a sudo before the pip3 and that should really work.

@kaustubhphatak
Copy link
Contributor Author

kaustubhphatak commented Jun 11, 2016

Actually sudo pip3 install --upgrade python-lirc did not work even after cleanup of cache and other traces. I waited for ha to throw an error.

Jun 11 10:08:07 pi2 hass[6671]: ERROR:homeassistant.bootstrap:Error during setup of component lirc
Jun 11 10:08:07 pi2 hass[6671]: Traceback (most recent call last):
Jun 11 10:08:07 pi2 hass[6671]: File "/usr/local/lib/python3.4/dist-packages/homeassistant/bootstrap.py", line 157, in _setup_component
Jun 11 10:08:07 pi2 hass[6671]: if not component.setup(hass, config):
Jun 11 10:08:07 pi2 hass[6671]: File "/usr/local/lib/python3.4/dist-packages/homeassistant/components/lirc.py", line 29, in setup
Jun 11 10:08:07 pi2 hass[6671]: import lirc
Jun 11 10:08:07 pi2 hass[6671]: ImportError: No module named 'lirc'

Post this I installed sudo pip3 install python-lirc. Still the freezing issue was present.

Actually this seems to be a knows issue Python Lirc blocks code even when blocking is off

I managed to solve this by modifying the following line in lirc.pyx from https://github.com/tompreston/python-lirc and then building python-lirc from source.

Original Line:
def init(program_name, config_filename=None, blocking=True, verbose=False):

Modified Line:
def init(program_name, config_filename=None, blocking=False, verbose=False):

So Finally I am able to use LIRC component on HA...

Cheers 👍

@balloob
Copy link
Member

balloob commented Jun 11, 2016

It's interesting this solves it for you as we explicitly pass in blocking=False: https://github.com/home-assistant/home-assistant/blob/dev/homeassistant/components/lirc.py#L31-L34

@kaustubhphatak
Copy link
Contributor Author

Correct, I saw that.. Actually I am also wondering why this might be the
case. Very very weird!!

On 11 June 2016 at 10:41, Paulus Schoutsen [email protected] wrote:

It's interesting this solves it for you as we explicitly pass in
blocking=False:
https://github.com/home-assistant/home-assistant/blob/dev/homeassistant/components/lirc.py#L31-L34


You are receiving this because you modified the open/close state.
Reply to this email directly, view it on GitHub
#2266 (comment),
or mute the thread
https://github.com/notifications/unsubscribe/AEPj_iHIkWWyLerrbgbCWPdP8qyhPWhsks5qKkNogaJpZM4IymbS
.

@home-assistant home-assistant locked and limited conversation to collaborators Mar 17, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants