Garage Door Unexpectedly Opened [SOLVED]

,
1

Roll over from prior post (See: Switches and Plugs Randomly Changing States

I have had an ongoing problem with some switches going on/off unexpectedly but have finally got a log of such an occurrence. In this case it occurs with my garage door. This started months ago after a system upgrade. Here is part of the log. If someone can please help me understand what is happening I would appreciate it. If there is another group I should be posting to, please let me know.

2022-11-07 21:34:20.997 DEBUG (MainThread) [homeassistant.components.http.auth] Authenticated 172.30.32.2 for /api/config using bearer token
2022-11-07 21:34:20.997 DEBUG (MainThread) [homeassistant.components.http.view] Serving /api/config to 172.30.32.2 (auth: True)
2022-11-07 21:34:21.000 DEBUG (MainThread) [homeassistant.components.http.auth] Authenticated 172.30.32.2 for /api/services/cover/close_cover using bearer token
2022-11-07 21:34:21.000 DEBUG (MainThread) [homeassistant.components.http.view] Serving /api/services/cover/close_cover to 172.30.32.2 (auth: True)
2022-11-07 21:34:21.001 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=cover, service=close_cover, service_data=entity_id=cover.garage_door>
2022-11-07 21:34:21.001 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140317000137264] Sending {“id”:11,“type”:“event”,“event”:{“event_type”:“call_service”,“data”:{“domain”:“cover”,“service”:“close_cover”,“service_data”:{“entity_id”:“cover.garage_door”}},“origin”:“LOCAL”,“time_fired”:“2022-11-08T03:34:21.001008+00:00”,“context”:{“id”:“01GHAMV7J8AXHFQW2A6M7P54AB”,“parent_id”:null,“user_id”:“a14bcf3442fb4a5e900b08f1ea4100f4”}}}
2022-11-07 21:34:21.001 DEBUG (Recorder) [homeassistant.components.recorder.core] Processing task: EventTask(event=<Event call_service[L]: domain=cover, service=close_cover, service_data=entity_id=cover.garage_door>)
2022-11-07 21:34:21.002 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f9e4eb7d740> checked out from pool
2022-11-07 21:34:21.003 DEBUG (SyncWorker_6) [paho.mqtt.client] Sending PUBLISH (d0, q1, r0, m139), ‘b’cmnd/GarageDoor/POWER’’, … (2 bytes)
2022-11-07 21:34:21.007 DEBUG (MainThread) [homeassistant.components.mqtt.client] Transmitting message on cmnd/GarageDoor/POWER: ‘ON’, mid: 139
2022-11-07 21:34:21.009 DEBUG (Thread-2 (_thread_main)) [paho.mqtt.client] Received PUBACK (Mid: 139)
2022-11-07 21:34:21.042 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci1/dev_31_C7_B9_5B_3B_90): [‘org.bluez.Device1’, {‘RSSI’: <dbus_fast.signature.Variant (‘n’, -63)>}, []]
2022-11-07 21:34:21.044 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_31_C7_B9_5B_3B_90): [‘org.bluez.Device1’, {‘RSSI’: <dbus_fast.signature.Variant (‘n’, -66)>}, []]
2022-11-07 21:34:21.096 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_E3_60_58_E0_74_B5): [‘org.bluez.Device1’, {‘RSSI’: <dbus_fast.signature.Variant (‘n’, -81)>}, []]
2022-11-07 21:34:21.099 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci1/dev_E3_60_58_E0_68_7F): [‘org.bluez.Device1’, {‘RSSI’: <dbus_fast.signature.Variant (‘n’, -78)>}, []]
2022-11-07 21:34:21.101 DEBUG (MainThread) [custom_components.ble_monitor.sensor] Data measuring sensor received: {‘type’: ‘iBeacon’, ‘packet’: ‘no packet id’, ‘firmware’: ‘iBeacon’, ‘data’: True, ‘rssi’: -78, ‘mac’: ‘E36058E0687F’, ‘uuid’: ‘494e54454c4c495f524f434b535f4857’, ‘tracker_id’: b’INTELLI_ROCKS_HW’, ‘major’: 20596, ‘minor’: 32616, ‘measured power’: -62, ‘cypress temperature’: 24.536250000000003, ‘cypress humidity’: 56.01171875}
2022-11-07 21:34:21.111 DEBUG (Thread-2 (_thread_main)) [paho.mqtt.client] Received PUBLISH (d0, q0, r0, m0), ‘stat/GarageDoor/RESULT’, … (14 bytes)
2022-11-07 21:34:21.113 DEBUG (MainThread) [homeassistant.components.mqtt.client] Received message on stat/GarageDoor/RESULT: b’{“POWER”:“ON”}’

2

You didn’t annotate the log saying which messages you do expect to be there or which devices you own. For example, perhaps some asshole is trying to fuck with you (which would depend on the security of your network).

3

Security wise, my router is set where the Wi-Fi MAC Address must be whitelisted. While there are a few ways around this, it is rather unlikely someone has got into the network (unless it was through via the mobile app, which I also believe is secure.

I tried to pare down the log to just the garage device but I honestly do not know the system at a level where I can easily identify what is related to the garage event and what is not.

4

You also need to have a model of what you expect and how this relates to reality. Everything put together in an IoT system is quite complicated.

Often people have such models in their heads, but when you want help, you first need to write down exactly those things, which is complicated for a lot of people, because they don’t have over two decades of experience doing that.

5

In your case, there is a feature to increase the number of saved “traces” for a given automation and that is probably a level of debugging that would fit your needs and also something that would be easy to understand for others.

6

I should have been clearer in my issue. The garage switch has been enabled and working perfectly for about 6 months before this. I can document, in detail, what it does, how it is wired, and the automation associated to it. If that is necessary I can provide that.

The issue is, once the Home Assistant core was updated (months ago) the automation is being triggered without user interaction. No other changes to the system had occurred.

I have set traces on the device and the system before but the trace shows when it was triggered. Nothing indicated what was triggering it. I turned on debug logging and pared the log to the moment the switch was triggered. I am looking for the why it was triggered and need a bit of help to understand the log.

7

You can also add Wireshark to your debugging setup. Systems don’t just do things.

8

Yes, Wireshark can tell me if a packet is sent to the specific device and I can pursue that. But to the comment “Systems don’t just do things”, having been in process analysis for a decade, designed systems prior to that, and was a developer for over a decade prior to that, systems do “just do things” because the more complex they are and the more integration are connected the higher the chance of unexpected or unhandled signals occur and undiscovered bugs exist.

9

Don’t be too quick to rule out environmental concerns - Ny garage started randomly opening a year ago at weird times. I was on Smartthings at the time and SWORE something was triggering the garage… To my suprise - nope.

No - I live near a US military installation and Milspec radios stomp on the radio range typically used by US rolling code garage door openers and have been known to trigger an open. I cleared all codes on all my door openers and re-registered my handsets and it hasn’t happened since. I do have a friend with a really nice spectrum analyzer and one night on a whim - fueled by a lot of burbon, we were looking at signals and sure enough theres a lot of strong activity in the range of the frequencies listed on my Craftsman GDOs…

May not be your issue - but worth eliminating before you chase that wild goose.

10

Yes, I can see that happening. In my case the garage door opening is one of about 3 devices that change or go on or both. It just happens to be the one I get notification on when it occurs (alert the door is open) so it was easy to pull the info from the log. I have had a light in the living room kick on unexpectedly, and the same with a light in my wife’s office office and in my office. All of these have been running stable for a long time.

Also, from prior posts, there is at least one other person who has the same problem.
I’m just trying to do the analysis but to your point, anything is possible.

1 Like
11

What brand/model of lights and GDO interface? Your troubleshooting will depend on the tech you are using.

12

The GDO is a Shelly Plus 1 module and based off DigiblurDYI DYI Smart Garage Door Opener (https://www.youtube.com/watch?v=nSrm6h7r-KE&t=69s)

One light is a TP-Link smart lightbulb, one is a Tasmota flashed smart lightbulb, and the last device affected (at least twice) is a Tasmota flashed smart switch. I have turned on the Tasmota debugging via sys-logging as well as MQTT logging. All the logs I looked at show they receive a signal from HA and then turn on.

Which is why I turned on debugging in HA that produced the above log.

1 Like
13

To try to debug HA is a huge task, but start to look at the code related to the garage door, like have you covered all the states possible for sensors and switches, like f.ex. unavailable and unknown?
How does these states affect scripts and automations?

14

Agreed but I am not trying to debug HA, I am just trying to understand what is triggering the switch and why.

In answer to your questions about the code related to the garage door, there is no automation, and no scripts. The way it was programmed and works is via the UI where there is a slide switch and a button. the button, when triggered via the UI, performs a “call service” and toggles the switch. The slide switch is just what is in the second image. There is also a reed switch to show state that when triggered send out a notification AFTER the garage door has opened and another if it is opened for more than 15 minutes.

There is one script I was using for testing but HA shows it has not been triggered since March 20th - 8 months ago. That script just performs a “Turn on switch.tasmota_garage”

image
image548×852 31.6 KB

image
image994×409 17.5 KB

15

From what I can tell from the Log, the triggered is listed in this line where the user_id is “a14bcf3442fb4a5e900b08f1ea4100f4”. That user ID is the Supervisor. I am trying to understand why the Supervisor is triggering the switch.

[homeassistant.components.websocket_api.http.connection] [140317000137264] Sending {“id”:11,“type”:“event”,“event”:{“event_type”:“call_service”,“data”:{“domain”:“cover”,“service”:“close_cover”,“service_data”:{“entity_id”:“cover.garage_door”}},“origin”:“LOCAL”,“time_fired”:“2022-11-08T03:34:21.001008+00:00”,“context”:{“id”:“01GHAMV7J8AXHFQW2A6M7P54AB”,“parent_id”:null,“user_id”:“a14bcf3442fb4a5e900b08f1ea4100f4”}}}

16

Supervisor is listed any time an automation triggers something. For instance I use Node Red heavily. All of my NR automation shows as triggered by Supervisor.

Do you have Alexa or Google by chance? If Alexa, do you have hunches turned on?

17

I have an Alexa and although hunches was enable [not now] there were no hunches programmed. I also have only one Red-Node and it was just a test entry with no triggers and does not reference the garage door.

One more questions about the log entry. I noticed there is an ID referenced in the same line as the user id.

context”:{“id”:“01GHAMV7J8AXHFQW2A6M7P54AB”,“parent_id”:null,“user_id”:“a14bcf3442fb4a5e900b08f1ea4100f4”}

I am assuming the “id”:“01GHAMV7J8AXHFQW2A6M7P54AB” referring to something specific in HA maybe like an automation or trigger. Is there a way to determine what the id is associated to?

18

Quick update. Looking at the log entries I figured out the entries were the Supervisor triggering the notification script that the door has opened. There is no log entry trigging opening the door. That meant, to @NathanCu point above, it is most likely environmental. I disabled the ability for HA to open the door but kept the notification in place so that HA will tell me when it is opened. If it opens unexpectedly again then I will be sure.

Thanks for the help.

1 Like
19

I have spent a fair amount of time trying to understand why specific devices activated (garage door opening & lights going on or off) on a system that was very stable for almost a year and it turns out lights_on gets the prize for the suggestion “perhaps some a–hole is trying to f*ck with you.”
That and my complacency with individual device security.

While my WiFi is relatively secure (my neighbor, being an EE got into it several times in the past, forcing me to go with whitelisting the mac addresses of all devices), it turns out that the asshole has a way to cause one or more of my Tasmota devices to reset, making the Tasmota WiFi access-point available. It was my own damn fault since when he first moved in, and me being neighborly, I gave him a Tasmota device to play with. From the Tasmota access point, it appears, he was only able to send a message across the MQTT server to another device, specifically to turn on the garage door and most recently, turning on a light and making it red for Valentine’s Day. Seems the fatherless-rodent has a sense of humor.

Solution was to disable all Tasmota devices from providing an access point and ensuring each device using the MQTT service has its own password. Still working on turning on TLS security.

Funny thing was when he tried to access my Samsung TV’s built-in access point with his S22 phone. The TV had a pop-up that said: Do you want to allow [neighbor’s name]’s S22 to connect?”

Once that happened the rest fell into place. Leastwise so far.

Thanks for the help.

20

I wonder if there is a way that the police can intervene.

I’m sure that someone hacking into their neighbors network infrastructure is against some FCC regulation in some way. I would be surprised if not.