openhab / openhab-addons

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

[boschindego] Problem after starting the mower #7438

Closed henrydiesner closed 2 years ago

henrydiesner commented 4 years ago

After starting the Bosch indego mower, the log-file warns (the login credentials are correct!):

"2020-04-21 16:15:06.145 [WARN ] [.internal.handler.BoschIndegoHandler] - The login credentials are wrong or another client connected to your Indego account de.zazaz.iot.bosch.indego.IndegoAuthenticationException: The request failed with error: HTTP/1.1 504 at de.zazaz.iot.bosch.indego.IndegoController.doPutRequest(IndegoController.java:312) ~[?:?] at de.zazaz.iot.bosch.indego.IndegoController.sendCommand(IndegoController.java:190) ~[?:?] at org.openhab.binding.boschindego.internal.handler.BoschIndegoHandler.poll(BoschIndegoHandler.java:132) ~[?:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_232] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_232] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_232] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_232] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]"

And any time later the mower really starts and in the log-file I see:

"2020-04-21 16:19:26.281 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: java.lang.NullPointerException: null at org.openhab.binding.boschindego.internal.handler.BoschIndegoHandler.getEshStatusFromCommand(BoschIndegoHandler.java:205) ~[?:?] at org.openhab.binding.boschindego.internal.handler.BoschIndegoHandler.poll(BoschIndegoHandler.java:139) ~[?:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_232] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_232] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_232] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_232] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]"

The mower works, but he don't answers to the system what he is doing.

22.04.2020 Today I've startet the mower with openHAB and the WARN log is: 2020-04-22 11:57:52.066 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: java.lang.NullPointerException: null at org.openhab.binding.boschindego.internal.handler.BoschIndegoHandler.getEshStatusFromCommand(BoschIndegoHandler.java:205) ~[?:?] at org.openhab.binding.boschindego.internal.handler.BoschIndegoHandler.poll(BoschIndegoHandler.java:139) ~[?:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_232] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_232] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_232] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_232] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]

The mower works, but without any reply to openHAB!

I use a NUC with Debian buster and openhabian (openHAB 2.5.4-1)

Jagohu commented 4 years ago

I have the same problem and I've temporarily solved it with this bash script running every 30 minutes from crontab. I hope it'll be solved sooner or later. In the meanwhile I've set the refresh time to 600 seconds too via PaperUI, hoping it wouldn't time out in about 12 hours. My suspicion is that I might have been polling the API too often (120 seconds) - someone mentioned in a post that the daily maximum should be around 30. Oh yeah, the script searches for the typical error for the binding and if it finds it in the past 30 minutes it restarts the bundle via openhab-cli. Then you should see your Bosch Indego coming back online (in the events.log).

thirtyminsago=`date -d '30 minutes ago' "+%Y-%m-%d %H:%M:"`
firstrow=`cat /var/log/openhab2/events.log | grep "$thirtyminsago" -n | head -n1 | cut -d ':' -f1`
lastrow=`cat /var/log/openhab2/events.log | grep '' -n | tail -n1 | cut -d ':' -f1`
((difference=lastrow-firstrow))

boscherror=`tail -n$difference /var/log/openhab2/openhab.log | grep "at org.openhab.binding.boschindego.internal.handler.BoschIndegoHandler"`
boschprocessid=sshpass -p 'habopen' ssh openhab@127.0.0.1 -p 8101 bundle:list | grep Indego | awk {'print $1'}
if [[ $boscherror != "" ]]; then
    sshpass -p 'habopen' ssh openhab@127.0.0.1 -p 8101 bundle:restart $boschprocessid
fi
henrydiesner commented 4 years ago

At first, I'll try to solve it with 600 seconds refreshing time in the PaperUI. Unfortunatelly I'm not practiced with bash scripts and crontab. I hope, the developer of the binding read that an find a solution. I love the Indego mower and I would like to continue working with it in openHAB.

Jagohu commented 4 years ago

No worries. If it doesn't work just do this in the Raspberry command line:

nano /home/pi/check_boschindego.sh

This will open the text editor (nano).

Then copy this code and insert it into nano with a right mouse click:

#!/usr/bin/env bash
#PATH=/usr/local/bin:/usr/local/sbin:/usr/bin:/usr/sbin
thirtyminsago=`date -d '30 minutes ago' "+%Y-%m-%d %H:%M:"`
firstrow=`cat /var/log/openhab2/openhab.log | grep "$thirtyminsago" -n | head -n1 | cut -d ':' -f1`
lastrow=`cat /var/log/openhab2/openhab.log | grep '' -n | tail -n1 | cut -d ':' -f1`
((difference=lastrow-firstrow))

boscherror=`tail -n$difference /var/log/openhab2/openhab.log | grep "at org.openhab.binding.boschindego.internal.handler.BoschIndegoHandler"`

if [[ $boscherror != "" ]]; then
       boschprocessid=sshpass -p 'habopen' ssh openhab@127.0.0.1 -p 8101 bundle:list | grep Indego | awk {'print $1'}
    sshpass -p 'habopen' ssh openhab@127.0.0.1 -p 8101 bundle:restart $boschprocessid
fi

Press Control-X (Exit) and then just say Y to save the file and Enter. Back in the command prompt type this: sudo chmod a+x /home/pi/check_boschindego.sh This will make the file executable.

Now we put it into Linux's "Task Manager", called cron. crontab -e Now you should have the same text editor open, but for Cron. You'll see that from the first line of the file normally:

Edit this file to introduce tasks to be run by cron.

Put this (copy) to the bottom: 0,30 * * * * sudo /home/pi/check_boschindego.sh Press Control-X, save and that's it, you should be all set.

Nevertheless I hope it'll work only with the changed refresh time and the developer will fix it.

henrydiesner commented 4 years ago

@Jagohu Thank you very much for the wonderful description! I did everything as described without any problems and I'll report how it works.

Jagohu commented 4 years ago

Good. :) To me it seems ok with the increased time parameter, but in case you need the script, I have updated it slightly so it keeps searching beyond 30 minutes if exactly 30 minutes before there was no log entry.

#!/usr/bin/env bash
#PATH=/usr/local/bin:/usr/local/sbin:/usr/bin:/usr/sbin
thirtyminsago=`date -d '30 minutes ago' "+%Y-%m-%d %H:%M:"`
ohlogfirstrow=`cat /var/log/openhab2/openhab.log | grep "$thirtyminsago" -n | head -n1 | cut -d ':' -f1`
if [[ ! $ohlogfirstrow =~ [0-9] ]]; then
    # if no numbers then start looking one minute earlier (not later to avoid missing things)
    minute=-31
    while [[ ! $ohlogfirstrow =~ [0-9] ]] ; do
        minutesago=$(date -d "$minute"' minutes' '+%Y-%m-%d %H:%M:')
        #echo "Check time: $minutesago"
        ohlogfirstrow=`cat /var/log/openhab2/openhab.log | grep "$minutesago" -n | head -n1 | cut -d ':' -f1`
        #echo $ohlogfirstrow
        ((minute--))
    done
fi 
lastrow=`cat /var/log/openhab2/openhab.log | grep '' -n | tail -n1 | cut -d ':' -f1`
((difference=lastrow-firstrow))

boscherror=`tail -n$difference /var/log/openhab2/openhab.log | grep "at org.openhab.binding.boschindego.internal.handler.BoschIndegoHandler"`

if [[ $boscherror != "" ]]; then
       boschprocessid=sshpass -p 'habopen' ssh openhab@127.0.0.1 -p 8101 bundle:list | grep Indego | awk {'print $1'}
    sshpass -p 'habopen' ssh openhab@127.0.0.1 -p 8101 bundle:restart $boschprocessid
fi
henrydiesner commented 4 years ago

@Jagohu OK, I've changed the bash file! Today it was raining, so I couldn't test the mower. I'll report after next mowing! Thank you very much.

henrydiesner commented 4 years ago

@Jagohu Today it works! With slowly respoce, but with responce. I'll watching the process in the next days. mower_openhab_app

henrydiesner commented 3 years ago

After starting the Bosch indego mower with the "Start mowing" command, the log-file warns with this issue: INFO: 2021-05-10 14:43:38.751 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'indegostate' received command 1 2021-05-10 14:43:38.759 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'indegostate' predicted to become 1 WARN: 2021-05-10 14:43:52.736 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: java.lang.NullPointerException: null at org.openhab.binding.boschindego.internal.handler.BoschIndegoHandler.getStatusFromCommand(BoschIndegoHandler.java:205) ~[?:?] at org.openhab.binding.boschindego.internal.handler.BoschIndegoHandler.poll(BoschIndegoHandler.java:139) ~[?:?] 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) [?:?]

The mower starts but give no response about his situation. @Jagohu Your mower works fine?

Jagohu commented 2 years ago

Sorry, I lost track... It still works fine it's just the same errors are back on OH3.2 and even the 600 seconds don't help.

https://github.com/zazaz-de/iot-device-bosch-indego-controller This refers to the need of a single connection to the account only - so ie. if you have your mobile phone with the app too, then it's an issue causing the errors.

jlaur commented 2 years ago

This issue might have been solved by #12905, but it would be nice with a confirmation of that. Would it be possible for one of you to upgrade to 3.3M7 and try the new version? If there are any issues, there is still a few days left for fixing them. If you are on 3.2, you can also install the JAR available here: https://drive.google.com/file/d/1bTr2sfFaZus-xrTaZ3g4qZrmju0Hhvy0/view?usp=sharing

jlaur commented 2 years ago

@henrydiesner - it seems that this bug is fixed by #12905. If you agree, please close it.

jlaur commented 2 years ago

Closing issue based on this comment.