Beginner struggling with the "Implementing a device" Guide

English Forum Software-Development
1

Update: Issue resolved. See comment for reason.
Hello everyone, I am really new to openems and my java skills are not that good either. I started learning openems last week and haven’t managed to make the Implementing a device tutorial work. I am not sure where is the problem and can use some tips or feedback.

Below are the logs from the edge. It seems that I am unable to connect with the modbus slave simulator even though it is running. I don’t really know what I should be asking here but any kind help would be appreciated.

org.ops4j.pax.logging.pax-logging-log4j2 [log4j2] INFO : Initializing Log4j2 using default configuration
org.ops4j.pax.logging.pax-logging-log4j2 [log4j2] INFO : Scanning for classes in '/org/ops4j/pax/logging/log4j2/internal/bridges/' matching criteria annotated with @Plugin
org.ops4j.pax.logging.pax-logging-log4j2 [log4j2] INFO : Log4J2 configured using default configuration.
org.ops4j.pax.logging.pax-logging-log4j2 [org.ops4j.pax.logging.spi.support.EventAdminConfigurationNotifier] INFO : Logging configuration changed. (Event Admin service unavailable - no notification sent).
io.openems.edge.application [io.openems.edge.application.EdgeApp] INFO : ===========================================
io.openems.edge.application [io.openems.edge.application.EdgeApp] INFO : OpenEMS version [2022.3.0-SNAPSHOT] started
io.openems.edge.application [io.openems.edge.application.EdgeApp] INFO : ===========================================
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_power] Activate Ess.Power
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_host] Activate Core.Host
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_meta] Activate Core.Meta
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_evcsSlowPowerIncreaseFilter] Activate Evcs.SlowPowerIncreaseFilter
org.ops4j.pax.logging.pax-logging-log4j2 [org.ops4j.pax.logging.spi.support.EventAdminConfigurationNotifier] INFO : Logging configuration changed. (Event Admin service unavailable - no notification sent).
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_power] Modified Ess.Power
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_host] Deactivate Core.Host
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_host] Activate Core.Host
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_meta] Deactivate Core.Meta
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_meta] Activate Core.Meta
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_evcsSlowPowerIncreaseFilter] Modified Evcs.SlowPowerIncreaseFilter
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_host] Deactivate Core.Host
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_host] Activate Core.Host
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_host] Deactivate Core.Host
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_host] Activate Core.Host
org.apache.felix.http.jetty [org.eclipse.jetty.util.log] INFO : Logging initialized @2461ms to org.eclipse.jetty.util.log.Slf4jLog
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_host] Deactivate Core.Host
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_host] Activate Core.Host
org.apache.felix.http.jetty [org.eclipse.jetty.server.Server] INFO : jetty-9.4.44.v20210927; built: 2021-09-27T23:02:44.612Z; git: 8da83308eeca865e495e53ef315a249d63ba9332; jvm 11.0.13+8-Ubuntu-0ubuntu1.20.04
org.apache.felix.http.jetty [org.eclipse.jetty.server.session] INFO : DefaultSessionIdManager workerName=node0
org.apache.felix.http.jetty [org.eclipse.jetty.server.session] INFO : No SessionScavenger set, using defaults
org.apache.felix.http.jetty [org.eclipse.jetty.server.session] INFO : node0 Scavenging every 660000ms
org.apache.felix.http.jetty [org.eclipse.jetty.server.handler.ContextHandler] INFO : Started o.e.j.s.ServletContextHandler@44ecd95a{/,null,AVAILABLE}
org.apache.felix.http.jetty [org.eclipse.jetty.server.Server] INFO : Started @2572ms
org.apache.felix.http.jetty [org.eclipse.jetty.server.session] INFO : node0 Scavenging every 660000ms
org.apache.felix.http.jetty [org.eclipse.jetty.server.AbstractConnector] INFO : Started ServerConnector@113174b8{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
13:41:46.653 [FelixStartLevel] INFO  org.apache.felix.http.jetty - Started Jetty 9.4.44.v20210927 at port(s) HTTP:8080 on context path / [minThreads=8,maxThreads=200,acceptors=1,selectors=4]
13:41:46.729 [FelixStartLevel] WARN  io.openems.edge.core.componentmanager.ComponentManagerImpl - bundle io.openems.edge.core:1.0.0.202202170221 (75)[io.openems.edge.core.componentmanager.ComponentManagerImpl(2)] : Could not get service from ref [io.openems.edge.core.appmanager.AppManager, io.openems.edge.common.component.OpenemsComponent, io.openems.edge.common.jsonapi.JsonApi, org.osgi.service.cm.ConfigurationListener]
13:41:46.730 [FelixStartLevel] WARN  io.openems.edge.core.componentmanager.ComponentManagerImpl - bundle io.openems.edge.core:1.0.0.202202170221 (75)[io.openems.edge.core.componentmanager.ComponentManagerImpl(2)] : Could not get service from ref [io.openems.edge.core.appmanager.AppManager, io.openems.edge.common.component.OpenemsComponent, io.openems.edge.common.jsonapi.JsonApi, org.osgi.service.cm.ConfigurationListener]
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_componentManager] Activate Core.ComponentManager
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_appManager] Activate Core.AppManager
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_predictorManager] Activate Core.PredictorManager
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_sum] Activate Core.Sum
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_cycle] Activate Core.Cycle
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_appManager] Deactivate Core.AppManager
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_cycle] Deactivate Core.Cycle
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_predictorManager] Deactivate Core.PredictorManager
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_sum] Deactivate Core.Sum
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_componentManager] Deactivate Core.ComponentManager
13:41:46.832 [CM Event Dispatcher (Fire ConfigurationEvent: pid=Core.ComponentManager)] WARN  io.openems.edge.core.componentmanager.ComponentManagerImpl - bundle io.openems.edge.core:1.0.0.202202170221 (75)[io.openems.edge.core.componentmanager.ComponentManagerImpl(2)] : Could not get service from ref [io.openems.edge.core.appmanager.AppManager, io.openems.edge.common.component.OpenemsComponent, io.openems.edge.common.jsonapi.JsonApi, org.osgi.service.cm.ConfigurationListener]
13:41:46.836 [CM Event Dispatcher (Fire ConfigurationEvent: pid=Core.ComponentManager)] WARN  io.openems.edge.core.componentmanager.ComponentManagerImpl - bundle io.openems.edge.core:1.0.0.202202170221 (75)[io.openems.edge.core.componentmanager.ComponentManagerImpl(2)] : Could not get service from ref [io.openems.edge.core.appmanager.AppManager, io.openems.edge.common.component.OpenemsComponent, io.openems.edge.common.jsonapi.JsonApi, org.osgi.service.cm.ConfigurationListener]
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_componentManager] Activate Core.ComponentManager
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_appManager] Activate Core.AppManager
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_predictorManager] Activate Core.PredictorManager
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_sum] Activate Core.Sum
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_cycle] Activate Core.Cycle
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_appManager] Modified Core.AppManager
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_predictorManager] Deactivate Core.PredictorManager
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_predictorManager] Activate Core.PredictorManager
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_sum] Modified Core.Sum
io.openems.edge.common [io.openems.edge.common.component.AbstractOpenemsComponent] INFO : [_cycle] Modified Core.Cycle
13:41:47.012 [FelixStartLevel] INFO  org.ops4j.pax.logging.internal.Activator - Enabling Java Util Logging API support.
13:41:47.013 [FelixStartLevel] INFO  org.ops4j.pax.logging.internal.Activator - Enabling SLF4J API support.
13:41:47.015 [FelixStartLevel] INFO  org.ops4j.pax.logging.internal.Activator - Enabling Apache Commons Logging API support.
13:41:47.017 [FelixStartLevel] INFO  org.ops4j.pax.logging.internal.Activator - Enabling JULI Logger API support.
13:41:47.018 [FelixStartLevel] INFO  org.ops4j.pax.logging.internal.Activator - Enabling Avalon Logger API support.
13:41:47.022 [FelixStartLevel] INFO  org.ops4j.pax.logging.internal.Activator - Enabling JBoss Logging API support.
13:41:47.024 [FelixStartLevel] INFO  org.ops4j.pax.logging.internal.Activator - Enabling Log4J v1 API support.
13:41:47.028 [FelixStartLevel] INFO  org.ops4j.pax.logging.internal.Activator - Enabling Log4J v2 API support.
org.ops4j.pax.logging.pax-logging-log4j2 [log4j2] INFO : Log4J2 configured using configuration from passed properties
2022-02-21T13:41:52,097 [logging)] INFO  [ventAdminConfigurationNotifier] Sending Event Admin notification (configuration successful) to org/ops4j/pax/logging/Configuration
2022-02-21T13:41:56,909 [re.Cycle] WARN  [ms.edge.core.cycle.CycleWorker] [_cycle] There are no Schedulers configured!
2022-02-21T13:42:01,912 [re.Cycle] WARN  [ms.edge.core.cycle.CycleWorker] [_cycle] There are no Schedulers configured!
2022-02-21T13:42:06,911 [re.Cycle] WARN  [ms.edge.core.cycle.CycleWorker] [_cycle] There are no Schedulers configured!
2022-02-21T13:42:11,910 [re.Cycle] WARN  [ms.edge.core.cycle.CycleWorker] [_cycle] There are no Schedulers configured!
2022-02-21T13:42:14,985 [901b92c)] INFO  [onent.AbstractOpenemsComponent] [scheduler0] Activate Scheduler.AllAlphabetically
2022-02-21T13:42:38,921 [a26d898)] INFO  [onent.AbstractOpenemsComponent] [ctrlDebugLog0] Activate Controller.Debug.Log
2022-02-21T13:42:41,934 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _componentManager[Defective:ctrlDebugLog0[Undefined failure [-1];]|State:FAULT: A configured OpenEMS Component was not activated] _sum[State:Fault]
2022-02-21T13:42:46,913 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok]
2022-02-21T13:42:51,914 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok]
2022-02-21T13:42:56,911 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok]
2022-02-21T13:43:01,914 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok]
2022-02-21T13:43:06,656 [78ad809)] INFO  [onent.AbstractOpenemsComponent] [modbus0] Activate Bridge.Modbus.Tcp
2022-02-21T13:43:06,940 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok]
2022-02-21T13:43:11,913 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok]
2022-02-21T13:43:16,916 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok]
2022-02-21T13:43:21,913 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok]
2022-02-21T13:43:26,914 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok]
2022-02-21T13:43:28,168 [b7fb51e)] INFO  [onent.AbstractOpenemsComponent] [meter0] Activate Meter.Simulated.Modbus
2022-02-21T13:43:28,178 [b7fb51e)] INFO  [onent.AbstractOpenemsComponent] [meter0] Deactivate Meter.Simulated.Modbus
2022-02-21T13:43:28,186 [b7fb51e)] INFO  [onent.AbstractOpenemsComponent] [meter0] Activate Meter.Simulated.Modbus
2022-02-21T13:43:31,926 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok] meter0[L:UNDEFINED]
2022-02-21T13:43:36,593 [modbus0 ] WARN  [bridge.modbus.api.ModbusWorker] [modbus0] FC3ReadHoldingRegisters [meter0;unitid=1;ref=1000/0x3e8;length=1] execution failed: Connection to [127.0.0.1] failed: Connection refused (Connection refused)
2022-02-21T13:43:36,913 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok] meter0[L:UNDEFINED]
2022-02-21T13:43:41,841 [modbus0 ] WARN  [bridge.modbus.api.ModbusWorker] [modbus0] FC3ReadHoldingRegisters [meter0;unitid=1;ref=1000/0x3e8;length=1] execution failed: Connection to [127.0.0.1] failed: Connection refused (Connection refused)
2022-02-21T13:43:41,916 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok] meter0[L:UNDEFINED]
2022-02-21T13:43:46,862 [modbus0 ] WARN  [bridge.modbus.api.ModbusWorker] [modbus0] FC3ReadHoldingRegisters [meter0;unitid=1;ref=1000/0x3e8;length=1] execution failed: Connection to [127.0.0.1] failed: Connection refused (Connection refused)
2022-02-21T13:43:46,914 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok] meter0[L:UNDEFINED]
2022-02-21T13:43:51,862 [modbus0 ] WARN  [bridge.modbus.api.ModbusWorker] [modbus0] FC3ReadHoldingRegisters [meter0;unitid=1;ref=1000/0x3e8;length=1] execution failed: Connection to [127.0.0.1] failed: Connection refused (Connection refused)
2022-02-21T13:43:51,914 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok] meter0[L:UNDEFINED]
2022-02-21T13:43:56,860 [modbus0 ] WARN  [bridge.modbus.api.ModbusWorker] [modbus0] FC3ReadHoldingRegisters [meter0;unitid=1;ref=1000/0x3e8;length=1] execution failed: Connection to [127.0.0.1] failed: Connection refused (Connection refused)
2022-02-21T13:43:56,914 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok] meter0[L:UNDEFINED]```
2

The issue seems to have been resolved. I change the modbus/TCP port from 502 to 2502. It could have a firewall issue or something else using that port.

Another confusing part was that there was an existing Simulated Meter module and when I followed the guide, I create another one. Then I had two Simulated Meter modules and I didn’t know which one was mine. Later I renamed mine to Simulated Meter Modbus to be able differentiate it from the other one. Below are the logs when I switch between them:

2022-02-21T14:08:21,910 [modbus0 ] WARN  [bridge.modbus.api.ModbusWorker] [modbus0] FC3ReadHoldingRegisters [meter0;unitid=1;ref=801/0x321;length=12] execution failed: Transaction failed: Illegal Data Address: Illegal Data Address
2022-02-21T14:08:21,912 [modbus0 ] WARN  [bridge.modbus.api.ModbusWorker] [modbus0] FC3ReadHoldingRegisters [meter0;unitid=1;ref=1/0x1;length=68] execution failed: Transaction failed: Illegal Data Address: Illegal Data Address
2022-02-21T14:08:21,968 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok]
2022-02-21T14:08:26,969 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok]
2022-02-21T14:08:27,079 [bf018e5)] INFO  [onent.AbstractOpenemsComponent] [meter0] Activate Meter.Simulated.Modbus
2022-02-21T14:08:27,086 [bf018e5)] INFO  [onent.AbstractOpenemsComponent] [meter0] Deactivate Meter.Simulated.Modbus
2022-02-21T14:08:27,092 [bf018e5)] INFO  [onent.AbstractOpenemsComponent] [meter0] Activate Meter.Simulated.Modbus
2022-02-21T14:08:31,968 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok] meter0[L:UNDEFINED]
2022-02-21T14:08:36,970 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok Production:500 W Consumption:500 W] meter0[L:500 W]
2022-02-21T14:08:41,972 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok Production:500 W Consumption:500 W] meter0[L:500 W]
2022-02-21T14:08:46,972 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok Production:500 W Consumption:500 W] meter0[L:500 W]
2022-02-21T14:08:51,971 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok Production:500 W Consumption:500 W] meter0[L:500 W]
2022-02-21T14:08:52,338 [bf018e5)] INFO  [onent.AbstractOpenemsComponent] [meter0] Deactivate Meter.Simulated.Modbus
2022-02-21T14:08:56,971 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok]
2022-02-21T14:09:00,062 [a09d3e2)] INFO  [onent.AbstractOpenemsComponent] [meter0] Activate Meter.Siemens
2022-02-21T14:09:00,072 [a09d3e2)] INFO  [onent.AbstractOpenemsComponent] [meter0] Deactivate Meter.Siemens
2022-02-21T14:09:00,076 [a09d3e2)] INFO  [onent.AbstractOpenemsComponent] [meter0] Activate Meter.Siemens
2022-02-21T14:09:01,971 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok] meter0[L:UNDEFINED]
2022-02-21T14:09:06,324 [modbus0 ] WARN  [bridge.modbus.api.ModbusWorker] [modbus0] FC3ReadHoldingRegisters [meter0;unitid=1;ref=801/0x321;length=12] execution failed: Transaction failed: Illegal Data Address: Illegal Data Address
2022-02-21T14:09:06,329 [modbus0 ] WARN  [bridge.modbus.api.ModbusWorker] [modbus0] FC3ReadHoldingRegisters [meter0;unitid=1;ref=1/0x1;length=68] execution failed: Transaction failed: Illegal Data Address: Illegal Data Address
2022-02-21T14:09:06,971 [re.Cycle] INFO  [ntroller.debuglog.DebugLogImpl] [ctrlDebugLog0] _sum[State:Ok] meter0[L:UNDEFINED]
3

Now I want to automate this process. I want the openems edge to start with following components so that I don’t have to do them manually every time I change something. Any tips on how to do it?

1. Controller Debug Log

  • ID: ctrlDebugLog0
  • Enabled: checked

2. Scheduler All Alphabetically

  • ID: scheduler0
  • Enabled: checked
  • Cycle time: 1000

3. Bridge Modbus/TCP

  • ID: modbus0
  • IP-Address: localhost
  • Enabled: checked

4. Meter Simulated

  • ID: meter0
  • Enabled: checked
  • Meter-Type: PRODUCTION
  • Modbus-ID: modbus0
  • Modbus Unit-ID: 1
4

Hi,

since you are working on a Linux system you need to adjust the felix.cm.dir inside EdgeApp.bndrun to point to a directory. This is where Apache Felix Configuration Admin stores all the configurations:

Regards,
Stefan

2 Likes