Private
Public Access
Fix WNS push 400s and improve push failure logging (#56)
WNS (Windows/Edge push) has required an X-WNS-Cache-Policy header since April 2024; the production venv was likely still on the old pywebpush 2.0.x installed when the app was first deployed, which predates the library's fix. Floored the dependency at 2.4.0 (current latest) so the next deploy picks it up. Also logs response body and headers on any non-410/404 push failure, not just body text -- WNS's own 400s carry their actual reason in a header, which the old body-only logging would still have missed. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
This commit is contained in:
@@ -95,4 +95,17 @@ async def send_push_to_user(db: AsyncSession, user_id: uuid.UUID, payload: dict)
|
||||
)
|
||||
await db.commit()
|
||||
else:
|
||||
logger.warning("Push delivery failed for %s: %s", subscription.id, exc)
|
||||
# #56: WNS's own 400s carry the actual reason in a response
|
||||
# *header* ("Ttl value conflicts with X-WNS-Cache-Policy"),
|
||||
# not the body -- pywebpush's own exception message only
|
||||
# ever surfaces the body, so that specific bug still would
|
||||
# have needed a full journalctl+DB-dump investigation to
|
||||
# diagnose even with a body-only log line. Logging headers
|
||||
# too is the difference between "something is broken" and
|
||||
# this log line alone being enough next time, for any push
|
||||
# provider's failure, not just WNS's.
|
||||
response = exc.response
|
||||
detail = ""
|
||||
if response is not None:
|
||||
detail = f" | response: {response.text!r} | headers: {dict(response.headers)!r}"
|
||||
logger.warning("Push delivery failed for %s: %s%s", subscription.id, exc, detail)
|
||||
|
||||
@@ -15,7 +15,14 @@ dependencies = [
|
||||
"pydantic-settings>=2.6",
|
||||
"argon2-cffi>=23.1",
|
||||
"itsdangerous>=2.2",
|
||||
"pywebpush>=2.0",
|
||||
# #56: >=2.0 let the production venv sit on an old 2.0.x that predates
|
||||
# the fix for web-push-libs/pywebpush#162 -- WNS (Windows/Edge push)
|
||||
# has required an X-WNS-Cache-Policy header since April 2024, and an
|
||||
# old pywebpush that never sends it gets a bodyless 400 on every send.
|
||||
# Floored at the actual latest release (merged/shipped 2026-01 through
|
||||
# 2026-08) rather than pinning to whichever exact point release first
|
||||
# included the fix, since that wasn't independently confirmed.
|
||||
"pywebpush>=2.4.0",
|
||||
"redis>=5.0",
|
||||
"httpx>=0.27",
|
||||
"gunicorn>=23.0",
|
||||
|
||||
@@ -218,3 +218,57 @@ def test_expired_subscription_is_cleaned_up(ws_client, monkeypatch):
|
||||
assert ws.receive_json()["type"] == "joined"
|
||||
|
||||
assert _fetch_subscriptions(ws_client, bob["id"]) == []
|
||||
|
||||
|
||||
def test_non_gone_push_failure_logs_response_detail_and_keeps_subscription(ws_client, monkeypatch):
|
||||
# #56: a real WNS 400 carries its actual reason in a response *header*,
|
||||
# not the body -- str(WebPushException) alone (what used to be logged)
|
||||
# would have shown neither, which is exactly why that bug took a DB
|
||||
# dump + journalctl correlation to diagnose instead of one log line.
|
||||
class FakeResponse:
|
||||
status_code = 400
|
||||
text = "Bad Request"
|
||||
headers = {"X-WNS-Error-Description": "Ttl value conflicts with X-WNS-Cache-Policy"}
|
||||
|
||||
def fake_webpush(**kwargs):
|
||||
raise WebPushException("Push failed: 400 Bad Request", response=FakeResponse())
|
||||
|
||||
monkeypatch.setattr("app.services.push_service.webpush", fake_webpush)
|
||||
|
||||
# caplog's handler capture isn't reliable here -- the actual push send
|
||||
# (and its logger.warning call) runs on ws_client_factory's background
|
||||
# portal thread (see that fixture's own docstring), not pytest's main
|
||||
# thread. Patching the logger call directly sidesteps that instead of
|
||||
# depending on cross-thread log propagation.
|
||||
calls = []
|
||||
monkeypatch.setattr(
|
||||
"app.services.push_service.logger.warning",
|
||||
lambda msg, *args: calls.append(msg % args),
|
||||
)
|
||||
|
||||
alice = _register_ws(ws_client, _unique("alice"))
|
||||
room = ws_client.post("/api/rooms", json={"name": _unique("general")}).json()
|
||||
|
||||
bob = _register_ws(ws_client, _unique("bob"))
|
||||
ws_client.post(f"/api/rooms/{room['id']}/join")
|
||||
ws_client.post("/api/push/subscribe", json=_subscription_payload(_unique("bob")))
|
||||
assert len(_fetch_subscriptions(ws_client, bob["id"])) == 1
|
||||
|
||||
ws_client.post(
|
||||
"/api/auth/login", json={"username_or_email": alice["username"], "password": "password123"}
|
||||
)
|
||||
with ws_client.websocket_connect("/ws/chat") as ws:
|
||||
ws.send_json({"type": "join", "room_id": room["id"]})
|
||||
assert ws.receive_json()["type"] == "joined"
|
||||
ws.send_json({"type": "message", "room_id": room["id"], "content": "hello"})
|
||||
assert ws.receive_json()["type"] == "message"
|
||||
ws.send_json({"type": "join", "room_id": room["id"]})
|
||||
assert ws.receive_json()["type"] == "joined"
|
||||
|
||||
# A 400 isn't "gone" (404/410) -- the subscription stays, unlike the
|
||||
# expired-subscription case above.
|
||||
assert len(_fetch_subscriptions(ws_client, bob["id"])) == 1
|
||||
|
||||
assert len(calls) == 1
|
||||
assert "Bad Request" in calls[0]
|
||||
assert "Ttl value conflicts with X-WNS-Cache-Policy" in calls[0]
|
||||
|
||||
Reference in New Issue
Block a user