wonderslug / MMM-HomeAssistantDisplay

A Magic Mirror Module to display information from Home Assistant.
MIT License
83 stars 6 forks source link

Home Assistant is holding new connections open with each launch of Magic Mirror #14

Open MeighenHouse opened 1 year ago

MeighenHouse commented 1 year ago

This is undoubtedly an edge case and I'm not sure where the bug is exactly, but, I'm using Magic Mirror as a screensaver on my android TV. It simply calls up the webpage and everything works great.

However, it appears that Home Assistant is holding open the connection between MagicMirror and itself each time the webpage is launched. And after some number of times of the screensaver popping on and going off it eventually uses up all the file descriptors in the docker container and Home Assistant starts producing error messages and stops working right.

I'm not sure where the issue actually is. Is it in MagicMirror for not closing ports/keeping them open? Or is it in Home Assistant for just hanging on to them for so long.

Last time out of 1024 file descriptors home assistant had a connection to magic mirror for ~950 of them.

That's as much as I've been able to nail down so far.

wonderslug commented 1 year ago

Hey,

This sounds odd. The way it is currently written is that is caches the WebSocket connection to the HA service based on the module id. So the same connection is reused by every browser instance hitting it.

There was an update to the underlying homeassistant-ws library its using which updates the ws and isomorphic-ws libraries its dependent on.

Can you try editing the package.json and change the homeassistant-ws version to 2.2.0 and rerun the npm install for the module. Lets try and see if the updated libraries make any difference. I dont see anything specific in them about leaking file handles, but we can see whats up.

MeighenHouse commented 1 year ago

Ok, just to be clear, this is the section I'm supposed to edit, right?

"dependencies": { "@mdi/font": "latest", "backoff": "^2.5.0", "homeassistant": "^0.2.0", "homeassistant-ws": "^0.2.1" },

And does the last "^0.2.1" become "^2.2.1"? That seems like quite the jump.

I've been doing some digging on the problem and I'm starting to reach the limits of my understanding. Home Assistant is continuing to increase the number of connections to the ip address 172.18.0.3 which is the internal ip of my magic mirror docker container, but when I try to look up to see open connections for the container process all I see are files and no network connections. Full Disclosure: I'm not sure I'm doing it right.

Does the magicmirror server do any processing/network connections, or is it done all within the served page on the browser?

MeighenHouse commented 1 year ago

Ok, was looking through the docker log for magicmirroc and before I restarted the container this was repeating:

[20.04.2023 22:35.57.734] [DEBUG] [MMM-HomeAssistantDisplay] [ 'Found listening connection (module_5_MMM-HomeAssistantDisplay) for entity sensor.alyssa_s_room_voc' ] [20.04.2023 22:35.57.734] [DEBUG] [MMM-HomeAssistantDisplay] [ 'Found listening connection (module_5_MMM-HomeAssistantDisplay) for entity sensor.alyssa_s_room_voc' ] [20.04.2023 22:35.57.735] [DEBUG] [MMM-HomeAssistantDisplay] [ 'Found listening connection (module_5_MMM-HomeAssistantDisplay) for entity sensor.alyssa_s_room_voc' ] [20.04.2023 22:35.57.735] [DEBUG] [MMM-HomeAssistantDisplay] [ 'Found listening connection (module_5_MMM-HomeAssistantDisplay) for entity sensor.alyssa_s_room_voc' ] [20.04.2023 22:35.57.736] [DEBUG] [MMM-HomeAssistantDisplay] [ 'Found listening connection (module_5_MMM-HomeAssistantDisplay) for entity sensor.alyssa_s_room_voc' ] [20.04.2023 22:35.57.737] [DEBUG] [MMM-HomeAssistantDisplay] [ 'Found listening connection (module_5_MMM-HomeAssistantDisplay) for entity sensor.alyssa_s_room_voc' ] [20.04.2023 22:35.57.737] [DEBUG] [MMM-HomeAssistantDisplay] [ 'Found listening connection (module_5_MMM-HomeAssistantDisplay) for entity sensor.alyssa_s_room_voc'

I have a second voc sensor using the same integration and still the final page shows all the correct info.

After I restarted MM (and the connections in Home Assistant dropped again) I noticed these lines in the log:

[20.04.2023 22:40.37.143] [ERROR] [MMM-HomeAssistantDisplay] [ 'Unable to connect to Home Assistant for module module_5_MMM-HomeAssistantDisplay failed with message: ', "Cannot read properties of undefined (reading 'info')" ] [20.04.2023 22:40.45.284] [INFO] [MMM-HomeAssistantDisplay] [ 'HomeAssistant connected for module_6_MMM-HomeAssistantDisplay' ] [20.04.2023 22:40.45.295] [INFO] [MMM-HomeAssistantDisplay] [ 'HomeAssistant connected for module_7_MMM-HomeAssistantDisplay' ] [20.04.2023 22:40.45.301] [INFO] [MMM-HomeAssistantDisplay] [ 'HomeAssistant connected for module_8_MMM-HomeAssistantDisplay' ] [20.04.2023 22:40.45.318] [INFO] [MMM-HomeAssistantDisplay] [ 'Conected to Home Assistant for module_6_MMM-HomeAssistantDisplay after 0 retries' ] [20.04.2023 22:40.45.318] [INFO] [MMM-HomeAssistantDisplay] [ 'Conected to Home Assistant for module_7_MMM-HomeAssistantDisplay after 0 retries' ] [20.04.2023 22:40.45.319] [INFO] [MMM-HomeAssistantDisplay] [ 'Conected to Home Assistant for module_8_MMM-HomeAssistantDisplay after 0 retries' ] [20.04.2023 22:40.47.159] [INFO] [MMM-HomeAssistantDisplay] [ 'Conected to Home Assistant for module_5_MMM-HomeAssistantDisplay after 19 retries' ]

wonderslug commented 1 year ago

My Bad..."homeassistant-ws": "^0.2.1" should change to "homeassistant-ws": "^0.2.2"

The Magic Mirror server handles the connection to the Home Assistant server. The modules node_helper.js is run on the server and a web socket connection gets setup between the MM server and the browser (or Electron instance) which is just rendering the display as HTML.

Im not sure why the logs are showing and error reading from 'info'. Im not seeing anything in the MMM-HomeAssistantDisplay that would do that.

MeighenHouse commented 1 year ago

I've done the 0.2.2 npm install and no change. Obviously I have to have something messed up.

Looking through the logs it seems when HomeAssistantDisplay generates a message, it does so for each open connection. Through Webmin I was able to see that Home Assistant had 22 connections open to MagicMirror and in between the log messages for MMM-BackgroundSlideshow there is a burst of 22 log entries HAD. I'll attact part of the log to see if anything makes sense to you.

Also, this is my entry in config.js that contains the references to the sensor messages.

    {
        module: 'MMM-HomeAssistantDisplay',
        position: 'top_left',
        config: {
            host: "192.168.1.100",
            token: 
            port: 8123,
            useTLS: false,
            title: "House Status",
            useModuleTigger: false,
            moduleTriggerTemplate: '{{ states.media_player.side_room_speaker.state == "playing"}}',
            moduleTriggerEntities: ["sensor.alyssa_s_room_temperature","sensor.vanessas_room_temperature","sensor.alyssa_s_room_voc","'sensor.vanessas_room_voc","input_boolean.campfire","switch.sonoff_1000df774f_1","switch.sonoff_1000df774f_2"],
            class: "playing_in_side_room",
            sections: [{
                    triggerEntities: ["sensor.alyssa_s_room_temperature","sensor.vanessas_room_temperature","sensor.alyssa_s_room_voc","'sensor.vanessas_room_voc","input_boolean.campfire","switch.sonoff_1000df774f_1","switch.sonoff_1000df774f_2"],
                    displayTemplate: `
            <div>Alyssa's Room Temp: {{states('sensor.alyssa_s_room_temperature')}}<i class='mdi mdi-temperature-celsius'></i><i class='mdi mdi-thermometer'></i></div>
            <div>Vanessa's Room Temp: {{states('sensor.vanessas_room_temperature')}}<i class='mdi mdi-temperature-celsius'></i><i class='mdi mdi-thermometer'></i></div>
            {% if states('sensor.alyssa_s_room_voc')| int >= states('input_number.voc_hrv_low_speed_trigger') |int %}<div>Alyssa's Room VOC: {{ states('sensor.alyssa_s_room_voc')|int }} ppb <i class=' mdi mdi-flower-pollen'></i></div>{% endif %}
            {% if states('sensor.vanessas_room_voc')| int >= states('input_number.voc_hrv_low_speed_trigger') |int %}<div>Vanessa's Room VOC: {{ states('sensor.vanessas_room_voc')|int }} ppb <i class=' mdi mdi-flower-pollen'></i></div>{% endif %}
            {% if states.input_boolean.campfire.state == "on" %}<i class='mdi mdi-fire-circle'></i>{% endif %}
            {% if states.switch.sonoff_1000df774f_1.state == "on" %}<i class='mdi mdi-fan-chevron-down'></i>{% endif %}
            {% if states.switch.sonoff_1000df774f_2.state == "on" %}<i class='mdi mdi-fan-chevron-up'></i>{% endif %}
                    `,
                class: "playing_info"
                }]
            },
      },

Magic Mirror Log.txt