JuiceRescue / juicepassproxy

Proxy UDP requests to/from Juicebox EV chargers to MQTT discoverable by Home Assistant
80 stars 11 forks source link

Error messages when using juicebox_commands branch #90

Open niharmehta opened 2 weeks ago

niharmehta commented 2 weeks ago

The good news is that setting the new image for the juicebox_commands branch seemed to work. Also, most of the read values I had before seem to be working. With the EXPERIMENTAL set to true, I see the number control in HA.
However, I am seeing a couple of errors in the logs that I am not sure about: First, the NOT a valid JB message. Second seems to be a log entry about not having the current_max_charging set. I did a quick search and did not find any other reports of this.


024-10-03 00:15:57  INFO      [ha_mqtt_discoverable.sensors] Setting Data from JuiceBox to 0817010902040449282317246897:v07,s0001,u29148,V2400,L0024880089,S2,T62,M40,m40,t09,i77,e-001,f6001,X0,Y0,E006779,A0394,p0992!2QS: using hmd/sensor/JuiceBox/Data-from-JuiceBox/state

2024-10-03 00:15:57  WARNING   [juicebox_mitm] Unable to send command to juicebox before current_max and current_max_charging values are set

2024-10-03 00:16:06  INFO      [juicebox_message] from_string 0817010902040449282317246897:v07,s0001,u30048,V2400,L0024880114,S2,T62,M40,m40,t09,i78,e-001,f6001,X0,Y0,E006804,A0394,p0992!P1Z:

2024-10-03 00:16:06  ERROR     [juicebox_mitm] Not a valid juicebox message b'0817010902040449282317246897:v07,s0001,u30048,V2400,L0024880114,S2,T62,M40,m40,t09,i78,e-001,f6001,X0,Y0,E006804,A0394,p0992!P1Z:'

Traceback (most recent call last):

  File "/juicepassproxy/juicebox_mitm.py", line 158, in _main_mitm_handler

    self._last_message = juicebox_message_from_bytes(data)

                         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

  File "/juicepassproxy/juicebox_message.py", line 90, in juicebox_message_from_bytes

    return juicebox_message_from_string(string)

           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

  File "/juicepassproxy/juicebox_message.py", line 135, in juicebox_message_from_string

    return JuiceboxMessage(False).from_string(string)

           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

  File "/juicepassproxy/juicebox_message.py", line 187, in from_string

    raise JuiceboxInvalidMessageFormat(f"Found checksum in message that are supposed to dont have checksum '{string}'")

juicebox_exceptions.JuiceboxInvalidMessageFormat: Found checksum in message that are supposed to dont have checksum '0817010902040449282317246897:v07,s0001,u30048,V2400,L0024880114,S2,T62,M40,m40,t09,i78,e-001,f6001,X0,Y0,E006804,A0394,p0992!P1Z:'

2024-10-03 00:16:06  INFO      [ha_mqtt_discoverable.sensors] Setting Current to 39.4 using hmd/sensor/JuiceBox/Current/state

2024-10-03 00:16:06  INFO      [ha_mqtt_discoverable.sensors] Setting Energy (Session) to 6804.0 using hmd/sensor/JuiceBox/Energy--Session-/state

2024-10-03 00:16:06  INFO      [ha_mqtt_discoverable.sensors] Setting Voltage to 240.0 using hmd/sensor/JuiceBox/Voltage/state

2024-10-03 00:16:06  INFO      [ha_mqtt_discoverable.sensors] Setting Energy (Lifetime) to 24880114.0 using hmd/sensor/JuiceBox/Energy--Lifetime-/state

2024-10-03 00:16:06  INFO      [ha_mqtt_discoverable.sensors] Setting Status to Charging using hmd/sensor/JuiceBox/Status/state

2024-10-03 00:16:06  INFO      [ha_mqtt_discoverable.sensors] Setting Temperature to 143.6 using hmd/sensor/JuiceBox/Temperature/state

2024-10-03 00:16:06  INFO      [ha_mqtt_discoverable.sensors] Setting Max Charging Current to 40.0 using hmd/number/JuiceBox/Max-Charging-Current/state

2024-10-03 00:16:06  INFO      [ha_mqtt_discoverable.sensors] Setting Current Rating to 40.0 using hmd/sensor/JuiceBox/Current-Rating/state

2024-10-03 00:16:06  INFO      [ha_mqtt_discoverable.sensors] Setting Frequency to 60.01 using hmd/sensor/JuiceBox/Frequency/state

2024-10-03 00:16:06  INFO      [ha_mqtt_discoverable.sensors] Setting Power to 9456.0 using hmd/sensor/JuiceBox/Power/state

2024-10-03 00:16:06  INFO      [ha_mqtt_discoverable.sensors] Setting Data from JuiceBox to 0817010902040449282317246897:v07,s0001,u30048,V2400,L0024880114,S2,T62,M40,m40,t09,i78,e-001,f6001,X0,Y0,E006804,A0394,p0992!P1Z: using hmd/sensor/JuiceBox/Data-from-JuiceBox/state

2024-10-03 00:16:06  WARNING   [juicebox_mitm] Unable to send command to juicebox before current_max and current_max_charging values are set
ivanfmartinez commented 2 weeks ago

This message format was not considered in the new routines. I have added it to my branch https://github.com/snicker/juicepassproxy/pull/69

will work with new version

About the current_max_charging message, it will only stops after the message is parsed correctly, it occurs because HA tries to set default values to parameters, but the code can only do this after knowing the message format to be used with the device.

awp0 commented 2 weeks ago

I had the same two problems described by @niharmehta, when using the juicebox_commands branch (using docker label). Just now I manually added the two files (using docker volumes) from today's most recent commit, and that seemed to resolve the problem with "not valid juicebox message". But I still can't seem to get past the problem with initial values of current_max_charging and current_max.

@ivanfmartinez I think I understand your description of the problem, but would you have any tips for resolving it? It seems to be blocking the message to the juicebox (unless I'm misinterpreting):

2024-10-03 16:30:22 WARNING [juicebox_mitm] Unable to send command to juicebox before current_max and current_max_charging values are set

PS: thanks for all of your work on this! Pretty exciting, given yesterday's announcement.

niharmehta commented 2 weeks ago

Thanks @ivanfmartinez for the quick fix! Hopefully the container for the branch will be updated soon.

ivanfmartinez commented 2 weeks ago

@awp0 that warning came from this part of code : https://github.com/snicker/juicepassproxy/pull/69/files#diff-8c66151797142880ff510b609d598b88cff39528d0845a1967dea7413cac9bdeR286

Only after having both parameters defined it will be able to send the responses to the device.

This parameters will be set from the message that came from juicebox device or from being set from homeassistant.

Normaly after the first message came from device they are defined. But this was tested with my device that send v09u messages.

Looking in detail the message that was indicated here, it misses the "C" parameter.

I have commited some more changes as workaround for this case. But considering that it is sending a different message maybe the responde should be different also.

Will be very nice if we have a packet capture from this version talking with enel x servers to know the correct response.

awp0 commented 2 weeks ago

Thank you for the very fast turnaround @ivanfmartinez ! I consumed these new changes and started fresh in HA. The good news is that this indeed eliminates the error related to initial values. But it seems the Juicebox isn't accepting the command because when I attempt to change max charging current from HA, the response from Juicebox seems to indicate that it's still default. Here's what I see in the logs when I attempt to change Max Charging Current from default 40A down to 21A:

2024-10-03 18:52:04  INFO      [juicebox_mqtthandler] Number Callback (Max Charging Current): 21. User Data: None
2024-10-03 18:52:04  INFO      [ha_mqtt_discoverable.sensors] Setting Max Charging Current to 21.0 using hmd/number/JuiceBox/Max-Charging-Current/state
2024-10-03 18:52:04  INFO      [juicebox_mitm] command message = CMD41852A21M40C006S072!6R2$ new_values=True new_version=False
2024-10-03 18:52:04  INFO      [juicebox_mitm] Sending command to juicebox CMD41852A21M40C006S072!6R2$ new_values=True
2024-10-03 18:52:04  INFO      [juicebox_udpcupdater] JuiceboxUDPCUpdater Check Starting
2024-10-03 18:52:04  INFO      [ha_mqtt_discoverable.sensors] Setting Max Charging Current to 21.0 using hmd/number/JuiceBox/Max-Charging-Current/state
2024-10-03 18:52:04  DEBUG     [juicebox_udpcupdater] Active UDPC Stream: 2
2024-10-03 18:52:04  INFO      [juicebox_udpcupdater] UDPC IP correct
2024-10-03 18:52:04  INFO      [juicebox_message] from_string 0817081002000438538219245203:v07,s0787,u28804,V2413,L0007450385,S0,T20,M40,m40,t09,i15,e0000,f6001,X0,Y0!649:
2024-10-03 18:52:04  DEBUG     [juicebox_mqtthandler] From JuiceBox: b'0817081002000438538219245203:v07,s0787,u28804,V2413,L0007450385,S0,T20,M40,m40,t09,i15,e0000,f6001,X0,Y0!649:'
2024-10-03 18:52:04  DEBUG     [juicebox_mqtthandler] Publish Basic Message: {'type': 'basic', 'current': 0, 'energy_session': 0, 'protocol_version': '07', 'unknown_s': '0787', 'loop_counter': '28804', 'voltage': 241.3, 'energy_lifetime': 7450385.0, 'status': 'Unplugged', 'temperature': 68.0, 'current_max_charging': 40.0, 'current_rating': 40.0, 'report_time': '09', 'interval': '15', 'unknown_e': '0000', 'frequency': 60.01, 'unknown_X': '0', 'unknown_Y': '0', 'power': 0.0, 'current_max': 40.0, 'data_from_juicebox': '0817081002000438538219245203:v07,s0787,u28804,V2413,L0007450385,S0,T20,M40,m40,t09,i15,e0000,f6001,X0,Y0!649:'}

PS: I can attempt packet capture, but I'm not very experience with this. I'll investigate, but others can probably do it faster.

niharmehta commented 2 weeks ago

@ivanfmartinez . Attached is a PCAP from the JB talking directly to the ENELX servers . (No JPP in the middle) . The car is out for a few hours , so I could not control charging or do too many changes to give more data. jb1.pcap.zip

ivanfmartinez commented 2 weeks ago

@niharmehta the capture that you sent shows you device on 192.168.237.4 sending UDP to the server on ports 8042 and 8047 , but I did not see responses from server.

could you please try again and send a capture with responses from the enel x server ?

@awp0 if you can capture also will give more sample data to check.

At least in my device that uses v09u the responses are the one show on @awp0 log

CMD41852A21M40C006S072!6R2$
niharmehta commented 2 weeks ago

Sorry about that. I did not noticed that the JB disconnected from the cloud while capturing. It was up when I started. Here is anotehr capture. After 2 minutes, just 10 packets back from the 158.X address all on 8042 .. No car is connected so all I attempted to do is set the current limit and back. I can post more captures later today. jb2.pcap.zip

ivanfmartinez commented 2 weeks ago

Sorry about that. I did not noticed that the JB disconnected from the cloud while capturing. It was up when I started. Here is anotehr capture. After 2 minutes, just 10 packets back from the 158.X address all on 8042 .. No car is connected so all I attempted to do is set the current limit and back. I can post more captures later today. jb2.pcap.zip

@niharmehta have you tried to set the limit to 29A ? and changed back to 40A ? This is what I see, the messages appear to be the same that are already supported by current code.

I recommend that you try with juicepassproxy changing values, sometimes it can miss a setting if you send the command few instants before the juicebox send a new message. In this case you setting can be lost.

Try changing both currrent parameters at diferent times, and sometimes for different values and save the juicepassproxy log to be checked in case of errors.

As your device does not send the offline max current I dont know if it will really accept both parameters.

awp0 commented 2 weeks ago

Not sure if this is helpful, but here's the output of the following tcpdump command executed from my router, when I switch Maximum Capacity in the Enel app to 19A.

pi@Firewalla:~/tcpdump-tmp (Firewalla2) $ sudo tcpdump -i br0 "dst 192.168.1.126" -A -v
tcpdump: listening on br0, link-type EN10MB (Ethernet), snapshot length 262144 bytes
17:08:47.240081 IP (tos 0x0, ttl 105, id 48839, offset 0, flags [DF], proto UDP (17), length 55)
    158.47.1.128.8047 > 192.168.1.126.32386: UDP, length 27
E..7..@.i..../.....~.o~..#..CMD41708A16M16C242S963!913$
17:08:57.867351 IP (tos 0x0, ttl 105, id 50860, offset 0, flags [DF], proto UDP (17), length 55)
    158.47.1.128.8047 > 192.168.1.126.32386: UDP, length 27
E..7..@.i..3./.....~.o~..#..CMD41708A19M18C008S964!D22$
awp0 commented 2 weeks ago

One difference between the proxy command and the Enel command is the timezone. To me it looks like the proxy sends the time (in the CMD block) in UTC regardless of container's timezone, but Enel is sending the time in my local time format. Is it possible that the Juicebox could reject a command that looks very different from its own clock? These two commands were issued less than 10 minutes of each other:

Proxy: CMD42156A24M40C006S001!QPX$ <-- time sent is 2156 Enel: CMD41748A24M23C006S062!H50$ <-- time sent is 1748

ivanfmartinez commented 2 weeks ago

@awp0 maybe the device dont like the changes. The protocol have time and also a sequence number.

As a suggestion try to turn off juicebox before each test (enel x server and juicepass server)

awp0 commented 2 weeks ago

Thanks @ivanfmartinez, no luck so far rebooting the machine. I've probably spent too much time today on this. Maybe tomorrow I'll see if I can figure out how to send a command to the device with correct time and high sequence number, just to see if one of those might be the cause of my problems. Thanks again for all of your work on this!

niharmehta commented 2 weeks ago

@ivanfmartinez . To answer your question from earlier packet capture, I did set the Current to 29 from 40 and back again.

I overrode the current juicebox-commands container with your two updated files . The error messages are no longer seen. As I think you were expecting with my current v7 protocol version, the Max Charging Current seems to be working using the slider in HA. The Max Current does NOT stay fixed at a reduced setting.
For whatever reason, the connection to ENELX directly from the JB or through the JPP does not seem to be working well. I am seeing the 8047 port packets exiting the firewall, but nothing coming back in. I am not sure if there is some sort of hold-down in ENELX if there is too many changes in connectivity by the JB that it hold down responding for a period of time.
Since I was not getting bi-directional communication, I did not do a packet capture yet that include the ENELX cloud. If it re-establishes, I will get some more captures.

ivanfmartinez commented 1 week ago

@niharmehta as this device does not send the Max Current on the message and my last change uses Current Rating , even if the device accept the change you will not see this change on the entity.

The juicepassproxy log showing where you send the new value and see what data the juicebox send back for some time maybe can help us to understand if this version are using different field to report the value.

About the ENELX servers, that behaviour of not responding was what made me search for altenartives long time ago. Many people have this instabilitys with ENELX servers, mine became offline for many days and then started working again. After I put juicepassproxy to work I just ignored ENELX and had no problems with that.

niharmehta commented 1 week ago

@ivanfmartinez , here are some logs from the docker log console . I made two attempts to set the slider in HA for Max Current.. First to 30, and then to around 21A. I see a message, then resets itself back to 40. Hope this is what you are looking for. jb_logs1.txt.zip

ivanfmartinez commented 1 week ago

@niharmehta the logs shows the new value are sent to the device. But it still does not send back new values.

Possibilities :

This parameter is the "offline max current" which take effect after around 5 minutes that the device does not get responses from server.

Maybe this older protocol devices uses a single parameter and dont have different current for offline, or use the rating current when offline. Only testing on the device to know.

Also is important to know if the Max Charging current persists when device turned off, if it persists indicates that the value is saved on EEPROM which will give a recomendation to dont change that too much like the "Max Current" on newer devices.

awp0 commented 1 week ago

I see the same behavior as @niharmehta, for both max current and max charging current. I've fixed my timezone problem with the container, but it made no difference. Maybe it's a command sequence problem, but I've tried restarting everything with no success and I've run out of ideas. I can see the correct commands being sent to the JB (in the logs), but then the original value is read back into HA a few seconds later. I've tried it while charging the car, and I can see no change in charging rate. I'm stumped.

Does anyone know if there's a simpler tool that would allow me to test custom commands directly to the JB (without HA or MQTT)? It would be interesting to experiment with higher sequence numbers or command strings. For example, when I was capturing packets from Enel, it was hard to understand the difference between C006 and C008.

Edit to say that my JB is one of the older black metal boxes.

niharmehta commented 1 week ago

@ivanfmartinez . Is there a specific test sequence you recommend to get the needed information back to you?

I am checking to see if I can get by JB back connected directly to ENELX . Capture whatever packets you need, and then do the same with JPP to see if what the differences are. Best case, I can test using the app while JPP is in the middle, but I have not been able to get both working at the same time the last few days. Any other test recommendations ?

ivanfmartinez commented 1 week ago

@ivanfmartinez . Is there a specific test sequence you recommend to get the needed information back to you?

I am checking to see if I can get by JB back connected directly to ENELX . Capture whatever packets you need, and then do the same with JPP to see if what the differences are. Best case, I can test using the app while JPP is in the middle, but I have not been able to get both working at the same time the last few days. Any other test recommendations ?

The idea is to check if the changes are working.

You should change parameters and check if the device responds. When we send the current change to juicebox it should give this information to the car, and then the car will reduce the current used.

You can see the results on the car and also in the current used during charging. Normally this tests must be made before the car is near fully charged, because when near full charged maybe the car will use less than the juicebox devices maximum indicates.

ivanfmartinez commented 1 week ago

Does anyone know if there's a simpler tool that would allow me to test custom commands directly to the JB (without HA or MQTT)? It would be interesting to experiment with higher sequence numbers or command strings. For example, when I was capturing packets from Enel, it was hard to understand the difference between C006 and C008.

@awp0 the juicebox apparently does not have any way to receive commands, It open the UDP connection to the server and wait for commands in that connection.

I think the easiest will be using HA and MQTT, there is a entity called "send_to_juicebox" on JPP, is disabled by default but should permit you to easily send data to juicebox, if you enable "data_from_juicebox" and "send_to_juicebox" in your homeassistant you should be able to make many tests.

niharmehta commented 1 week ago

@ivanfmartinez
Here are some packet captures all without any vehicle charging yet.

enelx_app_jb_max_current_p8042_1 is direct communication between the JB and the ENELX servers. I used the app (Settings -> Configuration -> A -> Maximum Capacity) to set the JB to a lower power capacity.

Next enelx_app_jb_max_current_p8042_jpp_ap_wired_1 is captured between the JPP and the JB . Again, I used the app to make the same changes as before.

enelx_app_jb_max_current_p8042_mx_lan_1 is another capture between my firewall/router and the JPP. Again this is using the app to make the same setting changes.

In both of the captures with the JPP being a proxy, the logs indicate Max Charging Current changing, not Max Current.

enelx_app_jb_max_current_p8042_mx_lan_1.pcap.zip

enelx_app_jb_max_current_p8042_jpp_ap_wired_1.pcap.zip

enelx_app_jb_max_current_p8042_1.pcap.zip

niharmehta commented 1 week ago

Last one for now. I directed JB to connect directly to ENELX and then set the Current to 20A and let it stabilize. I then started JPP and redirected the JB to JPP in DNS and issued a reboot on the telnet CLI to restart the Zentri stack. I made no other changes within the app. When JPP first came up, the logs initially show 40A, but next it showed 20A which was the same still reflected in the app. Logs attached. jb_app_then_jpp_logs1.txt.zip

ivanfmartinez commented 1 week ago

@niharmehta thanks for the logs, I never seen that debug messages on my logs.

I will make the changes to support this messages also. and when have more time will look in detail the captures also.

Your tests show that the value set from the ENELX server is preserved after reboot. Have you tested the same thing turning off the energy on juicebox ?

niharmehta commented 1 week ago

After powering down and up the JB, the setting is NOT preserved. Logs attached. jb_cycle_1.txt

ivanfmartinez commented 1 week ago

After powering down and up the JB, the setting is NOT preserved. Logs attached. jb_cycle_1.txt

This confirms that the device does not have an offline current or we dont know how to communicate correctly with this device :-)

But at least with the online current control the device will work fine for most cases and will return to maximum after power lost.

niharmehta commented 1 week ago

Once the JB connects back to ENELX, it drops to 20A (setting in app, so state is kept there). Actually quite concerning if I had a JB larger than the sized circuit when ENELX goes down. Depending on what the. captures indicate, it seems like ENELX does not have the capability either. Let me know if any other packet captures would be helpful.

Anyways not a major issue, if I ever have a situation where this function matters, I will be getting a new EVSE.

ivanfmartinez commented 1 week ago

Once the JB connects back to ENELX, it drops to 20A (setting in app, so state is kept there). Actually quite concerning if I had a JB larger than the sized circuit when ENELX goes down. Depending on what the. captures indicate, it seems like ENELX does not have the capability either. Let me know if any other packet captures would be helpful.

Anyways not a major issue, if I ever have a situation where this function matters, I will be getting a new EVSE.

@niharmehta I agree that server can keep state information, but the best way to do this will be a refator on JPP to :

I'm not a experient python programmer neither used to the libraries that do the mqtt entities, this should be done after merging the commands branch by persons that know better how to do this in python

my suggestion now for the users that have this limit case is to create an automation in HA that update the max charging current value after juicebox connect to JPP

ivanfmartinez commented 1 week ago

@niharmehta and @awp0 can you test with latest version ?

@FalconFour indicated that the v07 works with offline current, just not report that. I think that my last commit is very safe, you just have to manually configure the offline current or wait at least 6 minutes to JPP get the offline current from the device.

niharmehta commented 1 week ago

@ivanfmartinez , I tested the latest build this evening. Cleared HA, MQTT entries, and shut the JB down. Restarted the latest build . It took about 6 minutes and the Max Current Offline/ Wanted showed up!