Thread Lock messages at INFO level

[JohnJ9ml]

pypowerwall 0.12.12:

I started noticing these this morning before I pointed two clients at the same proxy:

I'm getting thread lock INFO level diags from the docker logs:

05/23/2025 10:08:42 AM [pypowerwall.tedapi.pypowerwall_tedapi] [DEBUG] -- tedapi: Request for /api/meters/aggregates 05/23/2025 10:08:42 AM [pypowerwall.tedapi] [DEBUG] Using Cached Payload 05/23/2025 10:08:42 AM [pypowerwall.tedapi] [DEBUG] Using Cached Payload 05/23/2025 10:08:42 AM [pypowerwall.tedapi] [DEBUG] Using Cached Payload 05/23/2025 10:08:42 AM [pypowerwall.tedapi] [DEBUG] Using Cached Payload 05/23/2025 10:08:42 AM [pypowerwall.tedapi] [DEBUG] Using Cached Payload 05/23/2025 10:08:42 AM [pypowerwall.tedapi] [DEBUG] Using Cached Payload 05/23/2025 10:08:42 AM [proxy] [DEBUG] 192.168.1.37 "GET /pw/strings HTTP/1.1" 200 - 05/23/2025 10:08:42 AM [pypowerwall.tedapi] [DEBUG] Using Cached Payload 05/23/2025 10:08:42 AM [pypowerwall.tedapi] [DEBUG] Using Cached Payload 05/23/2025 10:08:42 AM [pypowerwall.tedapi] [DEBUG] Using Cached Components 05/23/2025 10:08:42 AM [pypowerwall.tedapi] [DEBUG] Using Cached Payload 05/23/2025 10:08:44 AM [proxy] [DEBUG] 192.168.1.111 "GET /fans/pw HTTP/1.1" 200 - 05/23/2025 10:08:44 AM [proxy] [DEBUG] 192.168.1.111 "GET /aggregates HTTP/1.1" 200 - 05/23/2025 10:08:44 AM [pypowerwall.tedapi] [DEBUG] Get controller data from Powerwall 05/23/2025 10:08:44 AM [proxy] [DEBUG] 192.168.1.111 "GET /soe HTTP/1.1" 200 - 05/23/2025 10:08:44 AM [pypowerwall.tedapi.pypowerwall_tedapi] [DEBUG] -- tedapi: Request for /api/meters/aggregates 05/23/2025 10:08:44 AM [proxy] [DEBUG] 192.168.1.111 "GET /strings HTTP/1.1" 200 - 05/23/2025 10:08:45 AM [pypowerwall.tedapi.pypowerwall_tedapi] [DEBUG] -- tedapi: Request for /api/system_status/soe 05/23/2025 10:08:45 AM [proxy] [DEBUG] 192.168.1.111 "GET /alerts/pw HTTP/1.1" 200 - 05/23/2025 10:08:45 AM [pypowerwall.tedapi] [DEBUG] Get Configuration from Powerwall 05/23/2025 10:08:45 AM [proxy] [DEBUG] 192.168.1.111 "GET /temps/pw HTTP/1.1" 200 - 05/23/2025 10:08:45 AM [pypowerwall.tedapi] [DEBUG] Get Status from Powerwall 05/23/2025 10:08:45 AM [proxy] [DEBUG] 192.168.1.111 "GET /freq HTTP/1.1" 200 - 05/23/2025 10:08:45 AM [pypowerwall.tedapi.pypowerwall_tedapi] [DEBUG] -- tedapi: Request for /api/system_status 05/23/2025 10:08:45 AM [proxy] [DEBUG] 192.168.1.111 "GET /pod HTTP/1.1" 200 - 05/23/2025 10:08:45 AM [pypowerwall.tedapi.pypowerwall_tedapi] [DEBUG] -- tedapi: Request for /api/system_status 05/23/2025 10:08:45 AM [pypowerwall.api_lock] [INFO] Timeout for <locked _thread.lock object at 0x7ffedd488fc0> 05/23/2025 10:08:45 AM [pypowerwall.api_lock] [INFO] Timeout for <locked _thread.lock object at 0x7ffedd4895c0> 05/23/2025 10:08:45 AM [pypowerwall.api_lock] [INFO] Timeout for <locked _thread.lock object at 0x7ffedd4895c0> 05/23/2025 10:08:45 AM [pypowerwall.api_lock] [INFO] Timeout for <locked _thread.lock object at 0x7ffedd488fc0> 05/23/2025 10:08:45 AM [pypowerwall.api_lock] [INFO] Timeout for <locked _thread.lock object at 0x7ffedd488fc0> 05/23/2025 10:08:45 AM [pypowerwall.tedapi] [DEBUG] Response Code: 200

I don't know that these are new, but I wasn't noticing them before today. I've no idea for certain that they aren't also tied to behaviors from the PW firmware upgrade to 25.10.4 either, but I thought I'd mention them.

Since they're at INFO level, I'm not sure they're considered issues, so I thought I'd post here first.