Weird behaviour: OH3 triggered all items on its own

[smvsousa (Sergio Sousa)]

Hi everyone,

I had a very strange situation last night. And that was a big scale happening of a couple of previous occurrences.
About 2AM, all my lights turned on, all my RSs opened, pumps turned on, etc. So, pretty much everything went ON without anyone triggering it directly.
I’ve successfully turned off most of the things, but from time to time others turned on.

Had a quick look at the logs and could find a series of errors which were not common and which disappeared after a restart of OH.

Not sharing any logs for the time being. (I can do later) .

Just trying to find out if someone else has been in a similar situation before or has any high level clue of what might have happened. (I’m considering hacking as an option, by the way).

Thanks so much,

Sérgio

[Felix_Schneider]

@smvsousa

I’m considering hacking as an option, by the way

If so you should really look into this!

• Do you see anything strange in /var/log/auth.log? Try cat /var/log/auth.log | grep -i 'Failed'
• Is you openHAB instance reachable from the internet with a port forwarding?

---

@smvsousa

Not sharing any logs for the time being. (I can do later) .

Without seeing the logs we can’t really help you. Maybe some rule triggers uncontrolled and causes this.

[rossko57]

HELP! Someone Hacked my system? Lights and other turning on and off randomly. OH3 Snapshot

Help!! something weird is happening. From two days my lights in home goes on and off, sprinkler system also and camera settings. here is part of log from today: 2020-12-06 00:36:57.331 [DEBUG] [qtt.generic.AbstractMQTTThingHandler] - Successfully published value OFF to topic /lampa-pod-tv/switch/cmd 2020-12-06 00:36:57.998 [INFO ] [smarthome.event.ItemCommandEvent ] - Item 'lampa_wyspa_switch' received command OFF 2020-12-06 00:36:58.010 [INFO ] [rthome.event.ItemStatePredictedEvent] -…

Unexpected events this morning

Hi, at about 5am this morning all my devices, lights, heating all came on and Alexa went to volume 10 and started shouting something! I switched everything off using the app, and a few minutes later all the lights etc came on again. After a few repeats I got up and rebooted the raspberry. And then it happened again! So I disconnected the internet and went back to bed. A few hours later I reconnected the internet and all is fine. Looking at the logs I can see items gettting On commands but …

[basriram (Sriram Balakrishnan)]

It did happen to me as well with OH3 and it was a hack. I had accidentally turned port forwarding on my firewall and someone managed to craft the URL to match openhab and access the default OH3 UI. Now I have configured nginx reverse proxy with authentication. FWIW the ip address of the hacker originated somewhere in the UK (vodaphone network).

[smvsousa (Sergio Sousa)]

Thanks for the feedback Felix,

Honestly, didn’t see anything strange on auth.log. However, my firewall stopped quite a few Web attacks to my server. I was considering that it might have not stopped all.
And that answers your other question. Yes, I did have OH port accessible from the Internet. I’ve opened quite some time ago for some tests and forgot to close it. It is closed now.

When I was mentioning weird data in the logs, I meant openhab.log. Here’s part of it:

Blockquote
2021-02-21 01:39:10.831 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item for widget org.openhab.core.model.sitemap.sitemap.Switch
2021-02-21 01:39:13.346 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item ‘test_mail’ for widget org.openhab.core.model.sitemap.sitemap.Switch
2021-02-21 01:39:13.348 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item ‘test_mail’ for widget org.openhab.core.model.sitemap.sitemap.Switch
2021-02-21 01:39:13.349 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item for widget org.openhab.core.model.sitemap.sitemap.Switch
2021-02-21 01:39:13.864 [INFO ] [org.openhab.core.model.script.FILE ] - Raising: rs_salaestar_janela
2021-02-21 01:39:13.882 [INFO ] [org.openhab.core.model.script.FILE ] - Raising: rs_cozinha_portada
2021-02-21 01:39:13.892 [INFO ] [org.openhab.core.model.script.FILE ] - Raising: rs_salaestar_portada
2021-02-21 01:39:13.899 [INFO ] [org.openhab.core.model.script.FILE ] - Raising: rs_salajantar_janela
2021-02-21 01:39:13.906 [INFO ] [org.openhab.core.model.script.FILE ] - Raising: rs_escritorio
2021-02-21 01:39:14.566 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item ‘test_mail’ for widget org.openhab.core.model.sitemap.sitemap.Switch
2021-02-21 01:39:14.731 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item ‘test_mail’ for widget org.openhab.core.model.sitemap.sitemap.Switch
2021-02-21 01:39:14.732 [ERROR] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve item for widget org.openhab.core.model.sitemap.sitemap.Switch

I have hundreds of these errors and warning above. They have disapeared after restarting OH.

And, before that I’ve found these older ones that I don’t understand:

Blockquote
2021-02-20 20:21:57.111 [WARN ] [io.openhabcloud.internal.CloudClient] - Jetty request 26436356 failed: null
2021-02-20 20:21:57.113 [WARN ] [io.openhabcloud.internal.CloudClient] - Response Failure: null

Blockquote
2021-02-18 05:16:24.021 [WARN ] [org.eclipse.jetty.server.HttpChannel] - www.voanews.com:443
java.lang.StringIndexOutOfBoundsException: begin 0, end -1, length 19
at java.lang.String.checkBoundsBeginEnd(String.java:3319) ~[?:?]
at java.lang.String.substring(String.java:1874) ~[?:?]
at org.ops4j.pax.web.service.spi.model.ServerModel.matchPathToContext(ServerModel.java:365) ~[?:?]
at org.ops4j.pax.web.service.spi.model.ServerModel.matchPathToContext(ServerModel.java:305) ~[?:?]
at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:65) ~[?:?]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.Server.handle(Server.java:494) ~[bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:374) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:268) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) [bundleFile:9.4.20.v20190813]
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) [bundleFile:9.4.20.v20190813]
at java.lang.Thread.run(Thread.java:834) [?:?]
2021-02-18 05:16:24.464 [WARN ] [org.eclipse.jetty.server.HttpChannel] - www.so.com:443
java.lang.StringIndexOutOfBoundsException: begin 0, end -1, length 14
at java.lang.String.checkBoundsBeginEnd(String.java:3319) ~[?:?]
at java.lang.String.substring(String.java:1874) ~[?:?]

Then on events.log, at the time of the event …

Blockquote
2021-02-21 01:39:40.438 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘ilu_suite_tecto’ received command ON
2021-02-21 01:39:40.452 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘ilu_suite_tecto’ predicted to become ON
2021-02-21 01:39:40.460 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_suite_porta’ changed from 68 to 64
2021-02-21 01:39:40.462 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘ilu_suite_tecto’ changed from OFF to ON
2021-02-21 01:39:40.625 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘ilu_suite_hall’ received command ON
2021-02-21 01:39:40.634 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘ilu_suite_hall’ predicted to become ON
2021-02-21 01:39:40.642 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘ilu_suite_hall’ changed from OFF to ON
2021-02-21 01:39:40.993 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘ilu_wcsuite_tecto’ received command ON
2021-02-21 01:39:41.004 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘ilu_wcsuite_tecto’ predicted to become ON
2021-02-21 01:39:41.014 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘ilu_wcsuite_tecto’ changed from OFF to ON
2021-02-21 01:39:41.037 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘System_Temperature_CPU’ changed from 56.9 to 58.0
2021-02-21 01:39:41.102 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_suite_portada’ changed from 67 to 64
2021-02-21 01:39:41.130 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_quartocriancas_portada’ changed from 71 to 67
2021-02-21 01:39:41.148 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_quartovisitas_porta’ changed from 74 to 71
2021-02-21 01:39:41.171 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_hallpiso1_porta’ changed from 73 to 69
2021-02-21 01:39:41.200 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_suite_closet_porta’ changed from 66 to 62
2021-02-21 01:39:41.224 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_suite_porta’ changed from 64 to 61
2021-02-21 01:39:41.415 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘sonoff_suite_rua’ received command ON
2021-02-21 01:39:41.421 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘sonoff_suite_rua’ predicted to become ON
2021-02-21 01:39:41.431 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘sonoff_suite_rua’ changed from OFF to ON
2021-02-21 01:39:41.676 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘clima_valv_onoff_knx_suite’ changed from ON to OFF
2021-02-21 01:39:42.062 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘System_Temperature_CPU’ changed from 58.0 to 56.9
2021-02-21 01:39:42.128 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_suite_portada’ changed from 64 to 61
2021-02-21 01:39:42.153 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_quartocriancas_portada’ changed from 67 to 64
2021-02-21 01:39:42.180 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_quartovisitas_porta’ changed from 71 to 67
2021-02-21 01:39:42.204 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_hallpiso1_porta’ changed from 69 to 66
2021-02-21 01:39:42.224 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_suite_closet_porta’ changed from 62 to 59
2021-02-21 01:39:42.264 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘rs_suite_porta’ changed from 61 to 58
2021-02-21 01:39:42.366 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘ilu_suite_closet’ received command ON
2021-02-21 01:39:42.376 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘ilu_suite_closet’ predicted to become ON
2021-02-21 01:39:42.388 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘ilu_suite_closet’ changed from OFF to ON
2021-02-21 01:39:42.797 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘ilu_wcsuite_espelho’ received command ON
2021-02-21 01:39:42.807 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘ilu_wcsuite_espelho’ predicted to become ON
2021-02-21 01:39:42.818 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘ilu_wcsuite_espelho’ changed from OFF to ON

I do have some rules, but haven’t touched them recently and they never caused me any troubles. Those rules don’t touch many of the items that have turned on.

[smvsousa (Sergio Sousa)]

Thanks for sharing your experience Sriram. I’m still unsure if this was indeed an attack. Can’t find any evidence of the attack on the my logs. However, I know that some attacks were blocked from my firewall.
All doors closed now. Keeping an eye on any strange behaviors.