Powerwall-Dashboard icon indicating copy to clipboard operation
Powerwall-Dashboard copied to clipboard

Frequent gaps in InfluxDB and errors in pypowerwall

Open jgleigh opened this issue 5 months ago • 56 comments

I've noticed that lately I'm seeing a lot more missing data in InfluxDB. I run tesla-history periodically to clean things up. I'm guessing this is related to 23.44.0 firmware, but hard to tell. Dashboard up-to-date and running 4.1.1.

Searching InfluxDB for data gaps (power usage)

  • Found data gap: [2024-03-10 20:32:00-07:00] - [2024-03-10 20:49:00-07:00] (0:17:00s)
  • Found data gap: [2024-03-10 23:31:00-07:00] - [2024-03-10 23:52:00-07:00] (0:21:00s)
  • Found data gap: [2024-03-11 00:47:00-07:00] - [2024-03-11 01:07:00-07:00] (0:20:00s)
  • Found data gap: [2024-03-11 03:02:00-07:00] - [2024-03-11 03:12:00-07:00] (0:10:00s)
  • Found data gap: [2024-03-11 21:32:00-07:00] - [2024-03-11 21:43:00-07:00] (0:11:00s)
  • Found data gap: [2024-03-14 01:02:00-07:00] - [2024-03-14 01:39:00-07:00] (0:37:00s)
  • Found data gap: [2024-03-14 08:30:00-07:00] - [2024-03-14 08:39:00-07:00] (0:09:00s)
  • Found data gap: [2024-03-14 18:30:00-07:00] - [2024-03-14 18:39:00-07:00] (0:09:00s)
  • Found data gap: [2024-03-14 20:01:00-07:00] - [2024-03-14 20:08:00-07:00] (0:07:00s)
  • Found data gap: [2024-03-14 21:15:00-07:00] - [2024-03-14 21:34:00-07:00] (0:19:00s)

2024-03-10 15:31:34 03/10/2024 03:31:34 PM [proxy] [INFO] pyPowerwall [0.7.9] Proxy Server [t42] - HTTP Port 8675 2024-03-10 15:31:34 03/10/2024 03:31:34 PM [proxy] [INFO] pyPowerwall Proxy Started 2024-03-10 15:31:36 03/10/2024 03:31:36 PM [proxy] [INFO] pyPowerwall Proxy Server - Local Mode 2024-03-10 15:31:36 03/10/2024 03:31:36 PM [proxy] [INFO] Connected to Energy Gateway 192.168.1.6 (Home Energy Gateway)

Every gap aligns with these messages in the pypowerwall log.

2024-03-10 20:32:10 03/10/2024 08:32:10 PM [proxy] [ERROR] Socket broken sending API response to client [doGET] ... repeats over and over 2024-03-10 20:36:20 03/10/2024 08:36:20 PM [proxy] [ERROR] Socket broken sending API response to client [doGET] 2024-03-10 20:49:30 ---------------------------------------- 2024-03-10 20:49:30 Exception occurred during processing of request from ('172.18.0.6', 34336) 2024-03-10 20:49:30 ---------------------------------------- 2024-03-10 20:49:30 Exception occurred during processing of request from ('172.18.0.6', 34362) 2024-03-10 20:49:30 Traceback (most recent call last): 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 210, in _get_session 2024-03-10 20:49:30 self.auth = {'AuthCookie': r.cookies['AuthCookie'], 'UserRecord': r.cookies['UserRecord']} 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 334, in getitem 2024-03-10 20:49:30 return self._find_no_duplicates(name) 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 413, in _find_no_duplicates 2024-03-10 20:49:30 raise KeyError(f"name={name!r}, domain={domain!r}, path={path!r}") 2024-03-10 20:49:30 KeyError: "name='AuthCookie', domain=None, path=None" 2024-03-10 20:49:30 2024-03-10 20:49:30 During handling of the above exception, another exception occurred: 2024-03-10 20:49:30 2024-03-10 20:49:30 Traceback (most recent call last): 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/socketserver.py", line 683, in process_request_thread 2024-03-10 20:49:30 self.finish_request(request, client_address) 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/socketserver.py", line 360, in finish_request 2024-03-10 20:49:30 self.RequestHandlerClass(request, client_address, self) 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/socketserver.py", line 747, in init 2024-03-10 20:49:30 self.handle() 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/http/server.py", line 433, in handle 2024-03-10 20:49:30 self.handle_one_request() 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/http/server.py", line 421, in handle_one_request 2024-03-10 20:49:30 method() 2024-03-10 20:49:30 File "/app/server.py", line 307, in do_GET 2024-03-10 20:49:30 d = pw.system_status() or {} 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 735, in system_status 2024-03-10 20:49:30 payload = self.poll('/api/system_status', jsonformat=True) 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 309, in poll 2024-03-10 20:49:30 self._get_session() 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 219, in _get_session 2024-03-10 20:49:30 raise LoginError("Invalid Powerwall Login") 2024-03-10 20:49:30 pypowerwall.LoginError: Invalid Powerwall Login 2024-03-10 20:49:30 ---------------------------------------- 2024-03-10 20:49:30 Traceback (most recent call last): 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 210, in _get_session 2024-03-10 20:49:30 self.auth = {'AuthCookie': r.cookies['AuthCookie'], 'UserRecord': r.cookies['UserRecord']} 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 334, in getitem 2024-03-10 20:49:30 return self._find_no_duplicates(name) 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 413, in _find_no_duplicates 2024-03-10 20:49:30 raise KeyError(f"name={name!r}, domain={domain!r}, path={path!r}") 2024-03-10 20:49:30 KeyError: "name='AuthCookie', domain=None, path=None" 2024-03-10 20:49:30 2024-03-10 20:49:30 During handling of the above exception, another exception occurred: 2024-03-10 20:49:30 2024-03-10 20:49:30 Traceback (most recent call last): 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/socketserver.py", line 683, in process_request_thread 2024-03-10 20:49:30 self.finish_request(request, client_address) 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/socketserver.py", line 360, in finish_request 2024-03-10 20:49:30 self.RequestHandlerClass(request, client_address, self) 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/socketserver.py", line 747, in init 2024-03-10 20:49:30 self.handle() 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/http/server.py", line 433, in handle 2024-03-10 20:49:30 self.handle_one_request() 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/http/server.py", line 421, in handle_one_request 2024-03-10 20:49:30 method() 2024-03-10 20:49:30 File "/app/server.py", line 189, in do_GET 2024-03-10 20:49:30 message = pw.poll('/api/meters/aggregates') 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 309, in poll 2024-03-10 20:49:30 self._get_session() 2024-03-10 20:49:30 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 219, in _get_session 2024-03-10 20:49:30 raise LoginError("Invalid Powerwall Login") 2024-03-10 20:49:30 pypowerwall.LoginError: Invalid Powerwall Login 2024-03-10 20:49:30 ---------------------------------------- 2024-03-10 20:49:31 ---------------------------------------- 2024-03-10 20:49:31 Exception occurred during processing of request from ('172.18.0.6', 34364) 2024-03-10 20:49:31 Traceback (most recent call last): 2024-03-10 20:49:31 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 210, in _get_session 2024-03-10 20:49:31 self.auth = {'AuthCookie': r.cookies['AuthCookie'], 'UserRecord': r.cookies['UserRecord']} 2024-03-10 20:49:31 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 334, in getitem 2024-03-10 20:49:31 return self._find_no_duplicates(name) 2024-03-10 20:49:31 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 413, in _find_no_duplicates 2024-03-10 20:49:31 raise KeyError(f"name={name!r}, domain={domain!r}, path={path!r}") 2024-03-10 20:49:31 KeyError: "name='AuthCookie', domain=None, path=None" 2024-03-10 20:49:31 2024-03-10 20:49:31 During handling of the above exception, another exception occurred: 2024-03-10 20:49:31 2024-03-10 20:49:31 Traceback (most recent call last): 2024-03-10 20:49:31 File "/usr/local/lib/python3.10/socketserver.py", line 683, in process_request_thread 2024-03-10 20:49:31 self.finish_request(request, client_address) 2024-03-10 20:49:31 File "/usr/local/lib/python3.10/socketserver.py", line 360, in finish_request 2024-03-10 20:49:31 self.RequestHandlerClass(request, client_address, self) 2024-03-10 20:49:31 File "/usr/local/lib/python3.10/socketserver.py", line 747, in init 2024-03-10 20:49:31 self.handle() 2024-03-10 20:49:31 File "/usr/local/lib/python3.10/http/server.py", line 433, in handle 2024-03-10 20:49:31 self.handle_one_request() 2024-03-10 20:49:31 File "/usr/local/lib/python3.10/http/server.py", line 421, in handle_one_request 2024-03-10 20:49:31 method() 2024-03-10 20:49:31 File "/app/server.py", line 192, in do_GET 2024-03-10 20:49:31 message = pw.poll('/api/system_status/soe') 2024-03-10 20:49:31 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 309, in poll 2024-03-10 20:49:31 self._get_session() 2024-03-10 20:49:31 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 219, in _get_session 2024-03-10 20:49:31 raise LoginError("Invalid Powerwall Login") 2024-03-10 20:49:31 pypowerwall.LoginError: Invalid Powerwall Login 2024-03-10 20:49:31 ---------------------------------------- 2024-03-10 20:49:35 ---------------------------------------- 2024-03-10 20:49:35 Exception occurred during processing of request from ('172.18.0.6', 38378) 2024-03-10 20:49:35 Traceback (most recent call last): 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 210, in _get_session 2024-03-10 20:49:35 self.auth = {'AuthCookie': r.cookies['AuthCookie'], 'UserRecord': r.cookies['UserRecord']} 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 334, in getitem 2024-03-10 20:49:35 return self._find_no_duplicates(name) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 413, in _find_no_duplicates 2024-03-10 20:49:35 raise KeyError(f"name={name!r}, domain={domain!r}, path={path!r}") 2024-03-10 20:49:35 KeyError: "name='AuthCookie', domain=None, path=None" 2024-03-10 20:49:35 2024-03-10 20:49:35 During handling of the above exception, another exception occurred: 2024-03-10 20:49:35 2024-03-10 20:49:35 Traceback (most recent call last): 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socketserver.py", line 683, in process_request_thread 2024-03-10 20:49:35 self.finish_request(request, client_address) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socketserver.py", line 360, in finish_request 2024-03-10 20:49:35 self.RequestHandlerClass(request, client_address, self) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socketserver.py", line 747, in init 2024-03-10 20:49:35 self.handle() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/http/server.py", line 433, in handle 2024-03-10 20:49:35 self.handle_one_request() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/http/server.py", line 421, in handle_one_request 2024-03-10 20:49:35 method() 2024-03-10 20:49:35 File "/app/server.py", line 307, in do_GET 2024-03-10 20:49:35 d = pw.system_status() or {} 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 735, in system_status 2024-03-10 20:49:35 payload = self.poll('/api/system_status', jsonformat=True) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 309, in poll 2024-03-10 20:49:35 self._get_session() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 219, in _get_session 2024-03-10 20:49:35 raise LoginError("Invalid Powerwall Login") 2024-03-10 20:49:35 pypowerwall.LoginError: Invalid Powerwall Login 2024-03-10 20:49:35 ---------------------------------------- 2024-03-10 20:49:35 ---------------------------------------- 2024-03-10 20:49:35 Exception occurred during processing of request from ('172.18.0.6', 38372) 2024-03-10 20:49:35 Traceback (most recent call last): 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 210, in _get_session 2024-03-10 20:49:35 self.auth = {'AuthCookie': r.cookies['AuthCookie'], 'UserRecord': r.cookies['UserRecord']} 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 334, in getitem 2024-03-10 20:49:35 return self._find_no_duplicates(name) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 413, in _find_no_duplicates 2024-03-10 20:49:35 raise KeyError(f"name={name!r}, domain={domain!r}, path={path!r}") 2024-03-10 20:49:35 KeyError: "name='AuthCookie', domain=None, path=None" 2024-03-10 20:49:35 2024-03-10 20:49:35 During handling of the above exception, another exception occurred: 2024-03-10 20:49:35 2024-03-10 20:49:35 Traceback (most recent call last): 2024-03-10 20:49:35 ---------------------------------------- 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socketserver.py", line 683, in process_request_thread 2024-03-10 20:49:35 self.finish_request(request, client_address) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socketserver.py", line 360, in finish_request 2024-03-10 20:49:35 self.RequestHandlerClass(request, client_address, self) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socketserver.py", line 747, in init 2024-03-10 20:49:35 self.handle() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/http/server.py", line 433, in handle 2024-03-10 20:49:35 self.handle_one_request() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/http/server.py", line 421, in handle_one_request 2024-03-10 20:49:35 method() 2024-03-10 20:49:35 Exception occurred during processing of request from ('172.18.0.6', 38350) 2024-03-10 20:49:35 File "/app/server.py", line 192, in do_GET 2024-03-10 20:49:35 message = pw.poll('/api/system_status/soe') 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 309, in poll 2024-03-10 20:49:35 self._get_session() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 219, in _get_session 2024-03-10 20:49:35 raise LoginError("Invalid Powerwall Login") 2024-03-10 20:49:35 pypowerwall.LoginError: Invalid Powerwall Login 2024-03-10 20:49:35 ---------------------------------------- 2024-03-10 20:49:35 Traceback (most recent call last): 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 210, in _get_session 2024-03-10 20:49:35 self.auth = {'AuthCookie': r.cookies['AuthCookie'], 'UserRecord': r.cookies['UserRecord']} 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 334, in getitem 2024-03-10 20:49:35 return self._find_no_duplicates(name) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 413, in _find_no_duplicates 2024-03-10 20:49:35 raise KeyError(f"name={name!r}, domain={domain!r}, path={path!r}") 2024-03-10 20:49:35 KeyError: "name='AuthCookie', domain=None, path=None" 2024-03-10 20:49:35 2024-03-10 20:49:35 During handling of the above exception, another exception occurred: 2024-03-10 20:49:35 2024-03-10 20:49:35 Traceback (most recent call last): 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socketserver.py", line 683, in process_request_thread 2024-03-10 20:49:35 self.finish_request(request, client_address) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socketserver.py", line 360, in finish_request 2024-03-10 20:49:35 self.RequestHandlerClass(request, client_address, self) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socketserver.py", line 747, in init 2024-03-10 20:49:35 self.handle() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/http/server.py", line 433, in handle 2024-03-10 20:49:35 self.handle_one_request() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/http/server.py", line 421, in handle_one_request 2024-03-10 20:49:35 method() 2024-03-10 20:49:35 File "/app/server.py", line 269, in do_GET 2024-03-10 20:49:35 d = pw.system_status() or {} 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 735, in system_status 2024-03-10 20:49:35 payload = self.poll('/api/system_status', jsonformat=True) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 309, in poll 2024-03-10 20:49:35 self._get_session() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 219, in _get_session 2024-03-10 20:49:35 raise LoginError("Invalid Powerwall Login") 2024-03-10 20:49:35 pypowerwall.LoginError: Invalid Powerwall Login 2024-03-10 20:49:35 ---------------------------------------- 2024-03-10 20:49:35 ---------------------------------------- 2024-03-10 20:49:35 Exception occurred during processing of request from ('172.18.0.6', 34338) 2024-03-10 20:49:35 Traceback (most recent call last): 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/urllib3/connectionpool.py", line 537, in _make_request 2024-03-10 20:49:35 response = conn.getresponse() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/urllib3/connection.py", line 466, in getresponse 2024-03-10 20:49:35 httplib_response = super().getresponse() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/http/client.py", line 1375, in getresponse 2024-03-10 20:49:35 response.begin() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/http/client.py", line 318, in begin 2024-03-10 20:49:35 version, status, reason = self._read_status() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/http/client.py", line 279, in _read_status 2024-03-10 20:49:35 line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1") 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socket.py", line 705, in readinto 2024-03-10 20:49:35 return self._sock.recv_into(b) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/ssl.py", line 1307, in recv_into 2024-03-10 20:49:35 return self.read(nbytes, buffer) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/ssl.py", line 1163, in read 2024-03-10 20:49:35 return self._sslobj.read(len, buffer) 2024-03-10 20:49:35 TimeoutError: The read operation timed out 2024-03-10 20:49:35 2024-03-10 20:49:35 The above exception was the direct cause of the following exception: 2024-03-10 20:49:35 2024-03-10 20:49:35 Traceback (most recent call last): 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/requests/adapters.py", line 486, in send 2024-03-10 20:49:35 resp = conn.urlopen( 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/urllib3/connectionpool.py", line 847, in urlopen 2024-03-10 20:49:35 retries = retries.increment( 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/urllib3/util/retry.py", line 470, in increment 2024-03-10 20:49:35 raise reraise(type(error), error, _stacktrace) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/urllib3/util/util.py", line 39, in reraise 2024-03-10 20:49:35 raise value 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/urllib3/connectionpool.py", line 793, in urlopen 2024-03-10 20:49:35 response = self._make_request( 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/urllib3/connectionpool.py", line 539, in _make_request 2024-03-10 20:49:35 self._raise_timeout(err=e, url=url, timeout_value=read_timeout) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/urllib3/connectionpool.py", line 370, in _raise_timeout 2024-03-10 20:49:35 raise ReadTimeoutError( 2024-03-10 20:49:35 urllib3.exceptions.ReadTimeoutError: HTTPSConnectionPool(host='192.168.1.6', port=443): Read timed out. (read timeout=5) 2024-03-10 20:49:35 2024-03-10 20:49:35 During handling of the above exception, another exception occurred: 2024-03-10 20:49:35 2024-03-10 20:49:35 Traceback (most recent call last): 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 197, in _get_session 2024-03-10 20:49:35 r = self.session.post(url,data = pload, verify=False, timeout=self.timeout) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/requests/sessions.py", line 637, in post 2024-03-10 20:49:35 return self.request("POST", url, data=data, json=json, **kwargs) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/requests/sessions.py", line 589, in request 2024-03-10 20:49:35 resp = self.send(prep, **send_kwargs) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/requests/sessions.py", line 703, in send 2024-03-10 20:49:35 r = adapter.send(request, **kwargs) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/requests/adapters.py", line 532, in send 2024-03-10 20:49:35 raise ReadTimeout(e, request=request) 2024-03-10 20:49:35 requests.exceptions.ReadTimeout: HTTPSConnectionPool(host='192.168.1.6', port=443): Read timed out. (read timeout=5) 2024-03-10 20:49:35 2024-03-10 20:49:35 During handling of the above exception, another exception occurred: 2024-03-10 20:49:35 2024-03-10 20:49:35 Traceback (most recent call last): 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socketserver.py", line 683, in process_request_thread 2024-03-10 20:49:35 self.finish_request(request, client_address) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socketserver.py", line 360, in finish_request 2024-03-10 20:49:35 self.RequestHandlerClass(request, client_address, self) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/socketserver.py", line 747, in init 2024-03-10 20:49:35 self.handle() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/http/server.py", line 433, in handle 2024-03-10 20:49:35 self.handle_one_request() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/http/server.py", line 421, in handle_one_request 2024-03-10 20:49:35 method() 2024-03-10 20:49:35 File "/app/server.py", line 269, in do_GET 2024-03-10 20:49:35 d = pw.system_status() or {} 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 735, in system_status 2024-03-10 20:49:35 payload = self.poll('/api/system_status', jsonformat=True) 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 309, in poll 2024-03-10 20:49:35 self._get_session() 2024-03-10 20:49:35 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 202, in _get_session 2024-03-10 20:49:35 raise ConnectionError(err) 2024-03-10 20:49:35 pypowerwall.ConnectionError: Unable to connect to Powerwall at https://192.168.1.6 2024-03-10 20:49:35 ---------------------------------------- 2024-03-10 20:49:36 ---------------------------------------- 2024-03-10 20:49:36 Exception occurred during processing of request from ('172.18.0.6', 38394) 2024-03-10 20:49:36 Traceback (most recent call last): 2024-03-10 20:49:36 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 210, in _get_session 2024-03-10 20:49:36 self.auth = {'AuthCookie': r.cookies['AuthCookie'], 'UserRecord': r.cookies['UserRecord']} 2024-03-10 20:49:36 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 334, in getitem 2024-03-10 20:49:36 return self._find_no_duplicates(name) 2024-03-10 20:49:36 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 413, in _find_no_duplicates 2024-03-10 20:49:36 raise KeyError(f"name={name!r}, domain={domain!r}, path={path!r}") 2024-03-10 20:49:36 KeyError: "name='AuthCookie', domain=None, path=None" 2024-03-10 20:49:36 2024-03-10 20:49:36 During handling of the above exception, another exception occurred: 2024-03-10 20:49:36 2024-03-10 20:49:36 Traceback (most recent call last): 2024-03-10 20:49:36 File "/usr/local/lib/python3.10/socketserver.py", line 683, in process_request_thread 2024-03-10 20:49:36 self.finish_request(request, client_address) 2024-03-10 20:49:36 File "/usr/local/lib/python3.10/socketserver.py", line 360, in finish_request 2024-03-10 20:49:36 self.RequestHandlerClass(request, client_address, self) 2024-03-10 20:49:36 File "/usr/local/lib/python3.10/socketserver.py", line 747, in init 2024-03-10 20:49:36 self.handle() 2024-03-10 20:49:36 File "/usr/local/lib/python3.10/http/server.py", line 433, in handle 2024-03-10 20:49:36 self.handle_one_request() 2024-03-10 20:49:36 File "/usr/local/lib/python3.10/http/server.py", line 421, in handle_one_request 2024-03-10 20:49:36 method() 2024-03-10 20:49:36 File "/app/server.py", line 189, in do_GET 2024-03-10 20:49:36 message = pw.poll('/api/meters/aggregates') 2024-03-10 20:49:36 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 309, in poll 2024-03-10 20:49:36 self._get_session() 2024-03-10 20:49:36 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 219, in _get_session 2024-03-10 20:49:36 raise LoginError("Invalid Powerwall Login") 2024-03-10 20:49:36 pypowerwall.LoginError: Invalid Powerwall Login 2024-03-10 20:49:36 ---------------------------------------- 2024-03-10 20:49:40 ---------------------------------------- 2024-03-10 20:49:40 Exception occurred during processing of request from ('172.18.0.6', 38440) 2024-03-10 20:49:40 Traceback (most recent call last): 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 210, in _get_session 2024-03-10 20:49:40 self.auth = {'AuthCookie': r.cookies['AuthCookie'], 'UserRecord': r.cookies['UserRecord']} 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 334, in getitem 2024-03-10 20:49:40 return self._find_no_duplicates(name) 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 413, in _find_no_duplicates 2024-03-10 20:49:40 raise KeyError(f"name={name!r}, domain={domain!r}, path={path!r}") 2024-03-10 20:49:40 KeyError: "name='AuthCookie', domain=None, path=None" 2024-03-10 20:49:40 2024-03-10 20:49:40 During handling of the above exception, another exception occurred: 2024-03-10 20:49:40 2024-03-10 20:49:40 Traceback (most recent call last): 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/socketserver.py", line 683, in process_request_thread 2024-03-10 20:49:40 self.finish_request(request, client_address) 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/socketserver.py", line 360, in finish_request 2024-03-10 20:49:40 self.RequestHandlerClass(request, client_address, self) 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/socketserver.py", line 747, in init 2024-03-10 20:49:40 self.handle() 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/http/server.py", line 433, in handle 2024-03-10 20:49:40 self.handle_one_request() 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/http/server.py", line 421, in handle_one_request 2024-03-10 20:49:40 method() 2024-03-10 20:49:40 File "/app/server.py", line 192, in do_GET 2024-03-10 20:49:40 message = pw.poll('/api/system_status/soe') 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 309, in poll 2024-03-10 20:49:40 self._get_session() 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 219, in _get_session 2024-03-10 20:49:40 raise LoginError("Invalid Powerwall Login") 2024-03-10 20:49:40 pypowerwall.LoginError: Invalid Powerwall Login 2024-03-10 20:49:40 ---------------------------------------- 2024-03-10 20:49:40 ---------------------------------------- 2024-03-10 20:49:40 Exception occurred during processing of request from ('172.18.0.6', 38422) 2024-03-10 20:49:40 Traceback (most recent call last): 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 210, in _get_session 2024-03-10 20:49:40 self.auth = {'AuthCookie': r.cookies['AuthCookie'], 'UserRecord': r.cookies['UserRecord']} 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 334, in getitem 2024-03-10 20:49:40 return self._find_no_duplicates(name) 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 413, in _find_no_duplicates 2024-03-10 20:49:40 raise KeyError(f"name={name!r}, domain={domain!r}, path={path!r}") 2024-03-10 20:49:40 KeyError: "name='AuthCookie', domain=None, path=None" 2024-03-10 20:49:40 2024-03-10 20:49:40 During handling of the above exception, another exception occurred: 2024-03-10 20:49:40 2024-03-10 20:49:40 Traceback (most recent call last): 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/socketserver.py", line 683, in process_request_thread 2024-03-10 20:49:40 self.finish_request(request, client_address) 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/socketserver.py", line 360, in finish_request 2024-03-10 20:49:40 self.RequestHandlerClass(request, client_address, self) 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/socketserver.py", line 747, in init 2024-03-10 20:49:40 self.handle() 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/http/server.py", line 433, in handle 2024-03-10 20:49:40 self.handle_one_request() 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/http/server.py", line 421, in handle_one_request 2024-03-10 20:49:40 method() 2024-03-10 20:49:40 File "/app/server.py", line 307, in do_GET 2024-03-10 20:49:40 d = pw.system_status() or {} 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 735, in system_status 2024-03-10 20:49:40 payload = self.poll('/api/system_status', jsonformat=True) 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 309, in poll 2024-03-10 20:49:40 self._get_session() 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 219, in _get_session 2024-03-10 20:49:40 raise LoginError("Invalid Powerwall Login") 2024-03-10 20:49:40 pypowerwall.LoginError: Invalid Powerwall Login 2024-03-10 20:49:40 ---------------------------------------- 2024-03-10 20:49:40 ---------------------------------------- 2024-03-10 20:49:40 Exception occurred during processing of request from ('172.18.0.6', 38400) 2024-03-10 20:49:40 Traceback (most recent call last): 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 210, in _get_session 2024-03-10 20:49:40 self.auth = {'AuthCookie': r.cookies['AuthCookie'], 'UserRecord': r.cookies['UserRecord']} 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 334, in getitem 2024-03-10 20:49:40 return self._find_no_duplicates(name) 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/requests/cookies.py", line 413, in _find_no_duplicates 2024-03-10 20:49:40 raise KeyError(f"name={name!r}, domain={domain!r}, path={path!r}") 2024-03-10 20:49:40 KeyError: "name='AuthCookie', domain=None, path=None" 2024-03-10 20:49:40 2024-03-10 20:49:40 During handling of the above exception, another exception occurred: 2024-03-10 20:49:40 2024-03-10 20:49:40 Traceback (most recent call last): 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/socketserver.py", line 683, in process_request_thread 2024-03-10 20:49:40 self.finish_request(request, client_address) 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/socketserver.py", line 360, in finish_request 2024-03-10 20:49:40 self.RequestHandlerClass(request, client_address, self) 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/socketserver.py", line 747, in init 2024-03-10 20:49:40 self.handle() 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/http/server.py", line 433, in handle 2024-03-10 20:49:40 self.handle_one_request() 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/http/server.py", line 421, in handle_one_request 2024-03-10 20:49:40 method() 2024-03-10 20:49:40 File "/app/server.py", line 269, in do_GET 2024-03-10 20:49:40 d = pw.system_status() or {} 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 735, in system_status 2024-03-10 20:49:40 payload = self.poll('/api/system_status', jsonformat=True) 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 309, in poll 2024-03-10 20:49:40 self._get_session() 2024-03-10 20:49:40 File "/usr/local/lib/python3.10/site-packages/pypowerwall/init.py", line 219, in _get_session 2024-03-10 20:49:40 raise LoginError("Invalid Powerwall Login") 2024-03-10 20:49:40 pypowerwall.LoginError: Invalid Powerwall Login 2024-03-10 20:49:40 ---------------------------------------- 2024-03-10 20:49:44 03/10/2024 08:49:44 PM [proxy] [ERROR] Socket broken sending API response to client [doGET]

And then everything returns to normal until the next data gap.

jgleigh avatar Mar 15 '24 13:03 jgleigh

Potentially unrelated, but I had to reboot my Gateway today. It completely locked up and was offline for an hour before I noticed. Hadn't done that in a very long time (ever since I ditched WiFi).

jgleigh avatar Mar 15 '24 21:03 jgleigh

Definitely seems like a flaw in the Gateway design that it doesn't have a watchdog timer to reboot itself when it gets stuck. Gateway could be offline for a considerable amount of time if people don't watch it as closely as we tend to.

jgleigh avatar Mar 15 '24 21:03 jgleigh

pypowerwall.LoginError: Invalid Powerwall Login

I have seen this during upgrades or when the gateway starts rate limiting you. If it sees too many connections or requests, it will lock you out. However, it will clear within 10 minutes if you stop pypowerwall. I assume you are only using the standard pypowerwall to access the gateway? If so, you may want to adjust the cache or max pool size by adding these lines to pypowerwall.env:

PW_POOL_MAXSIZE=15
PW_CACHE_EXPIRE=5

I would only adjust one at a time. Specifically: Try to decrease the pool size to 12 or 10. If that doesn't help, try increasing the cache to 10 (seconds).

These default settings have been working through many different upgrades but perhaps something happened with 23.44.0 that makes it more sensitive to local API calls.

jasonacox avatar Mar 16 '24 05:03 jasonacox

I was using 15 for the pool size, so I'm going to try 10 and see if that helps. I found the old threads where this was actually made the default based on my feedback. :)

https://github.com/jasonacox/Powerwall-Dashboard/discussions/261

jgleigh avatar Mar 16 '24 13:03 jgleigh

That's right, you're the troublemaker?! 😂

Reducing to 10 could resurrect old errors again (pool cycling) but may reduce the rate limiting (if that is indeed what is happening). The other possibility is that requesting a 404 API endpoint (e.g. /api/device/vitals) trips the rate limit. Right now pypowerwall will continue to retry that API. We could add logic to detect Firmware version or the 404 response and either stop trying or cache it for a longer period.

jasonacox avatar Mar 16 '24 16:03 jasonacox

Good thought about vitals. I hadn't been watching it that closely to see when the data dropouts started, but it's very possible they align with 23.44.0.

A little surprised you haven't been upgraded yet.

jgleigh avatar Mar 16 '24 16:03 jgleigh

@jgleigh If you want to try it, I updated pypowerwall to cache the 404 responses and not retry them for 10 minutes. You can test it by editing the powerwall.yml and updating the version of pypowerwall to: jasonacox/pypowerwall:0.7.10t42

    pypowerwall:
        image: jasonacox/pypowerwall:0.7.10t42
# Restart
./compose-dash.sh up -d

I'l run some test and unless there are issues, push it as v4.1.2 for everyone else.

jasonacox avatar Mar 16 '24 19:03 jasonacox

@jasonacox, as an alternative to caching 404, would it be possible to test if version is above 23.44 and skip the call to vitals altogether. I know you don't want to give up on it yet, but right now it looks as though vitals is not coming back, so I'm not sure what we get from caching the results of a call we know is failing?

I've just checked my logs and I'm seeing the same intermittent broken sockets as @jgleigh - I've turned on debug to see if I get more on what is happening at this point.

BuongiornoTexas avatar Mar 16 '24 21:03 BuongiornoTexas

@BuongiornoTexas excellent point. I'll add that. Let me know what you see in debug mode. I'm also going to add detection logic for a 429 "Too Many Requests" HTTP response and build in backoff logic similar to the 404 response. That would help during high CPU events (e.g. during Firmware upgrades) as well.

jasonacox avatar Mar 16 '24 23:03 jasonacox

Here are the broken socket errors from the last couple of hours and a couple of lines each side. I'm not seeing a specific pattern in URLs - arguably it's a bit concerning that it is not tied to any specific url aside from vitals (which we already know is not working as it used to).

I also haven't seen an Exception yet, so I'll leave it running to see if I can get more info (there were definitely some Exceptions in the log before I restarted in debug mode).

03/17/2024 08:44:05 AM [proxy] [DEBUG] 172.18.0.4 "GET /api/system_status HTTP/1.1" 200 -
03/17/2024 08:44:05 AM [proxy] [DEBUG] 172.18.0.4 "GET /freq HTTP/1.1" 200 -
03/17/2024 08:44:05 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/devices/vitals
03/17/2024 08:44:05 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 08:44:05 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 08:44:05 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 08:44:06 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
--
03/17/2024 08:44:11 AM [proxy] [DEBUG] 172.18.0.4 "GET /freq HTTP/1.1" 200 -
03/17/2024 08:44:11 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/system_status/grid_status
03/17/2024 08:44:11 AM [pypowerwall] [DEBUG] ERROR unable to parse payload for grid_status: None
03/17/2024 08:44:11 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 08:44:11 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 08:44:11 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 08:44:15 AM [proxy] [DEBUG] 172.18.0.4 "GET /strings HTTP/1.1" 200 -
--
03/17/2024 09:05:00 AM [proxy] [DEBUG] 172.18.0.4 "GET /alerts/pw HTTP/1.1" 200 -
03/17/2024 09:05:00 AM [proxy] [DEBUG] 172.18.0.4 "GET /api/meters/solar HTTP/1.1" 200 -
03/17/2024 09:05:00 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/meters/site
03/17/2024 09:05:00 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 09:05:00 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:05:00 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:05:00 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
--
03/17/2024 09:05:05 AM [proxy] [DEBUG] 172.18.0.4 "GET /api/system_status HTTP/1.1" 200 -
03/17/2024 09:05:05 AM [proxy] [DEBUG] 172.18.0.4 "GET /api/meters/solar HTTP/1.1" 200 -
03/17/2024 09:05:05 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/devices/vitals
03/17/2024 09:05:05 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 09:05:05 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:05:05 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:05:05 AM [proxy] [DEBUG] 172.18.0.4 "GET /api/meters/site HTTP/1.1" 200 -
--
03/17/2024 09:08:30 AM [proxy] [DEBUG] 172.18.0.4 "GET /api/meters/site HTTP/1.1" 200 -
03/17/2024 09:08:30 AM [proxy] [DEBUG] 172.18.0.4 "GET /pod HTTP/1.1" 200 -
03/17/2024 09:08:30 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/system_status/soe
03/17/2024 09:08:30 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 09:08:30 AM [proxy] [DEBUG] 172.18.0.4 "GET /temps/pw HTTP/1.1" 200 -
03/17/2024 09:08:30 AM [proxy] [DEBUG] 172.18.0.4 "GET /aggregates HTTP/1.1" 200 -
03/17/2024 09:08:30 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
--
03/17/2024 09:17:50 AM [proxy] [DEBUG] 172.18.0.4 "GET /strings HTTP/1.1" 200 -
03/17/2024 09:17:50 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/devices/vitals
03/17/2024 09:17:50 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:17:50 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 09:17:50 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:17:50 AM [proxy] [DEBUG] 172.18.0.1 "GET /api/sitemaster HTTP/1.1" 200 -
03/17/2024 09:17:50 AM [proxy] [DEBUG] 172.18.0.1 "GET /api/system_status/soe HTTP/1.1" 200 -
--
03/17/2024 09:24:40 AM [proxy] [DEBUG] 172.18.0.4 "GET /alerts/pw HTTP/1.1" 200 -
03/17/2024 09:24:40 AM [proxy] [DEBUG] 172.18.0.4 "GET /aggregates HTTP/1.1" 200 -
03/17/2024 09:24:40 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/devices/vitals
03/17/2024 09:24:40 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 09:24:40 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:24:40 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:24:40 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
--
03/17/2024 09:46:30 AM [proxy] [DEBUG] 172.18.0.4 "GET /strings HTTP/1.1" 200 -
03/17/2024 09:46:30 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/meters/site
03/17/2024 09:46:30 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:46:30 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 09:46:30 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:46:30 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:46:30 AM [proxy] [DEBUG] 172.18.0.1 "GET /api/sitemaster HTTP/1.1" 200 -
--
03/17/2024 09:50:51 AM [proxy] [DEBUG] 172.18.0.4 "GET /temps/pw HTTP/1.1" 200 -
03/17/2024 09:50:51 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:50:51 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/operation
03/17/2024 09:50:51 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 09:50:53 AM [proxy] [DEBUG] 172.18.0.1 "GET /api/sitemaster HTTP/1.1" 200 -
03/17/2024 09:50:53 AM [proxy] [DEBUG] 172.18.0.1 "GET /api/meters/aggregates HTTP/1.1" 200 -
03/17/2024 09:50:53 AM [proxy] [DEBUG] 172.18.0.1 "GET /api/system_status/soe HTTP/1.1" 200 -
--
03/17/2024 09:50:55 AM [proxy] [DEBUG] 172.18.0.4 "GET /freq HTTP/1.1" 200 -
03/17/2024 09:50:55 AM [proxy] [DEBUG] 172.18.0.4 "GET /api/meters/solar HTTP/1.1" 200 -
03/17/2024 09:50:55 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/devices/vitals
03/17/2024 09:50:55 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 09:50:55 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:50:55 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:50:55 AM [proxy] [DEBUG] 172.18.0.4 "GET /api/meters/site HTTP/1.1" 200 -
--
03/17/2024 09:54:15 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/system_status
03/17/2024 09:54:15 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:54:15 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:54:15 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 09:54:15 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 09:54:15 AM [proxy] [DEBUG] 172.18.0.1 "GET /api/meters/aggregates HTTP/1.1" 200 -
03/17/2024 09:54:15 AM [proxy] [DEBUG] 172.18.0.1 "GET /api/sitemaster HTTP/1.1" 200 -
--
03/17/2024 10:01:55 AM [proxy] [DEBUG] 172.18.0.4 "GET /alerts/pw HTTP/1.1" 200 -
03/17/2024 10:01:55 AM [proxy] [DEBUG] 172.18.0.4 "GET /aggregates HTTP/1.1" 200 -
03/17/2024 10:01:55 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/meters/aggregates
03/17/2024 10:01:55 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 10:01:55 AM [proxy] [DEBUG] 172.18.0.4 "GET /temps/pw HTTP/1.1" 200 -
03/17/2024 10:01:55 AM [proxy] [DEBUG] 172.18.0.4 "GET /freq HTTP/1.1" 200 -
03/17/2024 10:01:55 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
--
03/17/2024 10:04:00 AM [proxy] [DEBUG] 172.18.0.4 "GET /freq HTTP/1.1" 200 -
03/17/2024 10:04:00 AM [proxy] [DEBUG] 172.18.0.4 "GET /pod HTTP/1.1" 200 -
03/17/2024 10:04:00 AM [pypowerwall] [DEBUG] ERROR Timeout waiting for Powerwall API https://192.168.25.11/api/devices/vitals
03/17/2024 10:04:00 AM [proxy] [ERROR] Socket broken sending API response to client [doGET]
03/17/2024 10:04:00 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 10:04:00 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals
03/17/2024 10:04:00 AM [pypowerwall] [DEBUG] 404 Powerwall API not found at https://192.168.25.11/api/devices/vitals

BuongiornoTexas avatar Mar 16 '24 23:03 BuongiornoTexas

Thanks @BuongiornoTexas - Did you switch to jasonacox/pypowerwall:0.7.10t42 ?

jasonacox avatar Mar 16 '24 23:03 jasonacox

| Did you switch to jasonacox/pypowerwall:0.7.10t42 ?

Not yet - I thought it was worth checking if I could get more details on the cause/trigger for the auth Exception @jgleigh is seeing before moving on to the new container.

BuongiornoTexas avatar Mar 16 '24 23:03 BuongiornoTexas

I've got 0.7.10t42 running. All good so far.

jgleigh avatar Mar 16 '24 23:03 jgleigh

I updated pypowerwall to detect the Firmware version > 23.44 which will cause it to disable API calls to vitals. I also added logic to detect rate limiting and activate a cooldown period (5m). Instead of serving up cached data during that cooldown, I'm sending back None to create a true representation of the state. It will likely still result in the proxy throwing some errors, but it should help the Powerwall gateway recover more quickly and reduce the timeouts.

You can test it by editing the powerwall.yml and updating the version of pypowerwall to: jasonacox/pypowerwall:0.7.11t42

    pypowerwall:
        image: jasonacox/pypowerwall:0.7.11t42
# Restart
./compose-dash.sh up -d

# Check logs - you should see a Firmware detection a vitals disabled notice if all goes well
docker logs pypowerwall -f

jasonacox avatar Mar 17 '24 01:03 jasonacox

Here's the output:

2024-03-16 18:10:50 03/16/2024 06:10:50 PM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/devices/vitals
2024-03-16 18:10:50 03/16/2024 06:10:50 PM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/devices/vitals
2024-03-16 18:10:50 03/16/2024 06:10:50 PM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/devices/vitals
2024-03-16 18:10:50 03/16/2024 06:10:50 PM [pypowerwall] [ERROR] Firmware 234400 detected - Does not support vitals API - disabling.
2024-03-16 18:10:50 03/16/2024 06:10:50 PM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/devices/vitals
2024-03-16 18:10:50 03/16/2024 06:10:50 PM [pypowerwall] [ERROR] Firmware 234400 detected - Does not support vitals API - disabling.
2024-03-16 18:10:50 03/16/2024 06:10:50 PM [pypowerwall] [ERROR] Firmware 234400 detected - Does not support vitals API - disabling.
2024-03-16 18:10:50 03/16/2024 06:10:50 PM [pypowerwall] [ERROR] Firmware 234400 detected - Does not support vitals API - disabling.

jgleigh avatar Mar 17 '24 01:03 jgleigh

@jgleigh Can you check if the broken sockets are still occurring?

docker logs pypowerwall 2>&1 >/dev/null | grep doGET

BuongiornoTexas avatar Mar 17 '24 01:03 BuongiornoTexas

Thanks @jgleigh ! As you see, each thread discovers the 404 and detects the new firmware, causing it to disable vitals.

@BuongiornoTexas , I'm still being a bit optimistic by looking for a 404 before disabling, but the effect is the same and should significantly reduce the load on the gateway. It may not 100% solve the doGET errors (since that is client side connection) but it should help.

Please let me know what you both observe. I'll run it for a while and submit it as v4.1.2 later today.

Thanks for your help!!! 🙏

jasonacox avatar Mar 17 '24 01:03 jasonacox

| It may not 100% solve the doGET errors (since that is client side connection)

I was mostly interested in the doGETs because only about half were on vitals. The log above shows doGET errors triggered by timeouts on grid_status, soe, aggregates and site meters. I was/am curious if these are resolved when the vitals calls are bypassed.

BuongiornoTexas avatar Mar 17 '24 02:03 BuongiornoTexas

Agree.

I just merged v4.1.2 - Use upgrade.sh to update to latest.

jasonacox avatar Mar 17 '24 04:03 jasonacox

I've just run the upgrade - I'm still seeing plenty of socket broken errors, but nothing on the vitals anymore. I'll check if any exceptions throw overnight.

BuongiornoTexas avatar Mar 17 '24 05:03 BuongiornoTexas

My socket errors were pretty random. I also reduced my pool size to 10. Going to let it run for a few days and see how things look with 4.1.2.

FYI, looks like another part of the API got dropped:

2024-03-16 22:52:50 03/16/2024 10:52:50 PM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/troubleshooting/problems

jgleigh avatar Mar 17 '24 05:03 jgleigh

Like @jgleigh, I'm seeing plenty of the api/troubleshooting/problems errors, and regular doGET errors still (had debug off overnight, so will need to check for more detail). Also had a series of auth errors lasting about 10 seconds in the middle of the night. This triggering error occured 6 times in a row, and then things went back to normal.

  File "/usr/local/lib/python3.10/site-packages/pypowerwall/__init__.py", line 212, in _get_session
    self.auth = {'AuthCookie': r.cookies['AuthCookie'], 'UserRecord': r.cookies['UserRecord']}

BuongiornoTexas avatar Mar 18 '24 04:03 BuongiornoTexas

No broken sockets here. Just the missing api/troubleshooting/problems.

2024-03-16 22:52:50 03/16/2024 10:52:50 PM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/devices/vitals
2024-03-16 22:52:50 03/16/2024 10:52:50 PM [pypowerwall] [ERROR] Firmware 234400 detected - Does not support vitals API - disabling.
2024-03-16 22:52:50 03/16/2024 10:52:50 PM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/troubleshooting/problems
2024-03-17 08:03:53 03/17/2024 08:03:53 AM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/troubleshooting/problems
2024-03-17 09:44:30 03/17/2024 09:44:30 AM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/troubleshooting/problems
2024-03-17 10:07:51 03/17/2024 10:07:51 AM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/troubleshooting/problems
2024-03-17 20:13:31 03/17/2024 08:13:31 PM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/troubleshooting/problems
2024-03-18 05:23:11 03/18/2024 05:23:11 AM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/troubleshooting/problems

jgleigh avatar Mar 18 '24 12:03 jgleigh

Hmm - OK, may be a local issue to my site. Will need to dig a bit more.

BuongiornoTexas avatar Mar 18 '24 21:03 BuongiornoTexas

Thanks! The /api/troubleshooting/problems 404 is new. I'm glad we have the 404 logic to cache it so at lest it will be less load. The power flow animation was designed to use that so it must have been removed. I'll stub it out.

FYI It would be this in the past, I assume this was a way to communicate banner notices of problems in the portal:

{
"problems": []
}

jasonacox avatar Mar 19 '24 04:03 jasonacox

Ok, if you want to try it - this quick update stubs out /api/troubleshooting/problems so related 404's should go away.

jasonacox/pypowerwall:0.7.12t44

jasonacox avatar Mar 19 '24 04:03 jasonacox

Hmm - OK, may be a local issue to my site. Will need to dig a bit more.

Is your Gateway on WiFi or Ethernet? I had a lot of trouble when my system was first installed. It would lose connections and lockup all the time on WiFi. Been mostly rock solid since I moved to Ethernet exclusively.

jgleigh avatar Mar 19 '24 04:03 jgleigh

Ok, if you want to try it - this quick update stubs out /api/troubleshooting/problems so related 404's should go away.

jasonacox/pypowerwall:0.7.12t44

Amazing work getting some of the string data back. I can only imagine the rest is buried in the API somewhere. Of course would love to see the temps again to hopefully catch a failing cooling system before it dies.

jgleigh avatar Mar 19 '24 04:03 jgleigh

Thanks @jgleigh ! We are still on the hunt for those temps. 😁

jasonacox avatar Mar 19 '24 04:03 jasonacox

Is your Gateway on WiFi or Ethernet?

Wifi, but fairly reliable since I put in a static ARP (as far as I can understand it, for some reason the powerwall stops doing the things it should to tell the router it is still on the network - static ARP fixes it). Horrible, but it works.

Will try the updated pypowerwall, but I think I'm seeing something else related to the powerflow animation - when I did the update yesterday, it updated my grafana.env to set GF_SECURITY_ALLOW_EMBEDDING to true. For reasons only known to grafana, this cratered performance, and a lot of the issues seemed to be with the powerflow animation. Switching it back to false got things moving again. This one I do not understand - as far as I know the only thing that is non-standard for my grafana is I'm caching the powerflow animation.

BuongiornoTexas avatar Mar 19 '24 05:03 BuongiornoTexas