Should throw an error when no BLE command is sent after a request is received ? #6
Comments
FraBoCH
changed the title
|
Thank you for the detailed description. |
|
I'm having the same issue. Can I enable some logging that could help in this case? body=map[] 2024/06/29 16:51:24 INFO received command |
|
Can you please set the environment variable |
|
@gauner1986, are you calling the ble proxy from a custom vehicle or a custom charger in evcc ? |
|
I have bumped the log level to debug and am hoping for a sunny day in the next time. I'm actually not using EVCC at all. I have my own automations in home assistant which do my solar excess charging. Excerpt of my configuration.yaml rest_command: |
|
Hi @wimaha does your http proxy try and wake the vehicle after a couple of errors? I have found that EVCC does not wake the vehicle reliably so after a couple of errors on charge start/stop or set charging amps I have my script send a wake command and then retry the previous command. Could that be the issue? |
|
Usually if that happens you receive a connection error though. In our error case here there's no feedback to the received commands at all. I had a case where it just happened in a series of events without any delays: 2024/06/28 16:24:04 INFO The command was successfully executed. command=charge_stop My automations were not yet perfect so the series of commands doesn't make sense in the end, but there should be feedback in the logs. Charging just continued in this case. |
|
Are you using on board ble or a dongle? I had a dongle that would crash
until I rebooted but that’s probably not your issue because that gave errors
…On Tue, 2 Jul 2024 at 08:27, gauner1986 ***@***.***> wrote:
Usually if that happens you receive a connection error though. In our
error case here there's no feedback to the received commands at all.
I had a case where it just happened in a series of events without any
delays:
2024/06/28 16:24:04 INFO The command was successfully executed.
command=charge_stop
2024/06/28 16:24:24 INFO received command command=charge_start VIN=VIN
body=map[]
2024/06/28 16:24:24 INFO received command command=set_charging_amps
VIN=VIN body=map[charging_amps:2]
2024/06/28 16:24:25 INFO handle command command=charge_start VIN=VIN
2024/06/28 16:24:28 INFO The command was successfully executed.
command=charge_start
2024/06/28 16:24:29 INFO handle command command=set_charging_amps VIN=VIN
2024/06/28 16:24:32 INFO The command was successfully executed.
command=set_charging_amps
2024/06/28 16:24:54 INFO received command command=set_charging_amps
VIN=VIN body=map[charging_amps:3]
2024/06/28 16:24:55 INFO handle command command=set_charging_amps VIN=VIN
2024/06/28 16:24:58 INFO The command was successfully executed.
command=set_charging_amps
2024/06/28 16:25:15 INFO received command command=charge_stop VIN=VIN
body=map[]
2024/06/28 16:25:15 INFO handle command command=charge_stop VIN=VIN
2024/06/28 16:25:24 INFO received command command=charge_stop VIN=VIN
body=map[]
2024/06/28 16:26:05 INFO received command command=charge_stop VIN=VIN
body=map[]
2024/06/28 16:26:24 INFO received command command=set_charging_amps
VIN=VIN body=map[charging_amps:3]
2024/06/28 16:26:35 INFO received command command=charge_stop VIN=VIN
body=map[]
2024/06/28 16:26:44 INFO received command command=charge_stop VIN=VIN
body=map[]
2024/06/28 16:27:04 INFO received command command=charge_stop VIN=VIN
body=map[]
2024/06/28 16:27:19 INFO received command command=charge_stop VIN=VIN
body=map[]
2024/06/28 16:30:40 INFO received command command=charge_stop VIN=VIN
body=map[]
2024/06/28 16:32:04 INFO received command command=set_charging_amps
VIN=VIN body=map[charging_amps:3]
2024/06/28 16:32:24 INFO received command command=set_charging_amps
VIN=VIN body=map[charging_amps:3]
—
Reply to this email directly, view it on GitHub
<#6 (comment)>,
or unsubscribe
<https://github.com/notifications/unsubscribe-auth/AKH2FP3GXU4BLG6PDHAJEQTZKHJUJAVCNFSM6AAAAABJMWDSZ6VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDEMBRGIYDANRWGY>
.
You are receiving this because you commented.Message ID:
***@***.***>
|
|
I'm using a raspberry pi 1 with a USB dongle. |
|
Check dmesg for an issues in there. I found that my UB400 worked fine but
my UB500 would crash on raspian. On Ubuntu on a pi zero 2 w the UB500
worked fine
…On Tue, 2 Jul 2024 at 09:00, gauner1986 ***@***.***> wrote:
I'm using a raspberry pi 1 with a USB dongle.
—
Reply to this email directly, view it on GitHub
<#6 (comment)>,
or unsubscribe
<https://github.com/notifications/unsubscribe-auth/AKH2FPZCD4TPB2CT4RQ6ISTZKHNRBAVCNFSM6AAAAABJMWDSZ6VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDEMBRGMZDKNBQHA>
.
You are receiving this because you commented.Message ID:
***@***.***>
|
|
Will do. Though last time I had the problem it was enough to simply restart the proxy. |
|
There are no unhandled errors in the program. So maybe the problem is in the ble package itself. It seems the handle loop is blocked without return or error. |
The proxy automatically wakes the vehicle when it is sleeping. So this is not the problem here. |
|
I have the same issue on a Raspberry pi Zero W. When charging, I hit the proxy every 15 seconds with a "set_charging_amps" command. After several hours, I see repeated "received command", but the commands are not sent to the car, nor is there any other error or informational message. |
|
Any Debug Logs? |
|
I've created a new version with the following improvements that might solve this problem:
The version is under the dev tag on Docker: Could you please test this version? Thank you! Edit: |
|
Couldn't test a lot in the past few days because of very bad weather in Hamburg. I'm building myself and running without docker due to system constraints. Did you commit in a special branch? |
|
Yes, you will find it in the branch |
I am now running your "refactor" version, with debug set. I'll share my experience and the logs, should the issue reoccur. |
This comment was marked as off-topic.
This comment was marked as off-topic.
|
It happened again today. This time with debug logs enabled. I'm on 89dba61. On restart everything went back to normal. This time it seemed to happen after the vehicle was temporarily not available.. |
|
Thank you for the logs. I can see the part which is blocking. Unfortunately the blocking part is ether in the tesla command repository or in the go ble package. But I think the teal problem here ist, that the connection can't be established after 18 attempts. Perhaps we should add something, that after 5 failed attempts no new commands are accepted and the proxy waits for a view minutes for the connection issue to be resolved. |
|
Hm. Not sure if this is the only trigger. There were other cases where the connection was fine beforehand. |
|
Got a new occurence. I didn't pay a lot of attention the last few days. There was one temporary connection issue again and then it got stalled for days without recovery: Is there a possibility to monitor a command and kill it if no success event is received in a certain time frame? |
|
I cam back from a week-end and no command are working, even after restarting evcc and TeslaBleHttpProxy and even waking up / starting the car from the phone app. My setup is interesting because I am migrating and I have two instances of TeslaBleHttpProxy v1.2 running, one on a Raspberry Pi4 (docker image) and one on an Intel NUC (self go compile). To switch, I change the evcc config and restart. But I have the same problem on both machines... Actually I have another Pi4 and same problem. Also generating new key and trying to register it did work. So I wonder is the problem is on TeslaBleHttpProxy, or could it be on the car side that sometimes just don't want to communicate at all? I tried to remove all the "Unknow key" to kind of clean, but now I have difficulty to recreate a key. It is so sad to have seen it working for hours or days and now it fail. I'll sleep on that and try again whenever possible with https://github.com/teslamotors/vehicle-command/ to check the basics. |
|
I tested with |
|
Some positive progress in my setup. Maybe it is not related to the distance, maybe it is just that both machine have been off during the move and the new installation... Still, it works for me (at least tonight). Either both stop working in a few hours or day... or maybe those few meter made the difference. If you have trouble, please give that a try. I also suspect that Tesla may have included power saving change in recent software upgrade, and that could include BLE power/sensitivity or make the car harder to wake up for us. |
|
Another occurence. After a timeout again:
|
|
There are now even more logs with version 1.2.2. Please use this version and report any error logs with this problem. Thank You!! |
|
The Bug ist finally resolved with Version 1.2.4 :-) |
I’m using your proxy with evcc, within in a custom charger and it’s working quite good. Today I observed some strange behavior with current not being adjusted and charge not stopping. When looking at the log, I saw the requests received, but nothing happening and no error:
2024/06/16 14:56:53 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:5]
2024/06/16 14:58:23 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:4]
2024/06/16 14:58:53 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:3]
2024/06/16 14:59:23 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:2]
2024/06/16 15:01:24 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:3]
2024/06/16 15:01:24 received command "charge_start" (VIN: MYMODELY) with body: map[]
2024/06/16 15:01:53 received command "wake_up" (VIN: MYMODELY) with body: map[]
2024/06/16 15:02:23 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:5]
2024/06/16 15:03:53 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:3]
2024/06/16 15:04:23 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:1]
2024/06/16 15:06:53 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:2]
2024/06/16 15:07:23 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:3]
2024/06/16 15:07:53 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:4]
2024/06/16 15:08:23 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:2]
2024/06/16 15:08:53 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:1]
2024/06/16 15:11:03 received command "charge_stop" (VIN: MYMODELY) with body: map[]
2024/06/16 15:14:53 received command "charge_stop" (VIN: MYMODELY) with body: map[]
2024/06/16 15:18:23 received command "charge_stop" (VIN: MYMODELY) with body: map[]
After restarting the container, everything started to work as expected again:
2024/06/16 16:11:50 TeslaBleHttpProxy is loading ...
2024/06/16 16:11:50 TeslaBleHttpProxy is running!
2024/06/16 16:12:27 received command "charge_stop" (VIN: MYMODELY) with body: map[]
2024/06/16 16:12:27 handle command: charge_stop (VIN: MYMODELY)
2024/06/16 16:12:27 Connecting to vehicle...
2024/06/16 16:12:29 sending command "charge_stop"...
2024/06/16 16:12:30 The command "charge_stop" was successfully executed.
Going back in the log I observed there has been some errors before and then at some point it seems the just give up trying to send BLE command until the restart.
2024/06/16 11:34:37 retrying in 6 seconds
2024/06/16 11:34:43 Connecting to vehicle...
2024/06/16 11:34:53 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:7]
2024/06/16 11:34:53 stop retrying after 3 attempts
2024/06/16 11:34:53 The command "set_charging_amps" was canceled:
2024/06/16 11:34:53 [Error]failed to connect to vehicle (A): failed to find BLE beacon for MYMODELY (S67a76e989a933054C): can't scan: context deadline exceeded
2024/06/16 11:34:54 handle command: set_charging_amps (VIN: MYMODELY)
2024/06/16 11:34:54 Connecting to vehicle...
2024/06/16 11:35:23 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:8]
2024/06/16 11:35:53 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:7]
2024/06/16 11:42:53 received command "set_charging_amps" (VIN: MYMODELY) with body: map[charging_amps:6]
Do you understand this behavior ? Instead of stopping to send BLE command, shouldn’t error be thrown for every command (and reported to evcc) ? Would it be possible to detect this special state and automatically restart the container ?
Let me know if you know if you need more information or test, I’ll be happy to help!
The text was updated successfully, but these errors were encountered: