openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.9k stars 3.59k forks source link

[goecharger] Binding is not working #14999

Closed Andycool29 closed 2 months ago

Andycool29 commented 1 year ago

I'm using this binding to surplus charging with PV. the binding is not working. If I disable and after enable the binding in OpenHab3 it works correctly. After all Pug/unplug activites with my e-car I have to restart the binding, otherwis surplus charging is not working correct. Instead http reguests are allways working with the GoE Wallbox.

hypetsch commented 1 year ago

This sounds similar to the issue I experienced twice now. In my case it was an ArrayIndexOutOfBoundsException.

2023-05-31 03:00:16.244 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1
        at org.openhab.binding.goecharger.internal.handler.GoEChargerV2Handler.getValue(GoEChargerV2Handler.java:155) ~[?:?]
        at org.openhab.binding.goecharger.internal.handler.GoEChargerV2Handler.lambda$1(GoEChargerV2Handler.java:381) ~[?:?]
        at java.util.ArrayList.forEach(ArrayList.java:1541) ~[?:?]
        at org.openhab.binding.goecharger.internal.handler.GoEChargerV2Handler.updateChannelsAndStatus(GoEChargerV2Handler.java:381) ~[?:?]
        at org.openhab.binding.goecharger.internal.handler.GoEChargerBaseHandler.refresh(GoEChargerBaseHandler.java:126) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
        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:1128) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
        at java.lang.Thread.run(Thread.java:829) [?:?]

As far as I understood the code, this should not happen anymore after the latest changes made in #14933 (even though the title is regarding a NullPointerException). So I am looking forward to an upcoming release.

Edit: Just for correctness: the orriginal fix for the ArrayIndexOutOfBoundsException was probably #14632

lsiepel commented 1 year ago

@Andycool29 can you verify this still exists with openHAB 4.0? As it looks like it has been fixed.

Andycool29 commented 1 year ago

It still exists with openhab 4.0

lsiepel commented 1 year ago

I’ll try to come up with a fix, but I need you for testing as I don’t own a goecharger.

Andycool29 commented 1 year ago

If its feasible from your side, ok let´s try

lsiepel commented 1 year ago

Can you elaborate on the issue and maybe provide some logs showing the issue?

I'm pretty sure it is not the ArrayIndexOutOfBoundsException or NullPointerException those seem properly fixed.

Andycool29 commented 1 year ago

Sorry i was absent the last few days. Just FYI i use openhab on CasaOS Docker, not knowing if this could also create problems. Eventlog is too big to send you, how can I send you the file?

Andycool29 commented 1 year ago

openhablogs.zip

lsiepel commented 1 year ago

Thanks. When i look at the log, i can see you manually disabled/enabled it here:

2023-08-07 13:32:44.527 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'goecharger:goe:519830c0b2' changed from ONLINE to UNINITIALIZED
2023-08-07 13:32:44.539 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'goecharger:goe:519830c0b2' changed from UNINITIALIZED to UNINITIALIZED (DISABLED)
2023-08-07 13:32:53.835 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'goecharger:goe:519830c0b2' changed from UNINITIALIZED (DISABLED) to INITIALIZING
2023-08-07 13:32:53.843 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'goecharger:goe:519830c0b2' changed from INITIALIZING to UNKNOWN
2023-08-07 13:32:54.073 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'goecharger:goe:519830c0b2' changed from UNKNOWN to ONLINE

I don't see any warning or error. If i'm not mistaken, the problem is that some channel is no longer updating, or some commands are no longer send, when the car is unplugged and later plugged in again?

Coudl you be more specific in what channel, steps to reproduce?

Could you put the binding log mode in trace? Unplug/re-plug the car, send a command like ALLOW_CHARGING = ON And send the log of that timeframe?

Just a copy of the openhab.log will be fine.

Andycool29 commented 1 year ago

Ok i try to do some tests. I do some control by http-Command like Allow_charging, set current and so on, this is always working, due to some missing functions in the GoE-Binding. E-Car is charged when I have enough PV-Power and this always works. With the command "Fahrzeug lädt" I start some calculation about energy consumption (autarky-Calculation). This is not working, as the command from GoE is only working after restart (when I unplug/plug).

How do I start the binding log mode? I´ve never done this so far...

Bildschirmfoto 2023-08-07 um 16 53 30
lsiepel commented 1 year ago

I do some control by http-Command like Allow_charging, set current and so on, this is always working, due to some missing functions in the GoE-Binding.

All that http stuff should not be needed as all that is allready supported by the binding.

E-Car is charged when I have enough PV-Power and this always works. With the command "Fahrzeug lädt" I start some calculation about energy consumption (autarky-Calculation). This is not working, as the command from GoE is only working after restart (when I unplug/plug).

Still missing some information here. To rule out problems with the calculation/script (is it an openHAB rule?) you could link an Item to the goecharger channel allowCharging in MainUI. From there you can manually set it to on/off without using any kind of calculations etc.

I would like to have your log file set to TRACE, when the car is plugged toggle an on/off cycle to the allowCharging channel. Unplug the car, wait a minute, plug it back in and repeat the on/off toggle.

How to log could be read from the documentation: https://www.openhab.org/docs/administration/logging.html

But i'll save you some time, at the openHAB console: log:set TRACE org.openhab.binding.goecharger

Andycool29 commented 1 year ago

ALW and FRC was not working with the GoE binding (API version 2), thats why I'm using http-Commands, whereby I´d rather prefer using only the binding. I´d really appreciate a simpler solution, only using the binding. Enclosed my rules: ` rule "Wallbox start automatic" when //Item T_Einspeisung received update Time cron "0 0/3 ? " then
val IP_Wallbox = "gerties-goe" val Car_JSON = sendHttpGetRequest("http://" + IP_Wallbox + "/api/status?filter=car") //logInfo("GoE AutoStart", "Car Status " + Car_JSON) val Car_state = transform("JSONPATH", "$.car", Car_JSON) logInfo("GoE AutoStart", "Car Status " + Car_state + " " + " Spannung " + GoE_VoltageL1.state as Number

rule "Wallbox charging automatic" when Time cron "0 0/3 ? " //alle 3 Minuten checken, vielleicht besser then

if (GoE_Mode.state != 3 || ZOE_BattLev.state > 95) return;     //Betriebsart Manuell gewählt
val IP_Wallbox = "gerties-goe"
val Number newCurrent = GoE_CurrentL1.state as Number + ((T_Einspeisung.state as Number - T_Netzbezug.state as Number) / GoE_VoltageL1.state as Number / 3)
val Car_JSON = sendHttpGetRequest("http://" + IP_Wallbox + "/api/status?filter=car")
//logInfo("GoE Auto ", "Car JSON " + Car_JSON)
val Car_State = (transform("JSONPATH", "$.car", Car_JSON)) 
logInfo("GoE Auto ", "3min check " + Car_State )

if (Car_State == "2") {               //Zoe wird geladen
    logInfo("GoE Auto", "GoE Ladestrom anpassen  " + Car_State + " GoE Ladestrom " + newCurrent)
    if( newCurrent > 16 ){
        logInfo("GoE Auto", "Ladestrom > 16A " + newCurrent)
        GoE_MaxCurrent.sendCommand(16)
    }
    else if( newCurrent < 6 )
    {
        logInfo("GoE Auto", "Ladestrom < 6A " + newCurrent + " Laden beenden")
        GoE_MaxCurrent.sendCommand(6)
        sendHttpGetRequest("http://" + IP_Wallbox + "/mqtt?payload=alw=0")
        sendHttpGetRequest("http://" + IP_Wallbox + "/api/set?frc=1") // stop charging
    } else {
        logInfo("GoE Auto", "Ladestrom = " + newCurrent)
        GoE_MaxCurrent.sendCommand(newCurrent)
    }  
}    

end

rule "GoE Lademodus" when Item GoE_Mode changed then val IP_Wallbox = "gerties-goe" //"gerties-goe" = "192.168.177.82" //logInfo("GoE Lademodus ", "Manuelles Laden") if (ZOE_BattLev.state > 95) return; if (GoE_Mode.state == 0) { //GoE_AllowCharging.sendCommand(OFF) ### funzt leider nicht #### sendHttpGetRequest("http://" + IP_Wallbox + "/mqtt?payload=alw=0") sendHttpGetRequest("http://" + IP_Wallbox + "/api/set?frc=1") // stop charging GoE_SessionChargeEnergyLimit.sendCommand(30) GoE_MaxCurrent.sendCommand(6) logInfo("GoE Lademodus ", "Manuelles Laden beendet") } if (GoE_Mode.state == 1) { sendHttpGetRequest("http://" + IP_Wallbox + "/api/set?psm=1") // load with one phase //GoE_AllowCharging.sendCommand(ON) ### funzt leider nicht #### sendHttpGetRequest("http://" + IP_Wallbox + "/mqtt?payload=alw=1") sendHttpGetRequest("http://" + IP_Wallbox + "/api/set?frc=2") // start charging //GoE_SessionChargeEnergyLimit.sendCommand(0) logInfo("GoE Lademodus ", "Manuelles Laden 1phasig") } if (GoE_Mode.state == 2) { sendHttpGetRequest("http://" + IP_Wallbox + "/api/set?psm=2") // load with three phases //GoE_AllowCharging.sendCommand(ON) ### funzt leider nicht #### sendHttpGetRequest("http://" + IP_Wallbox + "/mqtt?payload=alw=1") sendHttpGetRequest("http://" + IP_Wallbox + "/api/set?frc=2") // start charging //GoE_SessionChargeEnergyLimit.sendCommand(0) logInfo("GoE Lademodus ", "manuelles Laden mit 3ph begonnen") } if (GoE_Mode.state == 3) //PV Überschuss laden { sendHttpGetRequest("http://" + IP_Wallbox + "/api/set?psm=2") // load with three phases //GoE_SessionChargeEnergyLimit.sendCommand(0) logInfo("GoE Lademodus ", "PV Überschuss aktiv") } end var boolean Flag_BattLev = 0 rule "GoE Status" when Item GoE_PwmSignal changed //Time cron "0 0/1 ? " then val IP_Wallbox = "gerties-goe" val Car_JSON = sendHttpGetRequest("http://" + IP_Wallbox + "/api/status?filter=car") //logInfo("GoE_Status", "Car JSON " + Car_JSON) var GoE_Meldung = transform("JSONPATH", "$.car", Car_JSON) logInfo("GoE_Status", "Status " + GoE_Meldung)

if (GoE_Meldung == "1") {
    logInfo("GoE_Status", "kein Fahrzeug")
    postUpdate(GoE_Status,"Kein Fahrzeug")
}
else 
if (GoE_Meldung == "2") {
    logInfo("GoE_Status", "Fahrzeug lädt")
    postUpdate(GoE_Status,"Fahrzeug lädt")
}
else 
if (GoE_Meldung == "3") {
    logInfo("GoE_Status", "Warte auf Fahrzeug")
    postUpdate(GoE_Status,"Warte auf Fahrzeug")
}
else 
if (GoE_Meldung == "4") {
    logInfo("GoE_Status", "Ladung beendet")
    postUpdate(GoE_Status,"Ladung beendet")
}
else {
    logInfo("GoE_Status", "Fehler GoE")
    postUpdate(GoE_Status,"Fehler GoE")
}
if (Flag_BattLev == 1 && ZOE_BattLev.state <= 90) Flag_BattLev = 0
if (Flag_BattLev == 0 && ZOE_BattLev.state > 95) {
    sendHttpGetRequest("http://" + IP_Wallbox + "/mqtt?payload=alw=0")
    sendHttpGetRequest("http://" + IP_Wallbox + "/api/set?frc=0") // stop charging
    GoE_MaxCurrent.sendCommand(6)
    logInfo("GoE_Status", "ZOE Batterie  = 95%")
    Flag_BattLev = 1
}

end`

lsiepel commented 1 year ago

@Andycool29 Sorry, without the asked information i can't help you.

Andycool29 commented 1 year ago

Ok I try to check your suggestions the next couple of days. I´m not so familar with the openHab console...

Andycool29 commented 1 year ago

@lsiepel I tried your suggestion but get the following error: openhab> log:set TRACE org.openhab.binding.goecharger 17:04:32.866 [Karaf ssh console user openhab] ERROR org.apache.karaf.shell.support.ShellUtil - Exception caught while executing command java.lang.IllegalStateException: Unrecognized configuration at org.apache.karaf.log.core.internal.LogServiceImpl.getDelegate(LogServiceImpl.java:71) ~[?:?] at org.apache.karaf.log.core.internal.LogServiceImpl.setLevel(LogServiceImpl.java:114) ~[?:?] at org.apache.karaf.log.command.SetLogLevel.execute(SetLogLevel.java:48) ~[?:?] at org.apache.karaf.shell.impl.action.command.ActionCommand.execute(ActionCommand.java:84) ~[?:?] at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:68) ~[?:?] at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:86) ~[?:?] at org.apache.felix.gogo.runtime.Closure.executeCmd(Closure.java:599) ~[?:?] at org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:526) ~[?:?] at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:415) ~[?:?] at org.apache.felix.gogo.runtime.Pipe.doCall(Pipe.java:416) ~[?:?] at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:229) ~[?:?] at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:59) ~[?:?] at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?] 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:833) ~[?:?] Error executing command: Unrecognized configuration

lsiepel commented 1 year ago

I have no clue why it throws this exception for this command. Tried to reproduce it, but all seems fine here, looks like something is wrong with your setup.

Another possible route would be: http://yourhost:8080/settings/addons/binding-goecharger/config and set it to trace from there. (alter the url to match your setup)

lsiepel commented 1 year ago

@Andycool29 did you get the trace log going?

Andycool29 commented 1 year ago

@lsiepel Not at all. Actually even frontail is not running anymore. Even event.log and openhab.log is stopped and I can´t start them anymore??? I didn´t find any "how do" in the WWW how to reactivate the general logging (event.log, openhab.log). Without this fundamental log it`s not possible anymore to check rules for error and so on....

lsiepel commented 1 year ago

Something is really wrong there. You probably allready restarted openHAB, did a clean cache etc. You might want to replace "userdata/etc/log4j2.xml" with the stock version?

There might be other places that hold logging configuration (jsondb?) but i don;t know how to reset those without a complete fresh install of openHAB.

Andycool29 commented 1 year ago

@lsiepel Many thxs. I´ll install everything from the scratch, which takes lots of efforts. New installation of OH4 didn´t help so far, after restoring backup I have the same problem. At the moment I´ll will not go ahead as I have not enough time, everything is done in my spare time. I´ll inform you as soon as my logging problems are solved...

lsiepel commented 1 year ago

@lsiepel Many thxs. I´ll install everything from the scratch, which takes lots of efforts. New installation of OH4 didn´t help so far, after restoring backup I have the same problem. At the moment I´ll will not go ahead as I have not enough time, everything is done in my spare time. I´ll inform you as soon as my logging problems are solved...

You might ask on the community forums if there are ways to prevent such a time consuming action. Maybe it is just some stupid file or permission set wrong.

lsiepel commented 2 months ago

Hope you managed to fix this. As there has not been a follow-up in over a year, i close this now. It also doesn't seem to be a bug in the binding, although without the needed details it is hard to say.