search

JuiceRescue / juicepassproxy

Proxy UDP requests to/from Juicebox EV chargers to MQTT discoverable by Home Assistant
Apache License 2.0
86 stars 12 forks source link

Child Process error with latest juicebox_commands branch #98

Closed niharmehta closed 1 month ago

niharmehta commented 1 month ago

A little while ago, after about 24 hours, the EnelX app suddenly woke up for a few minutes and showed connected. It only lasted a few minutes, and when checking the logs on JPP, I saw the errors below. I am not sure if its because something happened on the ENELX side, or JPP could not handle the connection drop. During this time, I was redirecting the directory, jb1, and prod servers using DNS. 


2024-10-05 12:11:59  INFO      [ha_mqtt_discoverable.sensors] Setting Current to 0 using hmd/sensor/JuiceBox/Current/state

2024-10-05 12:11:59  INFO      [ha_mqtt_discoverable.sensors] Setting Energy (Session) to 0 using hmd/sensor/JuiceBox/Energy--Session-/state

2024-10-05 12:11:59  INFO      [ha_mqtt_discoverable.sensors] Setting Voltage to 247.0 using hmd/sensor/JuiceBox/Voltage/state

2024-10-05 12:11:59  INFO      [ha_mqtt_discoverable.sensors] Setting Energy (Lifetime) to 24938768.0 using hmd/sensor/JuiceBox/Energy--Lifetime-/state

2024-10-05 12:11:59  INFO      [ha_mqtt_discoverable.sensors] Setting Status to Unplugged using hmd/sensor/JuiceBox/Status/state

2024-10-05 12:11:59  INFO      [ha_mqtt_discoverable.sensors] Setting Temperature to 111.2 using hmd/sensor/JuiceBox/Temperature/state

2024-10-05 12:11:59  INFO      [ha_mqtt_discoverable.sensors] Setting Max Charging Current to 21.0 using hmd/number/JuiceBox/Max-Charging-Current/state

2024-10-05 12:11:59  INFO      [ha_mqtt_discoverable.sensors] Setting Current Rating to 40.0 using hmd/sensor/JuiceBox/Current-Rating/state

2024-10-05 12:11:59  INFO      [ha_mqtt_discoverable.sensors] Setting Frequency to 59.98 using hmd/sensor/JuiceBox/Frequency/state

2024-10-05 12:11:59  INFO      [ha_mqtt_discoverable.sensors] Setting Power to 0.0 using hmd/sensor/JuiceBox/Power/state

2024-10-05 12:11:59  INFO      [ha_mqtt_discoverable.sensors] Setting Max Current to 40.0 using hmd/number/JuiceBox/Max-Current/state

2024-10-05 12:11:59  INFO      [ha_mqtt_discoverable.sensors] Setting Data from JuiceBox to 0817010902040449282317246897:v07,s0004,u27408,V2470,L0024938768,S0,T44,M21,m40,t09,i47,e0000,f5998,X0,Y0!WLY: using hmd/sensor/JuiceBox/Data-from-JuiceBox/state

2024-10-05 12:13:59  WARNING   [juicebox_mitm] No Message Received after 120 sec. (TimeoutError: )

2024-10-05 12:13:59  WARNING   [juicebox_mitm] JuiceboxMITM Reconnecting.

2024-10-05 12:16:04  WARNING   [juicebox_mitm] No Message Received after 120 sec. (TimeoutError: )

2024-10-05 12:16:04  WARNING   [juicebox_mitm] JuiceboxMITM Reconnecting.

2024-10-05 12:16:04  ERROR     [__main__] A JuicePass Proxy task failed: ChildProcessError: JuiceboxMITM: Unable to start MITM UDP Server.

Traceback (most recent call last):

  File "/juicepassproxy/juicepassproxy.py", line 565, in main

    await asyncio.gather(

  File "/juicepassproxy/juicebox_mitm.py", line 59, in start

    await self._connect()

  File "/juicepassproxy/juicebox_mitm.py", line 102, in _connect

    self._mitm_loop_task = await self._mitm_loop()

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

  File "/juicepassproxy/juicebox_mitm.py", line 112, in _mitm_loop

    await self._connect()

  File "/juicepassproxy/juicebox_mitm.py", line 102, in _connect

    self._mitm_loop_task = await self._mitm_loop()

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

  File "/juicepassproxy/juicebox_mitm.py", line 112, in _mitm_loop

    await self._connect()

  File "/juicepassproxy/juicebox_mitm.py", line 102, in _connect

    self._mitm_loop_task = await self._mitm_loop()

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

  File "/juicepassproxy/juicebox_mitm.py", line 112, in _mitm_loop

    await self._connect()

  File "/juicepassproxy/juicebox_mitm.py", line 102, in _connect

    self._mitm_loop_task = await self._mitm_loop()

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

  File "/juicepassproxy/juicebox_mitm.py", line 112, in _mitm_loop

    await self._connect()

  File "/juicepassproxy/juicebox_mitm.py", line 102, in _connect

    self._mitm_loop_task = await self._mitm_loop()

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

  File "/juicepassproxy/juicebox_mitm.py", line 112, in _mitm_loop

    await self._connect()

  File "/juicepassproxy/juicebox_mitm.py", line 102, in _connect

    self._mitm_loop_task = await self._mitm_loop()

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

  File "/juicepassproxy/juicebox_mitm.py", line 112, in _mitm_loop

    await self._connect()

  File "/juicepassproxy/juicebox_mitm.py", line 102, in _connect

    self._mitm_loop_task = await self._mitm_loop()

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

  File "/juicepassproxy/juicebox_mitm.py", line 112, in _mitm_loop

    await self._connect()

  File "/juicepassproxy/juicebox_mitm.py", line 102, in _connect

    self._mitm_loop_task = await self._mitm_loop()

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

  File "/juicepassproxy/juicebox_mitm.py", line 112, in _mitm_loop

    await self._connect()

  File "/juicepassproxy/juicebox_mitm.py", line 102, in _connect

    self._mitm_loop_task = await self._mitm_loop()

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

  File "/juicepassproxy/juicebox_mitm.py", line 112, in _mitm_loop

    await self._connect()

  File "/juicepassproxy/juicebox_mitm.py", line 100, in _connect

    raise ChildProcessError("JuiceboxMITM: Unable to start MITM UDP Server.")

ChildProcessError: JuiceboxMITM: Unable to start MITM UDP Server.

2024-10-05 12:16:14  ERROR     [__main__] JuicePass Proxy Exiting

2024-10-05 12:16:14  ERROR     [aiorun] Unhandled exception; stopping loop: 'Task exception was never retrieved'

Traceback (most recent call last):

  File "/juicepassproxy/juicepassproxy.py", line 590, in <module>

    run(main(), stop_on_unhandled_errors=True)

  File "/usr/local/lib/python3.12/site-packages/aiorun.py", line 253, in run

    loop.run_forever()

  File "/usr/local/lib/python3.12/asyncio/base_events.py", line 641, in run_forever

    self._run_once()

  File "/usr/local/lib/python3.12/asyncio/base_events.py", line 1987, in _run_once

    handle._run()

  File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run

    self._context.run(self._callback, *self._args)

  File "/usr/local/lib/python3.12/site-packages/aiorun.py", line 219, in new_coro

    await coro

  File "/juicepassproxy/juicepassproxy.py", line 586, in main

    sys.exit(1)

SystemExit: 1

--------------------------------

2024-10-05 12:16:15  INFO      [entrypoint.sh] Starting JuicePass Proxy

2024-10-05 12:16:15  INFO      [entrypoint.sh] Docker Environment Variables:

2024-10-05 12:16:15  INFO      [entrypoint.sh] JUICEBOX_HOST: 192.168.237.4

2024-10-05 12:16:15  INFO      [entrypoint.sh] ENELX_IP: 158.47.1.128

2024-10-05 12:16:15  INFO      [entrypoint.sh] MQTT_HOST: 192.168.37.25

2024-10-05 12:16:15  INFO      [entrypoint.sh] MQTT_USER: mqtt

2024-10-05 12:16:15  INFO      [entrypoint.sh] MQTT_PASS: ********

2024-10-05 12:16:15  INFO      [entrypoint.sh] JPP_HOST: 192.168.37.15

2024-10-05 12:16:15  INFO      [entrypoint.sh] DEBUG: false

2024-10-05 12:16:15  INFO      [entrypoint.sh] UPDATE_UDPC: false

2024-10-05 12:16:15  INFO      [entrypoint.sh] IGNORE_ENELX: false

2024-10-05 12:16:15  INFO      [entrypoint.sh] EXPERIMENTAL: true

2024-10-05 12:16:16  WARNING   [__main__] Starting JuicePass Proxy v0.3.1 (Log Level: INFO)

2024-10-05 12:16:16  INFO      [__main__] log_loc: /log/juicepassproxy.log

2024-10-05 12:16:16  INFO      [__main__] config_loc: /config/juicepassproxy.yaml

2024-10-05 12:16:16  INFO      [__main__] telnet timeout: 30

2024-10-05 12:16:16  INFO      [__main__] ignore_enelx: False

2024-10-05 12:16:16  INFO      [telnetlib3.client] Connected to <Peer 192.168.237.4 2000>

2024-10-05 12:16:18  INFO      [__main__] enelx_server: jbv1.emotorwerks.com

2024-10-05 12:16:18  INFO      [__main__] enelx_port: 8042

2024-10-05 12:16:18  INFO      [telnetlib3.client] Connection closed to <Peer 192.168.237.4 2000>

2024-10-05 12:16:18  INFO      [__main__] local_addr: 172.17.0.3:8042

2024-10-05 12:16:18  INFO      [__main__] enelx_addr: 158.47.1.128:8042

2024-10-05 12:16:18  INFO      [telnetlib3.client] Connected to <Peer 192.168.237.4 2000>

2024-10-05 12:16:20  INFO      [__main__] juicebox_id: 0817010902040449282317246897

2024-10-05 12:16:20  INFO      [__main__] experimental: True

2024-10-05 12:16:20  INFO      [__main__] max_current: 48

2024-10-05 12:16:20  INFO      [telnetlib3.client] Connection closed to <Peer 192.168.237.4 2000>

2024-10-05 12:16:20  INFO      [juicebox_mqtthandler] Starting JuiceboxMQTTHandler

2024-10-05 12:16:20  INFO      [juicebox_mitm] Starting JuiceboxMITM

2024-10-05 12:16:20  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/sensor/JuiceBox/Status/config

2024-10-05 12:16:20  INFO      [ha_mqtt_discoverable] state_topic: hmd/sensor/JuiceBox/Status/state

2024-10-05 12:16:20  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/sensor/JuiceBox/Current/config

2024-10-05 12:16:20  INFO      [ha_mqtt_discoverable] state_topic: hmd/sensor/JuiceBox/Current/state

2024-10-05 12:16:20  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/sensor/JuiceBox/Current-Rating/config

2024-10-05 12:16:20  INFO      [ha_mqtt_discoverable] state_topic: hmd/sensor/JuiceBox/Current-Rating/state

2024-10-05 12:16:20  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/number/JuiceBox/Max-Current/config

2024-10-05 12:16:20  INFO      [ha_mqtt_discoverable] state_topic: hmd/number/JuiceBox/Max-Current/state

2024-10-05 12:16:21  WARNING   [juicebox_mqtthandler] Max Current has no initial_state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/number/JuiceBox/Max-Charging-Current/config

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] state_topic: hmd/number/JuiceBox/Max-Charging-Current/state

2024-10-05 12:16:21  WARNING   [juicebox_mqtthandler] Max Charging Current has no initial_state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/sensor/JuiceBox/Frequency/config

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] state_topic: hmd/sensor/JuiceBox/Frequency/state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/sensor/JuiceBox/Energy--Lifetime-/config

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] state_topic: hmd/sensor/JuiceBox/Energy--Lifetime-/state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/sensor/JuiceBox/Energy--Session-/config

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] state_topic: hmd/sensor/JuiceBox/Energy--Session-/state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/sensor/JuiceBox/Temperature/config

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] state_topic: hmd/sensor/JuiceBox/Temperature/state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/sensor/JuiceBox/Voltage/config

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] state_topic: hmd/sensor/JuiceBox/Voltage/state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/sensor/JuiceBox/Power/config

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] state_topic: hmd/sensor/JuiceBox/Power/state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/switch/JuiceBox/Act-as-Server/config

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] state_topic: hmd/switch/JuiceBox/Act-as-Server/state

2024-10-05 12:16:21  WARNING   [juicebox_mqtthandler] Can't update attributes for Act as Server as MQTT isn't connected/started. (AttributeError: 'Switch' object has no attribute 'update_state')

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/sensor/JuiceBox/Last-Debug-Message/config

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] state_topic: hmd/sensor/JuiceBox/Last-Debug-Message/state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable.sensors] Setting Last Debug Message to INFO: Starting JuicePass Proxy v0.3.1 using hmd/sensor/JuiceBox/Last-Debug-Message/state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/sensor/JuiceBox/Data-from-JuiceBox/config

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] state_topic: hmd/sensor/JuiceBox/Data-from-JuiceBox/state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/sensor/JuiceBox/Data-from-EnelX/config

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] state_topic: hmd/sensor/JuiceBox/Data-from-EnelX/state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] config_topic: homeassistant/text/JuiceBox/Send-Command-to-JuiceBox/config

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable] state_topic: hmd/text/JuiceBox/Send-Command-to-JuiceBox/state

2024-10-05 12:16:21  INFO      [ha_mqtt_discoverable.sensors] Setting Send Command to JuiceBox to Send Command to JuiceBox using hmd/text/JuiceBox/Send-Command-to-JuiceBox/state

2024-10-05 12:16:26  INFO      [juicebox_message] from_string 0817010902040449282317246897:v07,s0004,u53808,V2468,L0024938768,S0,T44,M21,m40,t09,i61,e0000,f5999,X0,Y0!Y9T:

2024-10-05 12:16:26  INFO      [ha_mqtt_discoverable.sensors] Setting Current to 0 using hmd/sensor/JuiceBox/Current/state

2024-10-05 12:16:26  INFO      [ha_mqtt_discoverable.sensors] Setting Energy (Session) to 0 using hmd/sensor/JuiceBox/Energy--Session-/state

2024-10-05 12:16:26  INFO      [ha_mqtt_discoverable.sensors] Setting Voltage to 246.8 using hmd/sensor/JuiceBox/Voltage/state

2024-10-05 12:16:26  INFO      [ha_mqtt_discoverable.sensors] Setting Energy (Lifetime) to 24938768.0 using hmd/sensor/JuiceBox/Energy--Lifetime-/state

2024-10-05 12:16:26  INFO      [ha_mqtt_discoverable.sensors] Setting Status to Unplugged using hmd/sensor/JuiceBox/Status/state

2024-10-05 12:16:26  INFO      [ha_mqtt_discoverable.sensors] Setting Temperature to 111.2 using hmd/sensor/JuiceBox/Temperature/state

2024-10-05 12:16:26  INFO      [ha_mqtt_discoverable.sensors] Setting Max Charging Current to 21.0 using hmd/number/JuiceBox/Max-Charging-Current/state

2024-10-05 12:16:26  INFO      [ha_mqtt_discoverable.sensors] Setting Current Rating to 40.0 using hmd/sensor/JuiceBox/Current-Rating/state

2024-10-05 12:16:26  INFO      [ha_mqtt_discoverable.sensors] Setting Frequency to 59.99 using hmd/sensor/JuiceBox/Frequency/state

2024-10-05 12:16:26  INFO      [ha_mqtt_discoverable.sensors] Setting Power to 0.0 using hmd/sensor/JuiceBox/Power/state

2024-10-05 12:16:26  INFO      [ha_mqtt_discoverable.sensors] Setting Max Current to 40.0 using hmd/number/JuiceBox/Max-Current/state

2024-10-05 12:16:26  INFO      [ha_mqtt_discoverable.sensors] Setting Data from JuiceBox to 0817010902040449282317246897:v07,s0004,u53808,V2468,L0024938768,S0,T44,M21,m40,t09,i61,e0000,f5999,X0,Y0!Y9T: using hmd/sensor/JuiceBox/Data-from-JuiceBox/state

2024-10-05 12:16:30  INFO      [ha_mqtt_discoverable.sensors] Setting Data from EnelX to CMD61216A40M40C006S302!PR7$ using hmd/sensor/JuiceBox/Data-from-EnelX/state

2024-10-05 12:16:30  INFO      [ha_mqtt_discoverable.sensors] Setting Data from EnelX to CMD61216A40M40C242S303!MJ9$ using hmd/sensor/JuiceBox/Data-from-EnelX/state

2024-10-05 12:18:30  WARNING   [juicebox_mitm] No Message Received after 120 sec. (TimeoutError: )

2024-10-05 12:18:30  WARNING   [juicebox_mitm] JuiceboxMITM Reconnecting.

2024-10-05 12:20:35  WARNING   [juicebox_mitm] No Message Received after 120 sec. (TimeoutError: )

2024-10-05 12:20:35  WARNING   [juicebox_mitm] JuiceboxMITM Reconnecting.

2024-10-05 12:22:40  WARNING   [juicebox_mitm] No Message Received after 120 sec. (TimeoutError: )

2024-10-05 12:22:40  WARNING   [juicebox_mitm] JuiceboxMITM Reconnecting.

2024-10-05 12:24:46  WARNING   [juicebox_mitm] No Message Received after 120 sec. (TimeoutError: )

2024-10-05 12:24:46  WARNING   [juicebox_mitm] JuiceboxMITM Reconnecting.
niharmehta commented 1 month ago

Closing issue , as it may be related to port 8047 no longer active and JPP getting confused when swapping hosts/ports.