Frequent gaps in InfluxDB and errors in pypowerwall

jgleigh commented 3 months ago

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 commented 3 months ago

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 commented 3 months ago

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.

jasonacox commented 3 months ago

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.

jgleigh commented 3 months ago

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

jasonacox commented 3 months ago

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.

jgleigh commented 3 months ago

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.

jasonacox commented 3 months ago

@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.

BuongiornoTexas commented 3 months ago

@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.

jasonacox commented 3 months ago

@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.

BuongiornoTexas commented 3 months ago

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

jasonacox commented 3 months ago

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

BuongiornoTexas commented 3 months ago

| 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.

jgleigh commented 3 months ago

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

jasonacox commented 3 months ago

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

jgleigh commented 3 months ago

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.

BuongiornoTexas commented 3 months ago

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

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

jasonacox commented 3 months ago

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!!! 🙏

BuongiornoTexas commented 3 months ago

| 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.

jasonacox commented 3 months ago

Agree.

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

BuongiornoTexas commented 3 months ago

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.

jgleigh commented 3 months ago

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

BuongiornoTexas commented 3 months ago

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']}

jgleigh commented 3 months ago

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

BuongiornoTexas commented 3 months ago

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

jasonacox commented 3 months ago

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 commented 3 months ago

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

jgleigh commented 3 months ago

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 commented 3 months ago

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.

jasonacox commented 3 months ago

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

BuongiornoTexas commented 3 months ago

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.

jasonacox commented 3 months ago

a lot of the issues seemed to be with the powerflow animation

It definitely exercises a lot of the APIs. You can bypass Grafana by going direct to the proxy to see the power flow: http://localhost:8675/example.html

BuongiornoTexas commented 3 months ago

The animation by pypowerwall:8675 has been consistently fine. No idea why it is a problem in the grafana frame.

The updated container seems to have improved the pypowerwall errors considerably - at least for the last 30 minutes. Will report back tomorrow with more data.

jgleigh commented 3 months ago

I have PW_BROWSER_CACHE=86400 set in my pypowerwall.env file so the animation is fully cached.

BuongiornoTexas commented 3 months ago

PW_BROWSER_CACHE=86400 matches my setting. And GF_SECURITY_ALLOW_EMBEDDING in grafana.env? (Changing this to false improved things - I don't why it should, but it did).

jgleigh commented 3 months ago

GF_SECURITY_ALLOW_EMBEDDING is true for me, but it's been like that for a year now.

https://github.com/jasonacox/Powerwall-Dashboard/issues/219

BuongiornoTexas commented 3 months ago

GF_SECURITY_ALLOW_EMBEDDING is true for me,

I wish I could say I was surprised to hear this (and I'm glad it is working well for you). Like I say, I can't see any reason why this makes a difference for me.

The only things I can think of that may be a bit different from standard in my setup are:

I use pwdusage to track my ToU. But this is coming in through a separate container which doesn't talk to pypowerwall.
Both I and my partner often have the dashboard open at the sametime (sometimes as many as three open dashboards if we have mobile or tablet viewing). Again, this shouldn't make a difference, as grafana is designed for interaction by many times more users!

jgleigh commented 3 months ago

A few errors, but no dropped data. Been running the newest version since 3/18.

2024-03-20 07:22:55 03/20/2024 07:22:55 AM [urllib3.connectionpool] [WARNING] Connection pool is full, discarding connection: 192.168.1.6. Connection pool size: 10
2024-03-20 07:23:25 03/20/2024 07:23:25 AM [urllib3.connectionpool] [WARNING] Connection pool is full, discarding connection: 192.168.1.6. Connection pool size: 10
2024-03-20 18:02:33 03/20/2024 06:02:33 PM [proxy] [ERROR] Socket broken sending API response to client [doGET]
2024-03-20 18:03:37 03/20/2024 06:03:37 PM [proxy] [ERROR] Socket broken sending API response to client [doGET]

jgleigh commented 3 months ago

Yet another deprecated API call: 2024-03-23 07:05:33 03/23/2024 07:05:33 AM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/customer/registration

Running firmware 24.4.0 now.

jasonacox commented 3 months ago

Thanks @jgleigh - Just tested and see the same. It doesn't appear to be an API that we use. Are you seeing it repeat in your logs?

jgleigh commented 3 months ago

Just occasionally. It popped up once today when upgrading to 4.2.0.

2024-03-23 08:34:50 03/23/2024 08:34:50 AM [proxy] [INFO] pyPowerwall [0.7.12] Proxy Server [t44] - HTTP Port 8675
2024-03-23 08:34:50 03/23/2024 08:34:50 AM [proxy] [INFO] pyPowerwall Proxy Started
2024-03-23 08:34:51 03/23/2024 08:34:51 AM [proxy] [INFO] pyPowerwall Proxy Server - Local Mode
2024-03-23 08:34:51 03/23/2024 08:34:51 AM [proxy] [INFO] Connected to Energy Gateway 192.168.1.6 (Home Energy Gateway)
2024-03-23 08:34:55 03/23/2024 08:34:55 AM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/devices/vitals
2024-03-23 08:34:55 03/23/2024 08:34:55 AM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/devices/vitals
2024-03-23 08:34:55 03/23/2024 08:34:55 AM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/devices/vitals
2024-03-23 08:34:55 03/23/2024 08:34:55 AM [pypowerwall] [ERROR] Firmware 240400 detected - Does not support vitals API - disabling.
2024-03-23 08:34:55 03/23/2024 08:34:55 AM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/devices/vitals
2024-03-23 08:34:55 03/23/2024 08:34:55 AM [pypowerwall] [ERROR] Firmware 240400 detected - Does not support vitals API - disabling.
2024-03-23 08:34:55 03/23/2024 08:34:55 AM [pypowerwall] [ERROR] Firmware 240400 detected - Does not support vitals API - disabling.
2024-03-23 08:34:55 03/23/2024 08:34:55 AM [pypowerwall] [ERROR] Firmware 240400 detected - Does not support vitals API - disabling.
2024-03-23 08:35:09 03/23/2024 08:35:09 AM [pypowerwall] [ERROR] 404 Powerwall API not found at https://192.168.1.6/api/customer/registration

jasonacox commented 3 months ago

Ok, that may be from the power flow animation startup.

jgleigh commented 3 months ago

I just opened the Dashboard and checked the logs again. Second instance of that same message, so looks like you're on the right path.

jgleigh commented 1 month ago

Sure would be nice to have all the old alerts available. No idea what's causing my Gateway to reboot all the time. Today it actually took down the inverters for a few minutes. No alerts that indicated anything was wrong.

jasonacox commented 1 month ago

HI @jgleigh - I would recommend contacting Tesla to raise the issue. Additionally, if you really want to get to the alerts, you could use the tedapi approach (research here). If you connect your computer to your Gateway WiFi, you can run the script here: https://github.com/jasonacox/pypowerwall/blob/main/tools/tedapi/status.py

jgleigh commented 1 month ago

Interesting. I didn't even think of that. Do you know if the Tesla One displays the same information (alerts mostly)? I've used it once when it first got released.

jasonacox commented 1 month ago

I suspect it might didn't find it. The payload you get back from tedapi will have things like this which should look familiar:

        "alerts": {
            "active": [
                "SystemConnectedToGrid",
                "FWUpdateSucceeded",
                "GridCodesWrite",
                "PodCommissionTime"
            ]
        },

jgleigh commented 1 month ago

Tesla One does not display the alerts (at least that I could find). It's got access to a lot of installer level stuff, but I didn't see that low level stuff in there. I'll have to mess around with the tedapi when I get some time.

jgleigh commented 1 month ago

@jasonacox Any way for the proxy (or Dashboard) to pull the data from two IP addresses (Ethernet primary, WiFi secondary)? I just turned the WiFi back on to see if they're both dropping out when the Gateway becomes unresponsive or if it's isolated to one interface.

jasonacox commented 1 month ago

Interesting idea. That would require a code change in pypowerwall (logic: detct failure, change, reconnect), but you may also be able to set up a reverse proxy load balancer that create a virtual endpoint for pypowerwall to use. If anyone has any ideas, let us know.

jgleigh commented 1 month ago

Epic failure so far...I re-enabled WiFi and two hours later the Gateway locked up and shutdown my whole array. Didn't notice until just now. :(

I'm changing the proxy to WiFi in case I have an Ethernet cabling issue (as opposed to a Gateway network controller issue). I feel like Samuel L Jackson in Jurassic Park!

jasonacox / Powerwall-Dashboard

Frequent gaps in InfluxDB and errors in pypowerwall #449