docbender / openHAB-Simatic

openHAB binding for Siemens Simatic S7 PLC
Eclipse Public License 2.0
20 stars 4 forks source link

Slow response and system faulty #8

Closed grzegorz914 closed 5 years ago

grzegorz914 commented 5 years ago

Hi,

I have regularly updated OH2 to latest snapshot now I’m on 2.5.0-1596, from less than two months simatic binding is a terrible slower complete system and consequently leads to a total system failure. I thing this behavior corespondent with latest changes in OH2. Downgrade to 2.5.0-M1 or remove Simatic binding solves this problem.

Can U check this behavior and fixed if possible?

2019-05-20 23:51:06.198 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@1f62a26' takes more than 5000ms.
 ==> /var/log/openhab2/events.log <==
2019-05-20 23:56:16.096 [vent.ItemStateChangedEvent] - PLC_EnergiaNapL1L2 changed from 417.510009765625 to 418.1199951171875
==> /var/log/openhab2/openhab.log <==
2019-05-20 23:56:16.108 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.io.monitor.internal.EventLogger@f4b49c' takes more than 5000ms.
==> /var/log/openhab2/events.log <==
2019-05-20 23:56:35.824 [vent.ItemStateChangedEvent] - PLC_EnergiaNapL2L3 changed from 416.3399963378906 to 416.80999755859375
==> /var/log/openhab2/openhab.log <==
2019-05-20 23:56:40.338 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.io.monitor.internal.EventLogger@f4b49c' takes more than 5000ms.
2019-05-20 23:58:49.982 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = 3e76f50c-1d22-4c29-8b2c-b4236812eb51, base URL = http://localhost:8080)
2019-05-21 00:05:48.464 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@1a318b4' takes more than 5000ms.
2019-05-21 00:11:25.660 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.io.monitor.internal.EventLogger@f4b49c' takes more than 5000ms.
2019-05-21 00:12:13.450 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.events.internal.EventBridge@1bfc064' takes more than 5000ms.
2019-05-21 00:18:46.567 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: Java heap space
    at java.nio.HeapByteBuffer.<init>(HeapByteBuffer.java:57) ~[?:?]
    at java.nio.ByteBuffer.allocate(ByteBuffer.java:335) ~[?:?]
    at sun.nio.cs.StreamDecoder.<init>(StreamDecoder.java:251) ~[?:?]
    at sun.nio.cs.StreamDecoder.<init>(StreamDecoder.java:231) ~[?:?]
    at sun.nio.cs.StreamDecoder.forInputStreamReader(StreamDecoder.java:69) ~[?:?]
    at java.io.InputStreamReader.<init>(InputStreamReader.java:74) ~[?:?]
    at org.openhab.binding.exec.internal.handler.ExecHandler$1.run(ExecHandler.java:181) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:?]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
    at java.lang.Thread.run(Thread.java:748) [?:?]
 2019-05-21 00:21:37.208 [INFO ] [control.internal.WebSocketConnection] - Web Socket close 1006. Reason: WebSocket Read EOF
 2019-05-21 00:22:59.618 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@1f62a26' takes more than 5000ms.
 2019-05-21 00:26:28.586 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - 
 java.lang.OutOfMemoryError: Java heap space
 2019-05-21 00:26:24.137 [ERROR] [org.apache.felix.fileinstall        ] - In main loop, we have serious trouble
 java.lang.OutOfMemoryError: Java heap space
 2019-05-21 00:27:46.575 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@1a318b4' takes more than 5000ms.
 2019-05-21 00:31:29.203 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
 java.lang.OutOfMemoryError: Java heap space
 2019-05-21 00:32:55.394 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
 java.lang.OutOfMemoryError: Java heap space
 2019-05-21 00:40:25.140 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
 java.lang.OutOfMemoryError: Java heap space
 2019-05-21 01:23:19.709 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
 java.lang.NullPointerException: null
    at org.openhab.binding.denonmarantz.internal.connector.telnet.DenonMarantzTelnetConnector.dispose(DenonMarantzTelnetConnector.java:100) ~[?:?]
    at org.openhab.binding.denonmarantz.internal.handler.DenonMarantzHandler.connectionError(DenonMarantzHandler.java:417) ~[?:?]
    at org.openhab.binding.denonmarantz.internal.DenonMarantzState.connectionError(DenonMarantzState.java:64) ~[?:?]
    at org.openhab.binding.denonmarantz.internal.connector.telnet.DenonMarantzTelnetConnector.telnetClientConnected(DenonMarantzTelnetConnector.java:79) ~[?:?]
    at org.openhab.binding.denonmarantz.internal.connector.telnet.DenonMarantzTelnetClient.connectTelnetSocket(DenonMarantzTelnetClient.java:146) ~[?:?]
    at org.openhab.binding.denonmarantz.internal.connector.telnet.DenonMarantzTelnetClient.run(DenonMarantzTelnetClient.java:66) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
    at java.lang.Thread.run(Thread.java:748) [?:?]
 2019-05-21 02:18:40.478 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
 java.lang.OutOfMemoryError: Java heap space
 2019-05-21 02:18:45.173 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
 java.lang.OutOfMemoryError: Java heap space

Thank Grzegorz

docbender commented 5 years ago

This has nothing with addon. This is OH problem. https://community.openhab.org/t/openhab2-snapshot-2-5-1595-fully-broken/74702/9

⁣Odesláno z TypeApp ​

    1. 2019 8:52, 8:52, Grzegorz notifications@github.com napsal/a:

      Hi,

      I have regularly updated OH2 to latest snapshot now I’m on 2.5.0-1996, from less than two months simatic binding is a terrible slower complete system and consequently leads to a total system failure. I thing this behavior corespondent with latest changes in OH2. Downgrade to 2.5.0-M1 solves this problem.

      Can U check this behavior and fixed if possible?

      Thank Grzegorz

      -- You are receiving this because you are subscribed to this thread. Reply to this email directly or view it on GitHub: https://github.com/docbender/openHAB-Simatic/issues/8

grzegorz914 commented 5 years ago

Strange, because all other installed bindings working OK if Simatic.binding is not installed.

grzegorz914 commented 5 years ago

Hi,

I make some test,

  1. installed OH 2.5.0 build 1601 from scratch, installed other binding without simatic binding CPU Usage 5-10%. Installed simatic - CPU Usage over 200%, system slow down.
1   PID     USER      PR    NI      VIRT      RES         SHR S        %CPU      %MEM        TIME+      COMMAND                                                                                                                                                              
2   2751  openhab.    20    0      627468    436880.    14792 S       212.8.     43.7       33:59.91        java                                                                                                                                                                 
3   3088  openhab+    20    0       9892     3332       2768 R        1.0.        0.3        0:15.90         top
  1. Installed OH2.5.0 build 1601 from scratch, installed only somatic without any other binding, CPU Usage over 200% as above.

any tips to find what is wrong?

thanks Grzegorz

docbender commented 5 years ago

 Hi,

This must be something strange in OH latest snapshots. There are some changes around replacing ESH components. I recommend to stay at M1 version and wait to next milestone version. Or you can report this issue to OH developers (check this topic: https://github.com/openhab/openhab-core/issues/829)

Best

grzegorz914 commented 5 years ago

OK,

already reported it.

grzegorz914 commented 5 years ago

Problem solved with 2.5.0 build 1619.