Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Pypowerwall fails to get data #568

Open
matteoandreozzi opened this issue Jan 13, 2025 · 18 comments
Open

Pypowerwall fails to get data #568

matteoandreozzi opened this issue Jan 13, 2025 · 18 comments

Comments

@matteoandreozzi
Copy link

Problem
No data is shown in Graphana. Pypowerwall reports a type error
To Reproduce
docker logs -f pypowerwall

Host System

  • Hardware Synology NAS

Additional context

Issue started on Dec 9th, with no apparent cause (no OS upgrades on the NAS).

Exception occurred during processing of request from ('172.19.0.1', 56634)
Traceback (most recent call last):
File "/usr/local/lib/python3.10/socketserver.py", line 683, in process_request_thread
self.finish_request(request, client_address)
File "/usr/local/lib/python3.10/socketserver.py", line 360, in finish_request
self.RequestHandlerClass(request, client_address, self)
File "/usr/local/lib/python3.10/socketserver.py", line 747, in init
self.handle()
File "/usr/local/lib/python3.10/http/server.py", line 433, in handle
self.handle_one_request()
File "/usr/local/lib/python3.10/http/server.py", line 421, in handle_one_request
method()
File "/app/server.py", line 683, in do_GET
self.send_header("Set-Cookie", f"AuthCookie={pw.client.auth['AuthCookie']};{cookiesuffix}")
TypeError: 'NoneType' object is not subscriptable

@matteoandreozzi
Copy link
Author

matteoandreozzi commented Jan 13, 2025

Verify.sh output:


Checking pypowerwall

  • Config File pypowerwall.env: GOOD
  • Container (pypowerwall): GOOD
  • Service (port 8675): GOOD
  • Version: 0.12.0 Proxy t66
  • Powerwall State: CONNECTED - Firmware: SolarOnly
  • Site Name: {"pypowerwall": "0.12.0 Proxy t66", "mode": "Local", "gets": 9783, "posts": 0, "errors": 0, "timeout": 0, "uri": {"/aggregates": 1395, "/alerts/pw": 1395, "/soe": 1395, "/pod": 1395, "/strings": 1395, "/temps/pw": 1395, "/freq": 1395, "/version": 4, "/stats": 2}, "ts": 1736768439, "start": 1736761463, "clear": 1736761463, "uptime": "1:56:16", "mem": 36240, "site_name": null, "cloudmode": false, "fleetapi": false, "tedapi": false, "pw3": false, "tedapi_mode": "off", "siteid": null, "counter": 0, "cf": ".auth/.powerwall", "config": {"PW_BIND_ADDRESS": "", "PW_PASSWORD": null, "PW_EMAIL": "[email protected]", "PW_HOST": "", "PW_TIMEZONE": "Europe/London", "PW_DEBUG": false, "PW_CACHE_EXPIRE": 5, "PW_BROWSER_CACHE": 0, "PW_TIMEOUT": 5, "PW_POOL_MAXSIZE": 15, "PW_HTTPS": "no", "PW_PORT": 8675, "PW_STYLE": "grafana-dark.js", "PW_SITEID": null, "PW_AUTH_PATH": ".auth", "PW_AUTH_MODE": "cookie", "PW_CACHE_FILE": ".auth/.powerwall", "PW_CONTROL_SECRET": null, "PW_GW_PWD": null, "PW_NEG_SOLAR": true}}
  • Powerwall Gateway TEDAPI: Not Available (192.168.91.1)
  • Cloud Mode: NO

Checking telegraf

  • Config File telegraf.conf: GOOD
  • Local Config File telegraf.local: GOOD
  • Container (telegraf): GOOD
  • Version: Telegraf 1.28.2 (git: HEAD@8d9cf395)

Checking influxdb

  • Config File influxdb.conf: GOOD
  • Environment File influxdb.env: GOOD
  • Container (influxdb): GOOD
  • Service (port 8086): GOOD
  • Filesystem (./influxdb): GOOD
  • Version: InfluxDB shell version: 1.8.10

Checking grafana

  • Config File grafana.env: GOOD
  • Container (grafana): GOOD
  • Service (port 9000): GOOD
  • Filesystem (./grafana): GOOD
  • Version: Grafana CLI version 9.1.2

Checking weather411

  • Container (weather411): GOOD
  • Service (port 8676): GOOD
  • Weather: {"temperature": 5.78}
  • Version: 0.2.3

All tests succeeded.

@matteoandreozzi
Copy link
Author

I have enabled the debug flag in PyPowerwall and logged this via docker:

01/13/2025 05:13:38 PM [proxy] [INFO] pyPowerwall [0.12.0] Proxy Server [t66] - HTTP Port 8675
01/13/2025 05:13:38 PM [proxy] [INFO] pyPowerwall Proxy Started
01/13/2025 05:13:38 PM [teslapy] [WARNING] Cannot load cache: .auth/.pypowerwall.auth
Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/teslapy/init.py", line 296, in _cache_load
cache = json.load(infile)
File "/usr/local/lib/python3.10/json/init.py", line 293, in load
return loads(fp.read(),
File "/usr/local/lib/python3.10/json/init.py", line 346, in loads
return _default_decoder.decode(s)
File "/usr/local/lib/python3.10/json/decoder.py", line 340, in decode
raise JSONDecodeError("Extra data", s, end)
json.decoder.JSONDecodeError: Extra data: line 1 column 2736 (char 2735)
01/13/2025 05:13:38 PM [pypowerwall.cloud.pypowerwall_cloud] [ERROR] Login failure - MissingCodeError('(missing_code) Missing code parameter in response.')
01/13/2025 05:13:38 PM [proxy] [INFO] pyPowerwall Proxy Server - Local Mode
01/13/2025 05:13:38 PM [proxy] [INFO] Connected to Energy Gateway (Unknown)
01/13/2025 05:13:40 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:13:45 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:13:50 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:13:55 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:14:00 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:14:05 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:14:10 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:14:15 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:14:20 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:14:25 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:14:30 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:14:35 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:14:41 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status

@matteoandreozzi
Copy link
Author

So, I actually found the issue and fixed it : no idea what caused it though! @jasonacox :

I noticed that the error given by the above parser log : json.decoder.JSONDecodeError: Extra data: line 1 column 2736 (char 2735) corresponded to a closed curly bracket in .pypowerwall.auth. I removed that curly bracket, restarted pypowerwall from docker, and it all runs fine now! No idea what caused it (maybe a bugged update.sh? ) Happy to help you trace back the root cause of this issue.

@wiltocking
Copy link

wiltocking commented Jan 13, 2025

So, I actually found the issue and fixed it : no idea what caused it though! @jasonacox :

I noticed that the error given by the above parser log : json.decoder.JSONDecodeError: Extra data: line 1 column 2736 (char 2735) corresponded to a closed curly bracket in .pypowerwall.auth. I removed that curly bracket, restarted pypowerwall from docker, and it all runs fine now! No idea what caused it (maybe a bugged update.sh? ) Happy to help you trace back the root cause of this issue.

Same exact issue with my setup, lost data around 5am and can't connect again.

Logs reporting "01/13/2025 05:34:20 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status" after initial errors in locating the Gateway IP but then switching to "Solar Mode" only. Everything else was green with verify.sh

Gonna try what you did and see if that works!

@wiltocking
Copy link

wiltocking commented Jan 14, 2025

Well, doesn't seem to be the same issue, my log files don't call out a decoder error, just mostly fails to get api data after connecting:

01/13/2025 05:48:11 PM [proxy] [INFO] pyPowerwall [0.12.0] Proxy Server [t66] - HTTP Port 8675
01/13/2025 05:48:11 PM [proxy] [INFO] pyPowerwall Proxy Started
01/13/2025 05:48:16 PM [pypowerwall.tedapi] [ERROR] Unable to connect to Powerwall Gateway 192.168.91.1
01/13/2025 05:48:16 PM [pypowerwall.tedapi] [ERROR] Please verify your your host has a route to the Gateway.
01/13/2025 05:48:16 PM [pypowerwall.tedapi] [ERROR] Error Details: HTTPSConnectionPool(host='192.168.91.1', port=443): Max retries exceeded with url: / (Caused by ConnectTimeoutError(<urllib3.connection.HTTPSConnection object at 0x7fafe1fca0>, 'Connection to 192.168.91.1 timed out. (connect timeout=5)'))
01/13/2025 05:48:16 PM [pypowerwall.tedapi] [ERROR] Failed to connect to Powerwall Gateway
01/13/2025 05:48:21 PM [pypowerwall.tedapi] [ERROR] Unable to connect to Powerwall Gateway 192.168.91.1
01/13/2025 05:48:21 PM [pypowerwall.tedapi] [ERROR] Please verify your your host has a route to the Gateway.
01/13/2025 05:48:21 PM [pypowerwall.tedapi] [ERROR] Error Details: HTTPSConnectionPool(host='192.168.91.1', port=443): Max retries exceeded with url: / (Caused by ConnectTimeoutError(<urllib3.connection.HTTPSConnection object at 0x7fafe705b0>, 'Connection to 192.168.91.1 timed out. (connect timeout=5)'))
01/13/2025 05:48:26 PM [proxy] [INFO] pyPowerwall Proxy Server - Local Mode
01/13/2025 05:48:26 PM [proxy] [INFO] Connected to Energy Gateway 192.168.91.1 (Unknown)
01/13/2025 05:48:45 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status
01/13/2025 05:48:50 PM [pypowerwall] [ERROR] Failed to get /api/system_status/grid_status

@wiltocking
Copy link

Checking pypowerwall

  • Config File pypowerwall.env: GOOD
  • Container (pypowerwall): GOOD
  • Service (port 8675): GOOD
  • Version: 0.12.0 Proxy t66
  • Powerwall State: CONNECTED - Firmware: SolarOnly
  • Site Name: {"pypowerwall": "0.12.0 Proxy t66", "mode": "Local", "gets": 1247, "posts": 0, "errors": 0, "timeout": 0, "uri": {"/aggregates": 179, "/soe": 179, "/temps/pw": 179, "/strings": 178, "/freq": 177, "/alerts/pw": 177, "/pod": 176, "/stats": 2}, "ts": 1736813002, "start": 1736812091, "clear": 1736812091, "uptime": "0:15:11", "mem": 37840, "site_name": null, "cloudmode": false, "fleetapi": false, "tedapi": false, "pw3": false, "tedapi_mode": "off", "siteid": null, "counter": 0, "cf": ".auth/.powerwall", "config": {"PW_BIND_ADDRESS": "", "PW_PASSWORD": "*****", "PW_EMAIL": "[email protected]", "PW_HOST": "192.168.91.1", "PW_TIMEZONE": "America/Chicago", "PW_DEBUG": false, "PW_CACHE_EXPIRE": 5, "PW_BROWSER_CACHE": 0, "PW_TIMEOUT": 5, "PW_POOL_MAXSIZE": 15, "PW_HTTPS": "no", "PW_PORT": 8675, "PW_STYLE": "grafana-dark.js", "PW_SITEID": null, "PW_AUTH_PATH": ".auth", "PW_AUTH_MODE": "cookie", "PW_CACHE_FILE": ".auth/.powerwall", "PW_CONTROL_SECRET": null, "PW_GW_PWD": "**********", "PW_NEG_SOLAR": true}}
  • Powerwall Gateway TEDAPI: Not Available (192.168.91.1)
  • Cloud Mode: NO

Checking telegraf

  • Config File telegraf.conf: GOOD
  • Local Config File telegraf.local: GOOD
  • Container (telegraf): GOOD
  • Version: Telegraf 1.28.2 (git: HEAD@8d9cf395)

Checking influxdb

  • Config File influxdb.conf: GOOD
  • Environment File influxdb.env: GOOD
  • Container (influxdb): GOOD
  • Service (port 8086): GOOD
  • Filesystem (./influxdb): GOOD
  • Version: InfluxDB shell version: 1.8.10

Checking grafana

  • Config File grafana.env: GOOD
  • Container (grafana): GOOD
  • Service (port 9000): GOOD
  • Filesystem (./grafana): GOOD
  • Version: Grafana CLI version 9.1.2

Checking weather411

  • Container (weather411): GOOD
  • Service (port 8676): GOOD
  • Weather: {"temperature": 13.01}
  • Version: 0.2.3

@wiltocking
Copy link

Well... and just as strangely as it started it has resolved itself! Tried to verify the Gateway was accessible in my LAN by going to its IP and logging into it's web-portal. It was, and afterwards the dashboard started working again...

@jasonacox
Copy link
Owner

@matteoandreozzi - Just so I am clear, your setup is Solar Only (or cloud mode)? I see that it some of the config data, along with a missing IP address. In any case, the corruption of the auth file is the cause and worth investigating. In cloud mode, the token will expire and renegotiate with a new token. The corruption could happen then. We are using the teslapy library for that. The error is also happening in that library. I'll take a look to see what we can do to mitigate or decoupling from that library.

@jasonacox
Copy link
Owner

jasonacox commented Jan 14, 2025

@wiltocking Your issue seems to be:

01/13/2025 05:48:16 PM [pypowerwall.tedapi] [ERROR] Unable to connect to Powerwall Gateway 192.168.91.1

This means pypowerwall was unable to connect to that gateway. The host running pypowerwall was unable to connect to 192.168.91.1 - which could be a lot of different networking reasons. One common one is when the Gateway is upgrading firmware, but that may not be your reason. Check your dashboard to see if there were any patterns or alerts that may give a clue as to why it stopped.

@matteoandreozzi
Copy link
Author

Hi @jasonacox my setup is Powerwall plus solar, with auth token authentication (not the new fleet one, to be exact).

I can confirm the installation is back to fully functional now after removing that spurious extra '}' .

Let me know how can I help with debugging the issue.

Things I have done which might have caused it:

  • used the update.sh script
  • expanded NAS storage (where PyPowerwall and the Dashboard run) . I don't see how this could have had anything to do with it
  • updated a bunch of unrelated NAS packages. Also, I don't think this caused it.

@wiltocking
Copy link

@wiltocking Your issue seems to be:

01/13/2025 05:48:16 PM [pypowerwall.tedapi] [ERROR] Unable to connect to Powerwall Gateway 192.168.91.1

This means pypowerwall was unable to connect to that gateway. The host running pypowerwall was unable to connect to 192.168.91.1 - which could be a lot of different networking reasons. One common one is when the Gateway is upgrading firmware, but that may not be your reason. Check your dashboard to see if there were any patterns or alerts that may give a clue as to why it stopped.

Well, it’s updating again but I’ve lost the Powerwall temps and local data that we had established before. Verify.sh when back to stating Not Connected so I’ll have to dig into it a bit to see if I can restore the local “Hybrid” connection we had. Didn’t see any unusual alerts on the dashboard and PW seems to still be on the same firmware from last year. Very weird.

@jasonacox
Copy link
Owner

@matteoandreozzi - That makes sense. The cloud connection method was designed for solar-only install and has limited metrics (but also works fine with Powerwall systems as you know). Have you looked at using one of the local methods instead? Not required, just more curious as to why you chose cloud. In any case, the issue would not be any of the triggers you mention, but likely the way the external library handles connection to the Tesla cloud. I have used this for quite some time and haven't seen the issue you have so it is likely an outlier, but I'm still going to investigate to see if we can add some better error handling.

@wiltocking It seems you are losing the route to the 192.168.91.1 endpoint from the host running the dashboard. Try to ping 192.168.91.1 directly from that host to see if it responds.

@longzheng
Copy link
Contributor

longzheng commented Jan 16, 2025

I also ran into this issue randomly across two Powerwall 2 gateways in two sites (my home and my parents home).

Based on my debugging, I noticed that from the Docker pypowerwall container, it would no longer connect to the 192.168.91.1 host with a simple command like curl -k 192.168.91.1. It would result in a timeout. It seems to get into this state after about 1 minute from a previously successful connection

2025-01-16 21:22:11 01/16/2025 09:22:11 PM [proxy] [INFO] pyPowerwall [0.12.0] Proxy Server [t66] - HTTP Port 8675
2025-01-16 21:22:11 01/16/2025 09:22:11 PM [proxy] [INFO] pyPowerwall Proxy Started
2025-01-16 21:22:11 01/16/2025 09:22:11 PM [proxy] [INFO] pyPowerwall Proxy Server - Local Mode
2025-01-16 21:22:11 01/16/2025 09:22:11 PM [proxy] [INFO] Connected to Energy Gateway 192.168.91.1 (NorthRd)
2025-01-16 21:22:11 01/16/2025 09:22:11 PM [proxy] [INFO] TEDAPI Mode Enabled for Device Vitals (hybrid)
2025-01-16 21:23:10 01/16/2025 09:23:10 PM [pypowerwall.tedapi] [ERROR] Error fetching controller data: HTTPSConnectionPool(host='192.168.91.1', port=443): Read timed out. (read timeout=5)
2025-01-16 21:23:15 01/16/2025 09:23:15 PM [pypowerwall.tedapi] [ERROR] Error fetching controller data: HTTPSConnectionPool(host='192.168.91.1', port=443): Read timed out. (read timeout=5)
2025-01-16 21:23:20 01/16/2025 09:23:20 PM [pypowerwall.tedapi] [ERROR] Error fetching controller data: HTTPSConnectionPool(host='192.168.91.1', port=443): Read timed out. (read timeout=5)

However at the same time, I can successfully get a response from another device (my laptop) on the network so it's not like the gateway is actually unresponsive, but it seems to soft-block/rate limit requests from that IP. It takes maybe a minute of no requests for this block/limit to reset and then connections can be made again.

I've had the TEDAPI method set up for months without issues so this seems like a new issue. Both Powerwall 2 gateways are running 24.44.0 510adfd5 and have been for some time. I wonder and suspect if maybe Tesla rolled out some sort of rate limit protection against the TEDAPI using a server-side config flag without a software update.

I've since just disabled the TEDAPI method by commenting out the #PW_HOST= variable in my pypowerwall.env and rebuilding the containers (with setup.sh). I lose the temperature and other additional metrics but it's better than having nothing at all.

P.S. The ony thing I've changed recently at both sites is upgrading my UniFi UDM OS but I don't expect that to have any overlap with over this issue.

@jasonacox
Copy link
Owner

@longzheng if you lose the ability to ping the 192.168.91.1 from the host, that indeed seems like a network issue. Are you setting the route locally or are you using your network router to create the route?

I have seen issues with hosts losing the ability to reach the endpoint but it is usually an arp issues (unable to get the right mac address for the LAN host so the route fails). As an alternative, I would try rebooting your system running the dashboard to see if it was in a bad state.

For troubleshooting you can try ip route to see what is showing up.

@longzheng
Copy link
Contributor

if you lose the ability to ping the 192.168.91.1 from the host, that indeed seems like a network issue. Are you setting the route locally or are you using your network router to create the route?

It's set as a static route in my Unifi router.

I have seen issues with hosts losing the ability to reach the endpoint but it is usually an arp issues (unable to get the right mac address for the LAN host so the route fails). As an alternative, I would try rebooting your system running the dashboard to see if it was in a bad state.

I've ruled out the host since pypowerwall can successfully connect for a few seconds before it fails (see the log from above).

@jasonacox
Copy link
Owner

Understood. thanks.

@wiltocking
Copy link

@matteoandreozzi - That makes sense. The cloud connection method was designed for solar-only install and has limited metrics (but also works fine with Powerwall systems as you know). Have you looked at using one of the local methods instead? Not required, just more curious as to why you chose cloud. In any case, the issue would not be any of the triggers you mention, but likely the way the external library handles connection to the Tesla cloud. I have used this for quite some time and haven't seen the issue you have so it is likely an outlier, but I'm still going to investigate to see if we can add some better error handling.

@wiltocking It seems you are losing the route to the 192.168.91.1 endpoint from the host running the dashboard. Try to ping 192.168.91.1 directly from that host to see if it responds.

Still able to ping from the host and get a response directly, it can locate the GW but not connect to it.

Image

@wiltocking
Copy link

Small update but not sure if this is what resolved it... Noticed I had the Gateway set to a static IP in its internal configuration BUT also had my router allocating a static IP to the same MAC Address (no idea if this is a conflict or not).

Set the static IP in the internal configuration to an IP address outside the router's DHCP table.

Image

Image

Ran add_route.sh again with the new IP and Ran setup.sh again for Powerwall Dashboard. For now, Hybrid local data has been restored.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants