[evcc] Data will not been updated

rbeudel commented 2 weeks ago

Hello, I am running evcc 0.130.6 in a Debian VM on Proxmox, a other Debian VM is OH 4.2.1. The problem is data is only updated, when changing the reading intervall (30s to 49s and so on) or building a new item from the channels. That is not a new problem for me, but I got no solution. Here is the openhab.log after changing the time:

2024-08-28 15:13:09.961 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Running refresh job ...
2024-08-28 15:13:09.975 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 1 loadpoints on site Mein Zuhause.
2024-08-28 15:13:09.976 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 2 vehicles on site Mein Zuhause.
2024-08-28 15:13:09.990 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.IllegalArgumentException: UID segment 'vehicledb:1#vehicleMinSoC' contains invalid characters. The last segment of the channel UID must match the pattern '[\w-]*|[\w-]*#[\w-]*'.
    at org.openhab.core.thing.ChannelUID.validateSegment(ChannelUID.java:136) ~[?:?]
    at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:76) ~[?:?]
    at org.openhab.core.thing.UID.<init>(UID.java:66) ~[?:?]
    at org.openhab.core.thing.ChannelUID.<init>(ChannelUID.java:76) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannel(EvccHandler.java:995) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannelsVehicle(EvccHandler.java:635) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannelsVehicle(EvccHandler.java:584) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.refresh(EvccHandler.java:428) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
    at java.lang.Thread.run(Thread.java:840) [?:?]

I removed the evcc binding and cleaned the cache some times, but it is still the same.

lsiepel commented 2 weeks ago

vehicledb:1#vehicleMinSoC seems to be the problem as the error states it must match the pattern [\w-]*|[\w-]*#[\w-]*

The documentation has this channel uid: evcc:device:demo:loadpoint0current#vehicleMinSoC

Do you have file or UI based configuration? Can you share your thing / item / channel declaration?

rbeudel commented 2 weeks ago

It is UI based. Here is the Thing: ` label: evcc Installation thingTypeUID: evcc:device configuration: refreshInterval: 40 url: http://192.168.1.112:7070 channels:

id: general#batteryCapacity channelTypeUID: evcc:batteryCapacity configuration: {}
id: general#batteryPower channelTypeUID: evcc:batteryPower configuration: {}
id: general#batterySoC channelTypeUID: evcc:batterySoC configuration: {}
id: general#batteryDischargeControl channelTypeUID: evcc:batteryDischargeControl configuration: {}
id: general#batteryMode channelTypeUID: evcc:batteryMode configuration: {}
id: general#prioritySoC channelTypeUID: evcc:prioritySoC configuration: {}
id: general#bufferSoC channelTypeUID: evcc:bufferSoC configuration: {}
id: general#bufferStartSoC channelTypeUID: evcc:bufferStartSoC configuration: {}
id: general#residualPower channelTypeUID: evcc:residualPower configuration: {}
id: general#gridPower channelTypeUID: evcc:gridPower configuration: {}
id: general#homePower channelTypeUID: evcc:homePower configuration: {}
id: general#pvPower channelTypeUID: evcc:pvPower configuration: {}
id: general#version channelTypeUID: evcc:version configuration: {}
id: general#availableVersion channelTypeUID: evcc:availableVersion configuration: {}
id: loadpoint0#activePhases channelTypeUID: evcc:activePhases configuration: {}
id: loadpoint0#chargeCurrent channelTypeUID: evcc:chargeCurrent configuration: {}
id: loadpoint0#chargeDuration channelTypeUID: evcc:chargeDuration configuration: {}
id: loadpoint0#chargePower channelTypeUID: evcc:chargePower configuration: {}
id: loadpoint0#chargeRemainingDuration channelTypeUID: evcc:chargeRemainingDuration configuration: {}
id: loadpoint0#chargeRemainingEnergy channelTypeUID: evcc:chargeRemainingEnergy configuration: {}
id: loadpoint0#chargedEnergy channelTypeUID: evcc:chargedEnergy configuration: {}
id: loadpoint0#charging channelTypeUID: evcc:charging configuration: {}
id: loadpoint0#vehicleConnected channelTypeUID: evcc:vehicleConnected configuration: {}
id: loadpoint0#vehicleConnectedDuration channelTypeUID: evcc:vehicleConnectedDuration configuration: {}
id: loadpoint0#enabled channelTypeUID: evcc:enabled configuration: {}
id: loadpoint0#maxCurrent channelTypeUID: evcc:maxCurrent configuration: {}
id: loadpoint0#minCurrent channelTypeUID: evcc:minCurrent configuration: {}
id: loadpoint0#mode channelTypeUID: evcc:mode configuration: {}
id: loadpoint0#phases channelTypeUID: evcc:phases configuration: {}
id: loadpoint0#limitEnergy channelTypeUID: evcc:limitEnergy configuration: {}
id: loadpoint0#limitSoC channelTypeUID: evcc:limitSoC configuration: {}
id: loadpoint0#effectiveLimitSoC channelTypeUID: evcc:effectiveLimitSoC configuration: {}
id: loadpoint0#vehicleSoC channelTypeUID: evcc:vehicleSoC configuration: {}
id: loadpoint0#title channelTypeUID: evcc:title configuration: {}
id: loadpoint0#vehicleOdometer channelTypeUID: evcc:vehicleOdometer configuration: {}
id: loadpoint0#vehiclePresent channelTypeUID: evcc:vehiclePresent configuration: {}
id: loadpoint0#vehicleRange channelTypeUID: evcc:vehicleRange configuration: {}
id: loadpoint0#vehicleName channelTypeUID: evcc:vehicleName configuration: {}
id: loadpoint0#chargerFeatureHeating channelTypeUID: evcc:chargerFeatureHeating configuration: {}
id: loadpoint0#chargerFeatureIntegratedDevice channelTypeUID: evcc:chargerFeatureIntegratedDevice configuration: {}
id: loadpoint0current#vehicleMinSoC channelTypeUID: evcc:vehicleMinSoC configuration: {}
id: loadpoint0current#vehicleLimitSoC channelTypeUID: evcc:vehicleLimitSoC configuration: {}
id: loadpoint0current#vehiclePlanSoC channelTypeUID: evcc:vehiclePlanSoC configuration: {}
id: loadpoint0current#vehicleTitle channelTypeUID: evcc:vehicleTitle configuration: {}
id: loadpoint0current#vehicleCapacity channelTypeUID: evcc:vehicleCapacity configuration: {}
id: loadpoint0current#vehiclePlanTime channelTypeUID: evcc:vehiclePlanTime configuration: {}
id: loadpoint0current#vehiclePlanEnabled channelTypeUID: evcc:vehiclePlanEnabled configuration: {} and a example for an item: label: evcc Laden aktive Phasen type: Number category: energy groupNames:
evcc_Installation tags:
Point ` For the vehicleminsoc I have no item. I dont now to get better Information without sreenshots

lsiepel commented 2 weeks ago

Did you check the newly added health option for orphaned links?

rbeudel commented 2 weeks ago

There are no orphaned links displayed in the moment

lsiepel commented 2 weeks ago

What is the thing uid ?

Did you try to remove the Thing and re-add it?

rbeudel commented 2 weeks ago

The thing uid is "evcc:device:08c28d69a2". I removed the thing, the binding and all items and cleaned cache several times.

lsiepel commented 2 weeks ago

Could you uninstall the curent binding and drop this binding in your addon folder? https://1drv.ms/u/s!AnMcxmvEeupwjv9nXPTluQVNdRcAHQ?e=M46ft0

After you add an item, the issue should still apear, but it should also log some info lines that can give me enough insight to fix it.

rbeudel commented 2 weeks ago

Uninstalled the evcc binding over the gui. Then put the file in /usr/share/openhab/addons and get then:

2024-08-29 13:21:24.946 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : BundleComponentActivator : ComponentHolder created.
2024-08-29 13:21:24.947 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Dependency Manager created osgi.ds.satisfying.conditioninterface=org.osgi.service.condition.Condition, filter=(osgi.condition.id=true), policy=dynamic, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=null
2024-08-29 13:21:24.947 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component created: DS=DS13, implementation=org.openhab.binding.evcc.internal.EvccHandlerFactory, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[binding.evcc]
2024-08-29 13:21:24.947 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component Services: scope=singleton, services=[org.openhab.core.thing.binding.ThingHandlerFactory]
2024-08-29 13:21:24.947 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component Properties: {osgi.ds.satisfying.condition.target=(osgi.condition.id=true)}
2024-08-29 13:21:24.947 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Querying state disabled
2024-08-29 13:21:24.947 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Querying state disabled
2024-08-29 13:21:24.947 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component can not be activated since it is in state disabled
2024-08-29 13:21:24.948 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Querying state disabled
2024-08-29 13:21:24.948 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Updating target filters
2024-08-29 13:21:24.948 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] :  No existing service listener to unregister for dependency osgi.ds.satisfying.condition
2024-08-29 13:21:24.948 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Setting target property for dependency osgi.ds.satisfying.condition to (osgi.condition.id=true)
2024-08-29 13:21:24.948 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : New service tracker for osgi.ds.satisfying.condition, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.condition.Condition), initialReferenceFilter (&(objectClass=org.osgi.service.condition.Condition)(osgi.condition.id=true))
2024-08-29 13:21:24.948 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : dm osgi.ds.satisfying.condition tracker reset (closed)
2024-08-29 13:21:24.948 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : dm osgi.ds.satisfying.condition tracking 1 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (enter)
2024-08-29 13:21:24.948 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : dm osgi.ds.satisfying.condition tracking 1 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (exit)
2024-08-29 13:21:24.949 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : dm osgi.ds.satisfying.condition tracker opened
2024-08-29 13:21:24.949 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : registering service listener for dependency osgi.ds.satisfying.condition
2024-08-29 13:21:24.949 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Changed state from disabled to unsatisfiedReference
2024-08-29 13:21:24.949 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Component enabled
2024-08-29 13:21:24.949 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : ActivateInternal
2024-08-29 13:21:24.950 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Querying state unsatisfiedReference
2024-08-29 13:21:24.950 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Querying state unsatisfiedReference
2024-08-29 13:21:24.950 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Activating component from state unsatisfiedReference
2024-08-29 13:21:24.951 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Querying state unsatisfiedReference
2024-08-29 13:21:24.951 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Querying state unsatisfiedReference
2024-08-29 13:21:24.951 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Changed state from unsatisfiedReference to satisfied
2024-08-29 13:21:24.951 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : registration change queue [registered]
2024-08-29 13:21:24.953 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Checking constructor public org.openhab.binding.evcc.internal.EvccHandlerFactory()
2024-08-29 13:21:24.953 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Found constructor with 0 arguments : public org.openhab.binding.evcc.internal.EvccHandlerFactory()
2024-08-29 13:21:24.954 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : This thread collected dependencies
2024-08-29 13:21:24.954 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : getService (single component manager) dependencies collected.
2024-08-29 13:21:24.954 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Querying state satisfied
2024-08-29 13:21:24.955 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Querying state satisfied
2024-08-29 13:21:24.955 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : For dependency osgi.ds.satisfying.condition, optional: false; to bind: [[RefPair: ref: [{org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true}] service: [null]]]
2024-08-29 13:21:24.956 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : getting activate: activate
2024-08-29 13:21:24.957 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Locating method activate in class org.openhab.binding.evcc.internal.EvccHandlerFactory
2024-08-29 13:21:24.957 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Declared Method org.openhab.binding.evcc.internal.EvccHandlerFactory.activate([interface org.osgi.service.component.ComponentContext]) not found
2024-08-29 13:21:24.957 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Locating method activate in class org.openhab.core.thing.binding.BaseThingHandlerFactory
2024-08-29 13:21:24.958 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Found activate method: protected void org.openhab.core.thing.binding.BaseThingHandlerFactory.activate(org.osgi.service.component.ComponentContext)
2024-08-29 13:21:24.958 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.manager.ComponentContextImpl]
2024-08-29 13:21:24.959 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : invoked activate: activate
2024-08-29 13:21:24.959 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Set implementation object for component
2024-08-29 13:21:24.959 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291052 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Changed state from satisfied to active
2024-08-29 13:21:24.968 [INFO ] [org.apache.felix.fileinstall        ] - Started bundle: file:/usr/share/openhab/addons/org.openhab.binding.evcc-4.3.0-SNAPSHOT.jar
2024-08-29 13:21:26.310 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Setting up refresh job ...
2024-08-29 13:21:26.311 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Running refresh job ...
2024-08-29 13:21:26.318 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 1 loadpoints on site Mein Zuhause.
2024-08-29 13:21:26.319 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 2 vehicles on site Mein Zuhause.
2024-08-29 13:21:26.321 [INFO ] [ab.binding.evcc.internal.EvccHandler] - Creating evcc channels with channelGroup loadpoint0current
2024-08-29 13:21:26.330 [INFO ] [ab.binding.evcc.internal.EvccHandler] - Creating vehicle with name db:1
2024-08-29 13:21:26.330 [INFO ] [ab.binding.evcc.internal.EvccHandler] - Creating evcc channels with channelGroup vehicledb:1
2024-08-29 13:21:26.330 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.IllegalArgumentException: UID segment 'vehicledb:1#vehicleMinSoC' contains invalid characters. The last segment of the channel UID must match the pattern '[\w-]*|[\w-]*#[\w-]*'.
    at org.openhab.core.thing.ChannelUID.validateSegment(ChannelUID.java:136) ~[?:?]
    at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:76) ~[?:?]
    at org.openhab.core.thing.UID.<init>(UID.java:66) ~[?:?]
    at org.openhab.core.thing.ChannelUID.<init>(ChannelUID.java:76) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannel(EvccHandler.java:996) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannelsVehicle(EvccHandler.java:636) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannelsVehicle(EvccHandler.java:585) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.refresh(EvccHandler.java:428) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
    at java.lang.Thread.run(Thread.java:840) [?:?]

lsiepel commented 2 weeks ago

Your vehicle name contains a : that is unexpected. Are you able to configure the vehicle name somewhere?

Relevant parts:

2024-08-29 13:21:26.330 [INFO ] [ab.binding.evcc.internal.EvccHandler] - Creating vehicle with name db:1
2024-08-29 13:21:26.330 [INFO ] [ab.binding.evcc.internal.EvccHandler] - Creating evcc channels with channelGroup vehicledb:1

lsiepel commented 2 weeks ago

I have updated the jar, it should now handle the semicolon properly. Please let me know your test findings.

rbeudel commented 2 weeks ago

I am not able to configure those : , nothing in the yaml. I deleted the jar and copied the new jar, but nothing better. Then I deleted the jar again and cleaned the cache. I copied the new jar again, but not good: 2024-08-29 15:09:18.119 [INFO ] [org.apache.felix.fileinstall ] - Started bundle: file:/usr/share/openhab/addons/org.openhab.binding.evcc-4.3.0-SNAPSHOT(1).jar 2024-08-29 15:09:18.374 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Setting up refresh job ... 2024-08-29 15:09:18.375 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Running refresh job ... 2024-08-29 15:09:18.390 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 1 loadpoints on site Mein Zuhause. 2024-08-29 15:09:18.391 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 1 vehicles on site Mein Zuhause. 2024-08-29 15:09:18.417 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: java.lang.IllegalArgumentException: UID segment 'vehicledb:1#vehicleMinSoC' contains invalid characters. The last segment of the channel UID must match the pattern '[\w-]*|[\w-]*#[\w-]*'. at org.openhab.core.thing.ChannelUID.validateSegment(ChannelUID.java:136) ~[?:?] at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:76) ~[?:?] at org.openhab.core.thing.UID.<init>(UID.java:66) ~[?:?] at org.openhab.core.thing.ChannelUID.<init>(ChannelUID.java:76) ~[?:?] at org.openhab.binding.evcc.internal.EvccHandler.createChannel(EvccHandler.java:995) ~[?:?] at org.openhab.binding.evcc.internal.EvccHandler.createChannelsVehicle(EvccHandler.java:635) ~[?:?] at org.openhab.binding.evcc.internal.EvccHandler.createChannelsVehicle(EvccHandler.java:584) ~[?:?] at org.openhab.binding.evcc.internal.EvccHandler.refresh(EvccHandler.java:428) ~[?:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?] at java.lang.Thread.run(Thread.java:840) [?:?] Thank you for the help until now, I trie out what you like.

rbeudel commented 2 weeks ago

May it be a problem if the password for the car api contains something like ( or - ?

lsiepel commented 2 weeks ago

No it is the UID for sure, that is based on the vehicle car. That comes from the remote API. I'll create another extensive logging version later.

lsiepel commented 1 week ago

Updated the JAR: https://1drv.ms/u/s!AnMcxmvEeupwjv9nXPTluQVNdRcAHQ?e=M46ft0 I would expect this issue to be solved, but appearently i'm missing something. Added some additional logging to see what.

rbeudel commented 1 week ago

I got the same logging as before aI think

2024-09-06 20:05:37.574 [INFO ] [org.apache.felix.fileinstall        ] - Uninstalling bundle 331 (org.openhab.binding.evcc)
2024-09-06 20:05:37.579 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Querying state active
2024-09-06 20:05:37.581 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Deactivating component
2024-09-06 20:05:37.582 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : registration change queue [unregistered]
2024-09-06 20:05:37.594 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Querying state active
2024-09-06 20:05:37.594 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : getting deactivate: deactivate
2024-09-06 20:05:37.597 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Locating method deactivate in class org.openhab.binding.evcc.internal.EvccHandlerFactory
2024-09-06 20:05:37.597 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Declared Method org.openhab.binding.evcc.internal.EvccHandlerFactory.deactivate([interface org.osgi.service.component.ComponentContext]) not found
2024-09-06 20:05:37.598 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Locating method deactivate in class org.openhab.core.thing.binding.BaseThingHandlerFactory
2024-09-06 20:05:37.598 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Found deactivate method: protected void org.openhab.core.thing.binding.BaseThingHandlerFactory.deactivate(org.osgi.service.component.ComponentContext)
2024-09-06 20:05:37.598 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : invoking deactivate: deactivate: parameters [org.apache.felix.scr.impl.manager.ComponentContextImpl]
2024-09-06 20:05:37.598 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : invoked deactivate: deactivate
2024-09-06 20:05:37.599 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : DependencyManager: osgi.ds.satisfying.condition close component unbinding from org.apache.felix.scr.impl.manager.ComponentContextImpl@3046a114 at tracking count 1 refpairs: [[RefPair: ref: [{org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true}] service: [null]]]
2024-09-06 20:05:37.599 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Unset and deconfigured implementation object for component in deleteComponent for reason Unspecified
2024-09-06 20:05:37.599 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Changed state from active to satisfied
2024-09-06 20:05:37.600 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Deactivating dependency managers
2024-09-06 20:05:37.600 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Disabling dependency managers
2024-09-06 20:05:37.600 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : unregistering service listener for dependency osgi.ds.satisfying.condition
2024-09-06 20:05:37.600 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Querying state satisfied
2024-09-06 20:05:37.600 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Changed state from satisfied to disposed
2024-09-06 20:05:37.600 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202408291201 (331)[org.openhab.binding.evcc.internal.EvccHandlerFactory(456)] : Disposing component (reason: 6)
2024-09-06 20:06:07.745 [INFO ] [org.apache.felix.fileinstall        ] - Installing bundle org.openhab.binding.evcc / 4.3.0.202409061756
2024-09-06 20:06:07.785 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : BundleComponentActivator : ComponentHolder created.
2024-09-06 20:06:07.786 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Dependency Manager created osgi.ds.satisfying.conditioninterface=org.osgi.service.condition.Condition, filter=(osgi.condition.id=true), policy=dynamic, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=null
2024-09-06 20:06:07.786 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component created: DS=DS13, implementation=org.openhab.binding.evcc.internal.EvccHandlerFactory, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[binding.evcc]
2024-09-06 20:06:07.786 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component Services: scope=singleton, services=[org.openhab.core.thing.binding.ThingHandlerFactory]
2024-09-06 20:06:07.786 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component Properties: {osgi.ds.satisfying.condition.target=(osgi.condition.id=true)}
2024-09-06 20:06:07.786 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Querying state disabled
2024-09-06 20:06:07.787 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Querying state disabled
2024-09-06 20:06:07.787 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component can not be activated since it is in state disabled
2024-09-06 20:06:07.787 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Querying state disabled
2024-09-06 20:06:07.787 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Updating target filters
2024-09-06 20:06:07.787 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] :  No existing service listener to unregister for dependency osgi.ds.satisfying.condition
2024-09-06 20:06:07.787 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Setting target property for dependency osgi.ds.satisfying.condition to (osgi.condition.id=true)
2024-09-06 20:06:07.787 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : New service tracker for osgi.ds.satisfying.condition, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.condition.Condition), initialReferenceFilter (&(objectClass=org.osgi.service.condition.Condition)(osgi.condition.id=true))
2024-09-06 20:06:07.787 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : dm osgi.ds.satisfying.condition tracker reset (closed)
2024-09-06 20:06:07.788 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : dm osgi.ds.satisfying.condition tracking 1 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (enter)
2024-09-06 20:06:07.788 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : dm osgi.ds.satisfying.condition tracking 1 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (exit)
2024-09-06 20:06:07.788 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : dm osgi.ds.satisfying.condition tracker opened
2024-09-06 20:06:07.788 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : registering service listener for dependency osgi.ds.satisfying.condition
2024-09-06 20:06:07.788 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Changed state from disabled to unsatisfiedReference
2024-09-06 20:06:07.788 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Component enabled
2024-09-06 20:06:07.788 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : ActivateInternal
2024-09-06 20:06:07.788 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Querying state unsatisfiedReference
2024-09-06 20:06:07.789 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Querying state unsatisfiedReference
2024-09-06 20:06:07.789 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Activating component from state unsatisfiedReference
2024-09-06 20:06:07.789 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Querying state unsatisfiedReference
2024-09-06 20:06:07.789 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Querying state unsatisfiedReference
2024-09-06 20:06:07.789 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Changed state from unsatisfiedReference to satisfied
2024-09-06 20:06:07.789 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : registration change queue [registered]
2024-09-06 20:06:07.792 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Checking constructor public org.openhab.binding.evcc.internal.EvccHandlerFactory()
2024-09-06 20:06:07.794 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Found constructor with 0 arguments : public org.openhab.binding.evcc.internal.EvccHandlerFactory()
2024-09-06 20:06:07.794 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : This thread collected dependencies
2024-09-06 20:06:07.794 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : getService (single component manager) dependencies collected.
2024-09-06 20:06:07.794 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Querying state satisfied
2024-09-06 20:06:07.794 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Querying state satisfied
2024-09-06 20:06:07.794 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : For dependency osgi.ds.satisfying.condition, optional: false; to bind: [[RefPair: ref: [{org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true}] service: [null]]]
2024-09-06 20:06:07.796 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : getting activate: activate
2024-09-06 20:06:07.796 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Locating method activate in class org.openhab.binding.evcc.internal.EvccHandlerFactory
2024-09-06 20:06:07.796 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Declared Method org.openhab.binding.evcc.internal.EvccHandlerFactory.activate([interface org.osgi.service.component.ComponentContext]) not found
2024-09-06 20:06:07.796 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Locating method activate in class org.openhab.core.thing.binding.BaseThingHandlerFactory
2024-09-06 20:06:07.796 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Found activate method: protected void org.openhab.core.thing.binding.BaseThingHandlerFactory.activate(org.osgi.service.component.ComponentContext)
2024-09-06 20:06:07.796 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.manager.ComponentContextImpl]
2024-09-06 20:06:07.797 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : invoked activate: activate
2024-09-06 20:06:07.797 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Set implementation object for component
2024-09-06 20:06:07.797 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061756 (332)[org.openhab.binding.evcc.internal.EvccHandlerFactory(457)] : Changed state from satisfied to active
2024-09-06 20:06:07.802 [INFO ] [org.apache.felix.fileinstall        ] - Started bundle: file:/usr/share/openhab/addons/org.openhab.binding.evcc-4.3.0-SNAPSHOT(2).jar
2024-09-06 20:06:08.783 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Setting up refresh job ...
2024-09-06 20:06:08.784 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Running refresh job ...
2024-09-06 20:06:08.793 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 1 loadpoints on site Mein Zuhause.
2024-09-06 20:06:08.794 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 2 vehicles on site Mein Zuhause.
2024-09-06 20:06:08.796 [INFO ] [ab.binding.evcc.internal.EvccHandler] - line 491, vehicleName 
2024-09-06 20:06:08.801 [INFO ] [ab.binding.evcc.internal.EvccHandler] - line 817, vehicleName 
2024-09-06 20:06:08.804 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.IllegalArgumentException: UID segment 'vehicledb:1#vehicleMinSoC' contains invalid characters. The last segment of the channel UID must match the pattern '[\w-]*|[\w-]*#[\w-]*'.
    at org.openhab.core.thing.ChannelUID.validateSegment(ChannelUID.java:136) ~[?:?]
    at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:76) ~[?:?]
    at org.openhab.core.thing.UID.<init>(UID.java:66) ~[?:?]
    at org.openhab.core.thing.ChannelUID.<init>(ChannelUID.java:76) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannel(EvccHandler.java:997) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannelsVehicle(EvccHandler.java:636) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannelsVehicle(EvccHandler.java:585) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.refresh(EvccHandler.java:429) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
    at java.lang.Thread.run(Thread.java:840) [?:?]

lsiepel commented 1 week ago

These lines where added:

2024-09-06 20:06:08.796 [INFO ] [ab.binding.evcc.internal.EvccHandler] - line 491, vehicleName 
2024-09-06 20:06:08.801 [INFO ] [ab.binding.evcc.internal.EvccHandler] - line 817, vehicleName

Based on:

logger.info("line 241, vehicleName {}", vehicleName);

I conclude the vehicleName is blank. Created a new version at the same link provided before, let me know your test results (and log). Thanks for all the testing.

rbeudel commented 1 week ago

Unfortunately a warning again

2024-09-07 08:43:19.769 [INFO ] [org.apache.felix.fileinstall        ] - Installing bundle org.openhab.binding.evcc / 4.3.0.202409061924
2024-09-07 08:43:19.813 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : BundleComponentActivator : ComponentHolder created.
2024-09-07 08:43:19.814 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Dependency Manager created osgi.ds.satisfying.conditioninterface=org.osgi.service.condition.Condition, filter=(osgi.condition.id=true), policy=dynamic, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=null
2024-09-07 08:43:19.815 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component created: DS=DS13, implementation=org.openhab.binding.evcc.internal.EvccHandlerFactory, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[binding.evcc]
2024-09-07 08:43:19.815 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component Services: scope=singleton, services=[org.openhab.core.thing.binding.ThingHandlerFactory]
2024-09-07 08:43:19.815 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component Properties: {osgi.ds.satisfying.condition.target=(osgi.condition.id=true)}
2024-09-07 08:43:19.815 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Querying state disabled
2024-09-07 08:43:19.815 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Querying state disabled
2024-09-07 08:43:19.815 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component can not be activated since it is in state disabled
2024-09-07 08:43:19.816 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Querying state disabled
2024-09-07 08:43:19.817 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Updating target filters
2024-09-07 08:43:19.817 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] :  No existing service listener to unregister for dependency osgi.ds.satisfying.condition
2024-09-07 08:43:19.817 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Setting target property for dependency osgi.ds.satisfying.condition to (osgi.condition.id=true)
2024-09-07 08:43:19.817 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : New service tracker for osgi.ds.satisfying.condition, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.condition.Condition), initialReferenceFilter (&(objectClass=org.osgi.service.condition.Condition)(osgi.condition.id=true))
2024-09-07 08:43:19.817 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : dm osgi.ds.satisfying.condition tracker reset (closed)
2024-09-07 08:43:19.817 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : dm osgi.ds.satisfying.condition tracking 1 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (enter)
2024-09-07 08:43:19.817 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : dm osgi.ds.satisfying.condition tracking 1 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (exit)
2024-09-07 08:43:19.818 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : dm osgi.ds.satisfying.condition tracker opened
2024-09-07 08:43:19.818 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : registering service listener for dependency osgi.ds.satisfying.condition
2024-09-07 08:43:19.818 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Changed state from disabled to unsatisfiedReference
2024-09-07 08:43:19.818 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Component enabled
2024-09-07 08:43:19.818 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : ActivateInternal
2024-09-07 08:43:19.819 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Querying state unsatisfiedReference
2024-09-07 08:43:19.819 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Querying state unsatisfiedReference
2024-09-07 08:43:19.819 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Activating component from state unsatisfiedReference
2024-09-07 08:43:19.819 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Querying state unsatisfiedReference
2024-09-07 08:43:19.819 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Querying state unsatisfiedReference
2024-09-07 08:43:19.819 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Changed state from unsatisfiedReference to satisfied
2024-09-07 08:43:19.819 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : registration change queue [registered]
2024-09-07 08:43:19.824 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Checking constructor public org.openhab.binding.evcc.internal.EvccHandlerFactory()
2024-09-07 08:43:19.825 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Found constructor with 0 arguments : public org.openhab.binding.evcc.internal.EvccHandlerFactory()
2024-09-07 08:43:19.825 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : This thread collected dependencies
2024-09-07 08:43:19.825 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : getService (single component manager) dependencies collected.
2024-09-07 08:43:19.825 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Querying state satisfied
2024-09-07 08:43:19.825 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Querying state satisfied
2024-09-07 08:43:19.825 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : For dependency osgi.ds.satisfying.condition, optional: false; to bind: [[RefPair: ref: [{org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true}] service: [null]]]
2024-09-07 08:43:19.827 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : getting activate: activate
2024-09-07 08:43:19.827 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Locating method activate in class org.openhab.binding.evcc.internal.EvccHandlerFactory
2024-09-07 08:43:19.828 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Declared Method org.openhab.binding.evcc.internal.EvccHandlerFactory.activate([interface org.osgi.service.component.ComponentContext]) not found
2024-09-07 08:43:19.828 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Locating method activate in class org.openhab.core.thing.binding.BaseThingHandlerFactory
2024-09-07 08:43:19.828 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Found activate method: protected void org.openhab.core.thing.binding.BaseThingHandlerFactory.activate(org.osgi.service.component.ComponentContext)
2024-09-07 08:43:19.828 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.manager.ComponentContextImpl]
2024-09-07 08:43:19.828 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : invoked activate: activate
2024-09-07 08:43:19.828 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Set implementation object for component
2024-09-07 08:43:19.828 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409061924 (333)[org.openhab.binding.evcc.internal.EvccHandlerFactory(458)] : Changed state from satisfied to active
2024-09-07 08:43:19.840 [INFO ] [org.apache.felix.fileinstall        ] - Started bundle: file:/usr/share/openhab/addons/org.openhab.binding.evcc-4.3.0-SNAPSHOT(3).jar
2024-09-07 08:43:20.600 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Setting up refresh job ...
2024-09-07 08:43:20.602 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Running refresh job ...
2024-09-07 08:43:20.610 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 1 loadpoints on site Mein Zuhause.
2024-09-07 08:43:20.611 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 2 vehicles on site Mein Zuhause.
2024-09-07 08:43:20.612 [INFO ] [ab.binding.evcc.internal.EvccHandler] - line 491, vehicleName ''
2024-09-07 08:43:20.623 [INFO ] [ab.binding.evcc.internal.EvccHandler] - line 817, vehicleName ''
2024-09-07 08:43:20.628 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.IllegalArgumentException: UID segment 'vehicledb:1#vehicleMinSoC' contains invalid characters. The last segment of the channel UID must match the pattern '[\w-]*|[\w-]*#[\w-]*'.
    at org.openhab.core.thing.ChannelUID.validateSegment(ChannelUID.java:136) ~[?:?]
    at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:76) ~[?:?]
    at org.openhab.core.thing.UID.<init>(UID.java:66) ~[?:?]
    at org.openhab.core.thing.ChannelUID.<init>(ChannelUID.java:76) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannel(EvccHandler.java:997) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannelsVehicle(EvccHandler.java:636) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannelsVehicle(EvccHandler.java:585) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.refresh(EvccHandler.java:429) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
    at java.lang.Thread.run(Thread.java:840) [?:?]

lsiepel commented 1 week ago

Missed a codepath, sorry for the amount of itterations. Also added the raw response to the logging output, so if it is not solved by now i can create unit tests. Please re-use the same link, the jar is updated.

Ultimately we can add a fix that is either:

ignore vehicles without a name, related channels wil not work.
generate a vehicle name within the binding, still have to look if there are property's available to have this stable and reproducable.

rbeudel commented 1 week ago

For your information, the first car Dennis DB:1 is created with the UI function of evcc and the second car EV5 with in the yaml.

2024-09-07 10:11:10.081 [INFO ] [org.apache.felix.fileinstall        ] - Installing bundle org.openhab.binding.evcc / 4.3.0.202409070723
2024-09-07 10:11:10.115 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : BundleComponentActivator : ComponentHolder created.
2024-09-07 10:11:10.116 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Dependency Manager created osgi.ds.satisfying.conditioninterface=org.osgi.service.condition.Condition, filter=(osgi.condition.id=true), policy=dynamic, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=null
2024-09-07 10:11:10.116 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component created: DS=DS13, implementation=org.openhab.binding.evcc.internal.EvccHandlerFactory, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[binding.evcc]
2024-09-07 10:11:10.116 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component Services: scope=singleton, services=[org.openhab.core.thing.binding.ThingHandlerFactory]
2024-09-07 10:11:10.116 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component Properties: {osgi.ds.satisfying.condition.target=(osgi.condition.id=true)}
2024-09-07 10:11:10.116 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Querying state disabled
2024-09-07 10:11:10.116 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Querying state disabled
2024-09-07 10:11:10.117 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Component can not be activated since it is in state disabled
2024-09-07 10:11:10.117 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory] : Querying state disabled
2024-09-07 10:11:10.117 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Updating target filters
2024-09-07 10:11:10.117 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] :  No existing service listener to unregister for dependency osgi.ds.satisfying.condition
2024-09-07 10:11:10.117 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Setting target property for dependency osgi.ds.satisfying.condition to (osgi.condition.id=true)
2024-09-07 10:11:10.117 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : New service tracker for osgi.ds.satisfying.condition, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.condition.Condition), initialReferenceFilter (&(objectClass=org.osgi.service.condition.Condition)(osgi.condition.id=true))
2024-09-07 10:11:10.117 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : dm osgi.ds.satisfying.condition tracker reset (closed)
2024-09-07 10:11:10.117 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : dm osgi.ds.satisfying.condition tracking 1 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (enter)
2024-09-07 10:11:10.118 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : dm osgi.ds.satisfying.condition tracking 1 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (exit)
2024-09-07 10:11:10.118 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : dm osgi.ds.satisfying.condition tracker opened
2024-09-07 10:11:10.118 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : registering service listener for dependency osgi.ds.satisfying.condition
2024-09-07 10:11:10.118 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Changed state from disabled to unsatisfiedReference
2024-09-07 10:11:10.118 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Component enabled
2024-09-07 10:11:10.118 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : ActivateInternal
2024-09-07 10:11:10.118 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Querying state unsatisfiedReference
2024-09-07 10:11:10.118 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Querying state unsatisfiedReference
2024-09-07 10:11:10.118 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Activating component from state unsatisfiedReference
2024-09-07 10:11:10.119 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Querying state unsatisfiedReference
2024-09-07 10:11:10.119 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Querying state unsatisfiedReference
2024-09-07 10:11:10.119 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Changed state from unsatisfiedReference to satisfied
2024-09-07 10:11:10.119 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : registration change queue [registered]
2024-09-07 10:11:10.120 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Checking constructor public org.openhab.binding.evcc.internal.EvccHandlerFactory()
2024-09-07 10:11:10.120 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Found constructor with 0 arguments : public org.openhab.binding.evcc.internal.EvccHandlerFactory()
2024-09-07 10:11:10.121 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : This thread collected dependencies
2024-09-07 10:11:10.121 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : getService (single component manager) dependencies collected.
2024-09-07 10:11:10.121 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Querying state satisfied
2024-09-07 10:11:10.121 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Querying state satisfied
2024-09-07 10:11:10.121 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : For dependency osgi.ds.satisfying.condition, optional: false; to bind: [[RefPair: ref: [{org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true}] service: [null]]]
2024-09-07 10:11:10.123 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : getting activate: activate
2024-09-07 10:11:10.123 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Locating method activate in class org.openhab.binding.evcc.internal.EvccHandlerFactory
2024-09-07 10:11:10.123 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Declared Method org.openhab.binding.evcc.internal.EvccHandlerFactory.activate([interface org.osgi.service.component.ComponentContext]) not found
2024-09-07 10:11:10.123 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Locating method activate in class org.openhab.core.thing.binding.BaseThingHandlerFactory
2024-09-07 10:11:10.123 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Found activate method: protected void org.openhab.core.thing.binding.BaseThingHandlerFactory.activate(org.osgi.service.component.ComponentContext)
2024-09-07 10:11:10.123 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.manager.ComponentContextImpl]
2024-09-07 10:11:10.124 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : invoked activate: activate
2024-09-07 10:11:10.124 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Set implementation object for component
2024-09-07 10:11:10.124 [DEBUG] [ing.evcc.internal.EvccHandlerFactory] - bundle org.openhab.binding.evcc:4.3.0.202409070723 (334)[org.openhab.binding.evcc.internal.EvccHandlerFactory(459)] : Changed state from satisfied to active
2024-09-07 10:11:10.139 [INFO ] [org.apache.felix.fileinstall        ] - Started bundle: file:/usr/share/openhab/addons/org.openhab.binding.evcc-4.3.0-SNAPSHOT(4).jar
2024-09-07 10:11:11.635 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Setting up refresh job ...
2024-09-07 10:11:11.636 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Running refresh job ...
2024-09-07 10:11:11.640 [DEBUG] [ab.binding.evcc.internal.api.EvccAPI] - {"result":{"auth":{},"availableVersion":"0.130.7","battery":[{"power":-833,"soc":23,"controllable":true}],"batteryCapacity":0,"batteryDischargeControl":true,"batteryEnergy":0,"batteryGridChargeActive":false,"batteryMode":"normal","batteryPower":-833,"batterySoc":23,"bufferSoc":0,"bufferStartSoc":0,"currency":"EUR","fatal":null,"greenShareHome":1,"greenShareLoadpoints":0,"gridConfigured":true,"gridCurrents":[-0.934,0.371,0.227],"gridEnergy":373.974,"gridPower":19,"gridPowers":[-50,68,2],"homePower":656,"influx":{"url":"","database":"","org":"","user":""},"interval":30,"loadpoints":[{"chargeCurrent":0,"chargeDuration":9006,"chargePower":0,"chargeRemainingDuration":0,"chargeRemainingEnergy":0,"chargedEnergy":27359.02,"chargerFeatureHeating":false,"chargerFeatureIntegratedDevice":false,"chargerIcon":null,"chargerPhases1p3p":false,"chargerPhysicalPhases":null,"charging":false,"connected":false,"connectedDuration":9360,"disableThreshold":0,"effectiveLimitSoc":100,"effectiveMaxCurrent":6,"effectiveMinCurrent":6,"effectivePlanSoc":0,"effectivePlanTime":null,"effectivePriority":0,"enableThreshold":0,"enabled":false,"limitEnergy":0,"limitSoc":0,"maxCurrent":6,"minCurrent":6,"mode":"off","phaseAction":"inactive","phaseRemaining":0,"phasesActive":1,"phasesConfigured":1,"phasesEnabled":1,"planEnergy":0,"planOverrun":0,"planProjectedEnd":null,"planProjectedStart":null,"planTime":null,"priority":0,"pvAction":"inactive","pvRemaining":0,"sessionCo2PerKWh":null,"sessionEnergy":27359.02,"sessionPrice":8.843,"sessionPricePerKWh":0.323,"sessionSolarPercentage":7.633,"smartCostActive":false,"smartCostNextStart":null,"title":"Garage","vehicleClimaterActive":null,"vehicleDetectionActive":false,"vehicleLimitSoc":0,"vehicleName":"","vehicleOdometer":0,"vehicleRange":0,"vehicleSoc":0,"vehicleWelcomeActive":false}],"maxGridSupplyWhileBatteryCharging":0,"mqtt":{"broker":"192.168.1.112:1883","topic":"evcc","user":"","clientID":"","insecure":true},"network":{"schema":"http","host":"evcc.local","port":7070},"prioritySoc":20,"pv":[{"power":1297,"energy":19983.342},{"power":173,"energy":568.6879883}],"pvEnergy":20552.03,"pvPower":1470,"residualPower":100,"siteTitle":"Mein Zuhause","smartCostType":"pricestatic","sponsor":{"name":"rbeudel","expiresAt":"2027-06-14T15:00:00Z"},"statistics":{"30d":{"avgCo2":0,"avgPrice":0.3110970151660133,"chargedKWh":168.43368034478678,"solarPercentage":13.077471827183444},"365d":{"avgCo2":0,"avgPrice":0.3110970151660133,"chargedKWh":168.43368034478678,"solarPercentage":13.077471827183444},"thisYear":{"avgCo2":0,"avgPrice":0.3110970151660133,"chargedKWh":168.43368034478678,"solarPercentage":13.077471827183444},"total":{"avgCo2":0,"avgPrice":0.3110970151660133,"chargedKWh":168.43368034478678,"solarPercentage":13.077471827183444}},"tariffFeedIn":0.12,"tariffGrid":0.34,"tariffPriceHome":0.12,"tariffPriceLoadpoints":0.34,"vehicles":{"db:1":{"title":"Dennis","icon":"car","capacity":58},"ev5":{"title":"Ioniq 5","icon":"car","capacity":77}},"version":"0.130.6"}}

2024-09-07 10:11:11.643 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 1 loadpoints on site Mein Zuhause.
2024-09-07 10:11:11.644 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 2 vehicles on site Mein Zuhause.
2024-09-07 10:11:11.645 [INFO ] [ab.binding.evcc.internal.EvccHandler] - line 491, vehicleName ''
2024-09-07 10:11:11.655 [INFO ] [ab.binding.evcc.internal.EvccHandler] - line 817, vehicleName ''
2024-09-07 10:11:11.659 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.IllegalArgumentException: UID segment 'vehicledb:1#vehicleMinSoC' contains invalid characters. The last segment of the channel UID must match the pattern '[\w-]*|[\w-]*#[\w-]*'.
    at org.openhab.core.thing.ChannelUID.validateSegment(ChannelUID.java:136) ~[?:?]
    at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:76) ~[?:?]
    at org.openhab.core.thing.UID.<init>(UID.java:66) ~[?:?]
    at org.openhab.core.thing.ChannelUID.<init>(ChannelUID.java:76) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannel(EvccHandler.java:1002) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannelsVehicle(EvccHandler.java:641) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.createChannelsVehicle(EvccHandler.java:590) ~[?:?]
    at org.openhab.binding.evcc.internal.EvccHandler.refresh(EvccHandler.java:433) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
    at java.lang.Thread.run(Thread.java:840) [?:?]

lsiepel commented 1 week ago

Thanks, updated the jar once again. Now it should contain a fix. The : is replaced by a -. This should be robust enough to work everywhere.

Let me know if this works as expected.

rbeudel commented 1 week ago

Yes it does

2024-09-07 15:12:50.960 [INFO ] [org.apache.felix.fileinstall ] - Started bundle: file:/usr/share/openhab/addons/org.openhab.binding.evcc-4.3.0-SNAPSHOT(5).jar 2024-09-07 15:12:51.279 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Setting up refresh job ... 2024-09-07 15:12:51.283 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Running refresh job ... 2024-09-07 15:12:51.289 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 1 loadpoints on site Mein Zuhause. 2024-09-07 15:12:51.290 [DEBUG] [ab.binding.evcc.internal.EvccHandler] - Found 2 vehicles on site Mein Zuhause.

no warning at all. Openhab is updated bei evcc. Great job. Thank you very much for your work.

openhab / openhab-addons

[evcc] Data will not been updated #17343