search

OpenEMS / openems

OpenEMS - Open Source Energy Management System
GNU Affero General Public License v3.0
810 stars 400 forks source link

OpenEMS sometimes stops on losing connection to FENECON persistence #3

Closed sfeilmeier closed 7 years ago

sfeilmeier commented 7 years ago

Bug Report or Feature Request (mark with an x)

- [x] bug report -> please search issues before submitting
- [ ] feature request

The log given by the failure.

Apr 27 18:39:39 fems421 java[2222]: [heduler0] [INFO ] [g.DebugLogController:82 ] meter0 [L:-130 W;-200 var|L1:0 W;-60 var|L2:-120 W;-70 var|L3:0 W;-50 var] meter1 [L:0;INVALID|L1:0 W;INVALID|L2:0 W;INVALID|L3:0 W;INVALID] ess0 [2017-3-2 Apr 27 18:39:40 fems421 java[2222]: [heduler0] [INFO ] [g.DebugLogController:82 ] meter0 [L:-130 W;-200 var|L1:0 W;-60 var|L2:-120 W;-70 var|L3:0 W;-50 var] meter1 [L:0;INVALID|L1:0 W;INVALID|L2:0 W;INVALID|L3:0 W;INVALID] ess0 [2017-3-2 Apr 27 18:39:41 fems421 java[2222]: [heduler0] [INFO ] [g.DebugLogController:82 ] meter0 [L:-130 W;-200 var|L1:0 W;-60 var|L2:-120 W;-70 var|L3:0 W;-50 var] meter1 [L:0;INVALID|L1:0 W;INVALID|L2:0 W;INVALID|L3:0 W;INVALID] ess0 [2017-3-2 Apr 27 18:39:42 fems421 java[2222]: [hread-27] [WARN ] [econ.WebsocketClient:78 ] Websocket [wss://fenecon.de:443/femsserver] error: java.io.IOException: Broken pipe Apr 27 18:39:43 fems421 java[2222]: [hread-27] [INFO ] [econ.WebsocketClient:73 ] Websocket [wss://fenecon.de:443/femsserver] closed. Code[1006] Reason[] Apr 27 18:39:43 fems421 java[2222]: [heduler0] [INFO ] [g.DebugLogController:82 ] meter0 [L:-130 W;-200 var|L1:0 W;-60 var|L2:-120 W;-70 var|L3:0 W;-50 var] meter1 [L:0;INVALID|L1:0 W;INVALID|L2:0 W;INVALID|L3:0 W;INVALID] ess0 [2017-3-2 Apr 27 18:39:43 fems421 java[2222]: [heduler0] [INFO ] [econ.WebsocketClient:56 ] Start new websocket connection to [/femsserver] Apr 27 18:39:43 fems421 java[2222]: [heduler0] [INFO ] [n.FeneconPersistence:230] FENECON persistence is connecting... [wss://fenecon.de:443/femsserver] Apr 27 18:39:43 fems421 java[2222]: [istence1] [INFO ] [n.FeneconPersistence:259] New cycle time: ConfigChannel[Optional[2000]] Apr 27 18:40:42 fems421 java[2222]: [hread-29] [WARN ] [econ.WebsocketClient:78 ] Websocket [wss://fenecon.de:443/femsserver] error: java.io.IOException: connection closed unexpectedly by peer Apr 27 19:49:26 fems421 java[2222]: [_bridge0] [ERROR] [o.ModbusRTUTransport:416] Last request: 04 03 00 C8 00 01 Apr 27 19:49:26 fems421 java[2222]: [_bridge0] [ERROR] [o.ModbusRTUTransport:417] Cannot read from serial port

Desired functionality.

As seen in the logs, Websocket connection stops and is trying to reconnect. This is done in the thread "scheduler0", which seems to block it. Afterwards there is no log output anymore. OpenEMS needed to be restartet.

Possible feature request: use systemd Watchdog to restart in such a case. (Might be obsolete with switch to OSGi/Kura)

sfeilmeier commented 7 years ago

Similar case at fems421:

Apr 28 11:04:20 fems421 java[989]: [istence1] [INFO ] [n.FeneconPersistence:230] FENECON persistence is connecting... [wss://fenecon.de:443/femsserver] Apr 28 11:04:20 fems421 java[989]: [hread-11] [WARN ] [econ.WebsocketClient:78 ] Websocket [wss://fenecon.de:443/femsserver] error: java.nio.channels.UnresolvedAddressException Apr 28 11:04:20 fems421 java[989]: [hread-11] [INFO ] [econ.WebsocketClient:73 ] Websocket [wss://fenecon.de:443/femsserver] closed. Code[-1] Reason[null] Apr 28 11:04:21 fems421 java[989]: [istence1] [WARN ] [n.FeneconPersistence:236] FENECON persistence failed connection to uri [wss://fenecon.de:443/femsserver] Apr 28 11:04:21 fems421 java[989]: [istence1] [INFO ] [n.FeneconPersistence:259] New cycle time: ConfigChannel[Optional[2000]] Apr 28 11:04:21 fems421 java[989]: [istence1] [INFO ] [econ.WebsocketClient:56 ] Start new websocket connection to [/femsserver] Apr 28 11:04:21 fems421 java[989]: [istence1] [INFO ] [n.FeneconPersistence:230] FENECON persistence is connecting... [wss://fenecon.de:443/femsserver] Apr 28 11:04:21 fems421 java[989]: [hread-12] [WARN ] [econ.WebsocketClient:78 ] Websocket [wss://fenecon.de:443/femsserver] error: java.nio.channels.UnresolvedAddressException Apr 28 11:04:21 fems421 java[989]: [heduler0] [INFO ] [g.DebugLogController:82 ] meter1 [L:INVALID;INVALID|L1:INVALID;INVALID|L2:INVALID;INVALID|L3:INVALID;INVALID] meter0 [L:INVALID;INVALID|L1:INVALID;INVALID|L2:INVALID;INVALID|L3:INVAL Apr 28 11:04:23 fems421 java[989]: [istence0] [ERROR] [.InfluxdbPersistence:186] Unable to connect to InfluxDB: java.net.ConnectException: Failed to connect to /127.0.0.1:8086 Apr 28 11:04:24 fems421 java[989]: [_bridge0] [ERROR] [col.modbus.ModbusRtu:119] Unable to open Modbus-RTU connection: Optional[com.ghgande.j2mod.modbus.net.SerialConnection@1229dc4] Apr 28 11:51:40 fems421 systemd[1]: Stopping OpenEMS...

sfeilmeier commented 7 years ago

And fems218:

Apr 28 10:30:57 fems218 java[3254]: [heduler0] [INFO ] [ities.SymmetricPower:170] Reduce activePower from [33320] to [0] and reactivePower from [0] to [0] Apr 28 10:30:57 fems218 java[3254]: [heduler0] [INFO ] [ingSurplusController:82 ] ess0 Set ActivePower [0] Apr 28 10:30:58 fems218 java[3254]: [teThread] [WARN ] [econ.WebsocketClient:78 ] Websocket [wss://fenecon.de:443/femsserver] error: java.io.IOException: Broken pipe Apr 28 10:30:58 fems218 java[3254]: [teThread] [INFO ] [econ.WebsocketClient:73 ] Websocket [wss://fenecon.de:443/femsserver] closed. Code[1006] Reason[] Apr 28 10:30:58 fems218 java[3254]: [heduler0] [INFO ] [g.DebugLogController:82 ] meter1 [L:70 W;0 var|L1:70 W;0 var|L2:0 W;0 var|L3:0 W;0 var] meter0 [L:32810 W;-6040 var|L1:14940 W;-2620 var|L2:9980 W;-920 var|L3:7890 W;-2500 var] ess0 Apr 28 10:30:58 fems218 java[3254]: [heduler0] [INFO ] [econ.WebsocketClient:56 ] Start new websocket connection to [/femsserver] Apr 28 10:30:58 fems218 java[3254]: [heduler0] [INFO ] [n.FeneconPersistence:230] FENECON persistence is connecting... [wss://fenecon.de:443/femsserver] Apr 28 10:30:59 fems218 java[3254]: [istence0] [INFO ] [n.FeneconPersistence:259] New cycle time: ConfigChannel[Optional[2000]] Apr 28 10:31:19 fems218 java[3254]: [hread-15] [WARN ] [econ.WebsocketClient:78 ] Websocket [wss://fenecon.de:443/femsserver] error: java.net.NoRouteToHostException: No route to host Apr 28 12:13:19 fems218 systemd[1]: Stopping OpenEMS...

sfeilmeier commented 7 years ago

Apr 28 21:10:48 fems421 java[1040]: [istence1] [INFO ] [n.FeneconPersistence:230] FENECON persistence is connecting... [wss://fenecon.de:443/femsserver] Apr 28 21:10:48 fems421 java[1040]: [hread-11] [WARN ] [econ.WebsocketClient:78 ] Websocket [wss://fenecon.de:443/femsserver] error: java.nio.channels.UnresolvedAddress Apr 28 21:10:49 fems421 java[1040]: [hread-11] [INFO ] [econ.WebsocketClient:73 ] Websocket [wss://fenecon.de:443/femsserver] closed. Code[-1] Reason[null] Apr 28 21:10:49 fems421 java[1040]: [istence1] [WARN ] [n.FeneconPersistence:236] FENECON persistence failed connection to uri [wss://fenecon.de:443/femsserver] Apr 28 21:10:49 fems421 java[1040]: [istence1] [INFO ] [n.FeneconPersistence:259] New cycle time: ConfigChannel[Optional[2000]] Apr 28 21:10:49 fems421 java[1040]: [istence1] [INFO ] [econ.WebsocketClient:56 ] Start new websocket connection to [/femsserver] Apr 28 21:10:49 fems421 java[1040]: [istence1] [INFO ] [n.FeneconPersistence:230] FENECON persistence is connecting... [wss://fenecon.de:443/femsserver] Apr 28 21:10:49 fems421 java[1040]: [heduler0] [INFO ] [g.DebugLogController:82 ] meter0 [L:INVALID;INVALID|L1:INVALID;INVALID|L2:INVALID;INVALID|L3:INVALID;INVALID] me Apr 28 21:10:49 fems421 java[1040]: [hread-12] [WARN ] [econ.WebsocketClient:78 ] Websocket [wss://fenecon.de:443/femsserver] error: java.nio.channels.UnresolvedAddress Apr 28 21:10:49 fems421 java[1040]: [istence0] [ERROR] [.InfluxdbPersistence:186] Unable to connect to InfluxDB: java.net.ConnectException: Failed to connect to /127.0. Apr 28 21:10:51 fems421 java[1040]: [_bridge1] [ERROR] [col.modbus.ModbusRtu:119] Unable to open Modbus-RTU connection: Optional[com.ghgande.j2mod.modbus.net.SerialConn May 01 15:09:34 fems421 systemd[1]: Stopping OpenEMS...

sfeilmeier commented 7 years ago

May 03 03:04:33 fems410 java[2161]: [heduler0] [ERROR] [.BalancingController:184] No Value available. Channel [InverterActivePower] May 03 03:04:34 fems410 java[2161]: [hread-99] [WARN ] [econ.WebsocketClient:78 ] Websocket [wss://fenecon.de:443/femsserver] error: java.nio.channels.UnresolvedAddressException May 03 03:04:34 fems410 java[2161]: [hread-99] [INFO ] [econ.WebsocketClient:73 ] Websocket [wss://fenecon.de:443/femsserver] closed. Code[-1] Reason[null] May 03 03:04:34 fems410 java[2161]: [istence1] [WARN ] [n.FeneconPersistence:236] FENECON persistence failed connection to uri [wss://fenecon.de:443/femsserver] May 03 03:04:34 fems410 java[2161]: [istence1] [INFO ] [n.FeneconPersistence:259] New cycle time: ConfigChannel[Optional[2000]] May 03 03:04:34 fems410 java[2161]: [istence1] [INFO ] [econ.WebsocketClient:56 ] Start new websocket connection to [/femsserver] May 03 03:04:34 fems410 java[2161]: [heduler0] [INFO ] [g.DebugLogController:82 ] meter0 [L:-4770 W;10570 var|L1:0 W;0 var|L2:0 W;0 var|L3:0 W;0 var] ess0 [SOC:99 %|L:INVALID;0 var|Allowed:INVALID;INVALID|GridMode:On-Grid] May 03 03:04:35 fems410 java[2161]: [istence1] [INFO ] [n.FeneconPersistence:230] FENECON persistence is connecting... [wss://fenecon.de:443/femsserver] May 03 03:04:35 fems410 java[2161]: [_bridge0] [ERROR] [col.modbus.ModbusTcp:112] Unable to open Modbus-TCP connection: /192.168.135.218 May 03 03:04:35 fems410 java[2161]: [read-100] [WARN ] [econ.WebsocketClient:78 ] Websocket [wss://fenecon.de:443/femsserver] error: java.nio.channels.UnresolvedAddressException May 03 03:08:24 fems410 java[2161]: [istence0] [ERROR] [.InfluxdbPersistence:155] Error writing to InfluxDB: java.lang.RuntimeException: java.net.SocketTimeoutException: Read timed out May 03 07:26:19 fems410 java[2161]: [orker-19] [INFO ] [cket.WebsocketServer:81 ] Incoming connection... May 03 08:21:25 fems410 systemd[1]: Stopping OpenEMS...