Every log record now carries type ('http' for the request middleware
line, 'wrapper' for garmin execute() calls and forwarded wrapper.py
stderr, 'app' for everything else), class (Go type with package, or the
package/module for free functions), and method (the emitting Go/Python
function -- wrapper.py stamps it automatically, so its msg prefixes are
gone). msg is optional and omitted when empty; the redundant messages
('HTTP request', 'wrapper call', 'garmin wrapper stderr') are dropped,
the HTTP verb moves to http_method, source=garmin-wrapper is replaced by
type=wrapper, and the request_id middleware plumbing (applog
WithLogger/FromContext) is removed. applog.App(class, method) is the
tagging helper for app records.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
367 lines
16 KiB
Python
367 lines
16 KiB
Python
import json
|
|
import os
|
|
import time
|
|
import queue
|
|
import threading
|
|
from unittest.mock import MagicMock, patch
|
|
|
|
import pytest
|
|
|
|
import wrapper
|
|
|
|
|
|
@pytest.fixture(autouse=True)
|
|
def reset_state():
|
|
original_state = wrapper._auth_state
|
|
original_client = wrapper._client
|
|
original_startup_attempted = wrapper._startup_login_attempted
|
|
for q in (wrapper._mfa_input_queue, wrapper._login_result_queue):
|
|
while not q.empty():
|
|
try:
|
|
q.get_nowait()
|
|
except queue.Empty:
|
|
break
|
|
wrapper._startup_login_attempted = False
|
|
yield
|
|
wrapper._auth_state = original_state
|
|
wrapper._client = original_client
|
|
wrapper._startup_login_attempted = original_startup_attempted
|
|
|
|
|
|
def test_authenticate_success():
|
|
env = {"GARMIN_EMAIL": "test@example.com", "GARMIN_PASSWORD": "secret"}
|
|
with patch.dict("os.environ", env):
|
|
with patch("wrapper.Garmin") as mock_garmin_cls:
|
|
mock_garmin_cls.return_value = MagicMock()
|
|
resp = wrapper.dispatch({"id": 1, "cmd": "authenticate"})
|
|
assert resp == {"id": 1, "result": {"status": "success", "message": "Authenticated successfully."}}
|
|
assert wrapper._auth_state == "authenticated"
|
|
|
|
|
|
def test_authenticate_mfa_required():
|
|
env = {"GARMIN_EMAIL": "test@example.com", "GARMIN_PASSWORD": "secret"}
|
|
with patch.dict("os.environ", env):
|
|
with patch("wrapper.Garmin") as mock_garmin_cls:
|
|
mock_garmin_cls.return_value = MagicMock()
|
|
with patch.object(wrapper._login_result_queue, "get", side_effect=queue.Empty):
|
|
resp = wrapper.dispatch({"id": 2, "cmd": "authenticate"})
|
|
assert resp["result"]["status"] == "mfa_required"
|
|
assert wrapper._auth_state == "mfa_pending"
|
|
|
|
|
|
def test_authenticate_missing_credentials():
|
|
with patch.dict("os.environ", {}, clear=False):
|
|
os.environ.pop("GARMIN_EMAIL", None)
|
|
os.environ.pop("GARMIN_PASSWORD", None)
|
|
resp = wrapper.dispatch({"id": 3, "cmd": "authenticate"})
|
|
assert resp["result"]["status"] == "failed"
|
|
assert "GARMIN_EMAIL" in resp["result"]["message"]
|
|
|
|
|
|
def test_complete_mfa_success():
|
|
wrapper._auth_state = "mfa_pending"
|
|
wrapper._login_result_queue.put(("success", None))
|
|
resp = wrapper.dispatch({"id": 4, "cmd": "complete_mfa", "params": {"code": "123456"}})
|
|
assert resp == {
|
|
"id": 4,
|
|
"result": {"status": "success", "message": "MFA accepted. Authenticated successfully."},
|
|
}
|
|
assert wrapper._auth_state == "authenticated"
|
|
assert wrapper._mfa_input_queue.get_nowait() == "123456"
|
|
|
|
|
|
def test_complete_mfa_not_in_progress():
|
|
wrapper._auth_state = "unauthenticated"
|
|
resp = wrapper.dispatch({"id": 5, "cmd": "complete_mfa", "params": {"code": "123456"}})
|
|
assert resp["result"]["status"] == "failed"
|
|
assert "No MFA in progress" in resp["result"]["message"]
|
|
|
|
|
|
def test_call_dispatches_to_named_garminconnect_method():
|
|
wrapper._auth_state = "authenticated"
|
|
wrapper._client = MagicMock()
|
|
wrapper._client.get_activities_by_date.return_value = [{"activityId": "111"}]
|
|
|
|
resp = wrapper.dispatch({
|
|
"id": 6,
|
|
"cmd": "call",
|
|
"params": {
|
|
"method": "get_activities_by_date",
|
|
"args": {"startdate": "2026-07-01", "enddate": "2026-07-25"},
|
|
},
|
|
})
|
|
|
|
assert resp == {"id": 6, "result": [{"activityId": "111"}]}
|
|
wrapper._client.get_activities_by_date.assert_called_once_with(
|
|
startdate="2026-07-01", enddate="2026-07-25"
|
|
)
|
|
|
|
|
|
def test_call_unauthenticated_is_error():
|
|
# Explicitly absent GARMIN_EMAIL/PASSWORD: this now indirectly triggers
|
|
# the lazy _startup_login fallback (see _handle_call), which must
|
|
# return immediately with nothing to resume, leaving this the same
|
|
# "Not authenticated" error as before -- not dependent on whatever
|
|
# happens to be in the ambient shell environment.
|
|
wrapper._auth_state = "unauthenticated"
|
|
with patch.dict("os.environ", {}, clear=False):
|
|
os.environ.pop("GARMIN_EMAIL", None)
|
|
os.environ.pop("GARMIN_PASSWORD", None)
|
|
resp = wrapper.dispatch({
|
|
"id": 7, "cmd": "call", "params": {"method": "get_activities_by_date", "args": {}},
|
|
})
|
|
assert "error" in resp
|
|
assert "Not authenticated" in resp["error"]
|
|
|
|
|
|
def test_call_unknown_method_is_error():
|
|
wrapper._auth_state = "authenticated"
|
|
wrapper._client = MagicMock(spec=["get_activities_by_date"])
|
|
resp = wrapper.dispatch({
|
|
"id": 8, "cmd": "call", "params": {"method": "delete_everything", "args": {}},
|
|
})
|
|
assert resp["id"] == 8
|
|
assert "error" in resp
|
|
|
|
|
|
def test_call_propagates_garminconnect_exception_as_error():
|
|
wrapper._auth_state = "authenticated"
|
|
wrapper._client = MagicMock()
|
|
wrapper._client.get_activity_splits.side_effect = Exception("not found")
|
|
resp = wrapper.dispatch({
|
|
"id": 9, "cmd": "call", "params": {"method": "get_activity_splits", "args": {"activity_id": "999"}},
|
|
})
|
|
assert resp["id"] == 9
|
|
assert resp["error"] == "not found"
|
|
# Failure detail travels in the protocol so the Go side can log one
|
|
# complete structured record (no stderr correlation needed).
|
|
assert resp["error_type"] == "Exception"
|
|
assert "Exception: not found" in resp["traceback"]
|
|
assert "not_found" not in resp
|
|
|
|
|
|
def test_dispatch_unknown_cmd_is_error():
|
|
resp = wrapper.dispatch({"id": 10, "cmd": "not_a_real_cmd"})
|
|
assert resp["id"] == 10
|
|
assert "unknown cmd" in resp["error"]
|
|
|
|
|
|
def test_startup_login_success():
|
|
env = {"GARMIN_EMAIL": "test@example.com", "GARMIN_PASSWORD": "secret"}
|
|
with patch.dict("os.environ", env):
|
|
with patch("wrapper.Garmin") as mock_garmin_cls:
|
|
mock_garmin_cls.return_value = MagicMock()
|
|
wrapper._startup_login()
|
|
assert wrapper._auth_state == "authenticated"
|
|
|
|
|
|
def test_startup_login_missing_credentials_returns_immediately():
|
|
with patch.dict("os.environ", {}, clear=False):
|
|
os.environ.pop("GARMIN_EMAIL", None)
|
|
os.environ.pop("GARMIN_PASSWORD", None)
|
|
wrapper._auth_state = "unauthenticated"
|
|
wrapper._startup_login()
|
|
assert wrapper._auth_state == "unauthenticated"
|
|
assert wrapper._client is None
|
|
|
|
|
|
def test_startup_login_times_out_without_blocking():
|
|
# _startup_login now waits on its own private, function-local queue
|
|
# (never the shared wrapper._login_result_queue -- see the
|
|
# no-shared-queue-leakage test below), so forcing its timeout path
|
|
# means intercepting the queue.Queue() constructor it calls internally
|
|
# rather than patching a module-level queue object.
|
|
env = {"GARMIN_EMAIL": "test@example.com", "GARMIN_PASSWORD": "secret"}
|
|
with patch.dict("os.environ", env):
|
|
with patch("wrapper.Garmin") as mock_garmin_cls:
|
|
mock_garmin_cls.return_value = MagicMock()
|
|
with patch("wrapper.queue.Queue") as mock_queue_cls:
|
|
mock_queue_cls.return_value.get.side_effect = queue.Empty
|
|
# Should return promptly (bounded by the 10s timeout passed to
|
|
# queue.get, which is mocked here to raise immediately) rather
|
|
# than blocking main()'s stdin dispatch loop from starting.
|
|
wrapper._startup_login()
|
|
assert wrapper._auth_state == "unauthenticated"
|
|
|
|
|
|
def test_startup_login_does_not_leak_into_shared_authenticate_queue():
|
|
"""Regression test: _startup_login used to push its background thread's
|
|
result onto the same module-level _login_result_queue that
|
|
_handle_authenticate/_handle_complete_mfa share for the MFA handoff. A
|
|
startup login that was still in flight when a user's first explicit
|
|
'authenticate' call came in could have that call accidentally dequeue
|
|
the startup thread's stale result instead of its own fresh one.
|
|
_startup_login now uses its own private queue, so a still-in-flight
|
|
startup attempt can never interfere with a later authenticate() call."""
|
|
release = threading.Event()
|
|
|
|
env = {"GARMIN_EMAIL": "test@example.com", "GARMIN_PASSWORD": "secret"}
|
|
with patch.dict("os.environ", env):
|
|
with patch("wrapper.Garmin") as mock_garmin_cls:
|
|
# A startup login whose underlying garminconnect call is still
|
|
# blocked (simulating "slow to resolve") when _startup_login's
|
|
# own bounded wait (mocked to time out immediately, so this test
|
|
# doesn't need to sleep the real 10s) returns.
|
|
slow_client = MagicMock()
|
|
slow_client.login.side_effect = lambda **kwargs: release.wait(5)
|
|
mock_garmin_cls.return_value = slow_client
|
|
with patch("wrapper.queue.Queue") as mock_queue_cls:
|
|
mock_queue_cls.return_value.get.side_effect = queue.Empty
|
|
wrapper._startup_login()
|
|
|
|
assert wrapper._auth_state == "unauthenticated"
|
|
# Nothing from the still-in-flight startup attempt ever touches the
|
|
# shared queue that authenticate()/complete_mfa() rely on.
|
|
assert wrapper._login_result_queue.empty()
|
|
|
|
release.set() # let the stale startup thread finish harmlessly in the background
|
|
|
|
# A fresh, unrelated authenticate() call must get its own result, not
|
|
# anything left over from the startup attempt above.
|
|
with patch.dict("os.environ", env):
|
|
with patch("wrapper.Garmin") as mock_garmin_cls2:
|
|
mock_garmin_cls2.return_value = MagicMock()
|
|
resp = wrapper.dispatch({"id": 20, "cmd": "authenticate"})
|
|
|
|
assert resp == {"id": 20, "result": {"status": "success", "message": "Authenticated successfully."}}
|
|
assert wrapper._auth_state == "authenticated"
|
|
|
|
|
|
def test_call_triggers_startup_login_lazily_on_first_call():
|
|
"""A data 'call' with no prior explicit authenticate on this subprocess
|
|
-- e.g. "Sync now" reaching an already-connected user's client right
|
|
after a backend restart -- gets exactly one lazy attempt to silently
|
|
resume a cached tokenstore session before giving up."""
|
|
wrapper._auth_state = "unauthenticated"
|
|
wrapper._client = MagicMock()
|
|
wrapper._client.get_activities_by_date.return_value = []
|
|
|
|
def fake_startup_login():
|
|
wrapper._auth_state = "authenticated"
|
|
|
|
with patch("wrapper._startup_login", side_effect=fake_startup_login) as mock_startup:
|
|
resp = wrapper.dispatch({
|
|
"id": 30, "cmd": "call", "params": {"method": "get_activities_by_date", "args": {}},
|
|
})
|
|
|
|
mock_startup.assert_called_once()
|
|
assert resp == {"id": 30, "result": []}
|
|
|
|
|
|
def test_call_does_not_retry_startup_login_after_first_attempt():
|
|
"""If the lazy startup-login attempt doesn't actually authenticate, a
|
|
second 'call' must not try it again -- one attempt per subprocess
|
|
lifetime, not once per call."""
|
|
wrapper._auth_state = "unauthenticated"
|
|
|
|
with patch("wrapper._startup_login") as mock_startup: # no-op: leaves state unauthenticated
|
|
wrapper.dispatch({"id": 31, "cmd": "call", "params": {"method": "x", "args": {}}})
|
|
wrapper.dispatch({"id": 32, "cmd": "call", "params": {"method": "x", "args": {}}})
|
|
|
|
mock_startup.assert_called_once()
|
|
|
|
|
|
def test_authenticate_prevents_later_lazy_startup_login():
|
|
"""Once authenticate has been explicitly called (regardless of
|
|
outcome), a later 'call' must never fall back to _startup_login -- that
|
|
would either duplicate a login authenticate already did, or waste an
|
|
extra hit against Garmin after a failure."""
|
|
env = {"GARMIN_EMAIL": "test@example.com", "GARMIN_PASSWORD": "secret"}
|
|
with patch.dict("os.environ", env):
|
|
with patch("wrapper.Garmin") as mock_garmin_cls:
|
|
mock_garmin_cls.return_value = MagicMock()
|
|
wrapper.dispatch({"id": 33, "cmd": "authenticate"})
|
|
|
|
wrapper._auth_state = "unauthenticated" # simulate a later, separate call finding no session
|
|
with patch("wrapper._startup_login") as mock_startup:
|
|
wrapper.dispatch({"id": 34, "cmd": "call", "params": {"method": "x", "args": {}}})
|
|
|
|
mock_startup.assert_not_called()
|
|
|
|
|
|
def test_call_marks_not_found_error_specifically():
|
|
from garminconnect import GarminConnectNotFoundError
|
|
|
|
wrapper._auth_state = "authenticated"
|
|
wrapper._client = MagicMock()
|
|
wrapper._client.get_workout_by_id.side_effect = GarminConnectNotFoundError("API Error 404")
|
|
resp = wrapper.dispatch({
|
|
"id": 11, "cmd": "call", "params": {"method": "get_workout_by_id", "args": {"workout_id": "999"}},
|
|
})
|
|
assert resp["id"] == 11
|
|
assert resp["error"] == "API Error 404"
|
|
assert resp["not_found"] is True
|
|
assert resp["error_type"] == "GarminConnectNotFoundError"
|
|
|
|
|
|
def test_call_does_not_mark_other_errors_as_not_found():
|
|
wrapper._auth_state = "authenticated"
|
|
wrapper._client = MagicMock()
|
|
wrapper._client.get_workout_by_id.side_effect = Exception("rate limited")
|
|
resp = wrapper.dispatch({
|
|
"id": 12, "cmd": "call", "params": {"method": "get_workout_by_id", "args": {"workout_id": "999"}},
|
|
})
|
|
assert resp["id"] == 12
|
|
assert resp["error"] == "rate limited"
|
|
assert "not_found" not in resp
|
|
|
|
|
|
def test_startup_login_late_success_flips_auth_state_for_later_calls():
|
|
"""A tokenstore resume that outlives the 10s wait must still recover
|
|
the subprocess: the background thread itself flips _auth_state on
|
|
success, so the next `call` command passes the auth check without an
|
|
explicit authenticate."""
|
|
env = {"GARMIN_EMAIL": "test@example.com", "GARMIN_PASSWORD": "secret"}
|
|
release = threading.Event()
|
|
mock_client = MagicMock()
|
|
mock_client.login.side_effect = lambda **kwargs: release.wait(timeout=5)
|
|
wrapper._auth_state = "unauthenticated"
|
|
with patch.dict("os.environ", env):
|
|
with patch("wrapper.Garmin", return_value=mock_client):
|
|
with patch("wrapper.queue.Queue") as mock_queue_cls:
|
|
# Simulate the 10s timeout: the reader gives up immediately,
|
|
# while the (still-blocked) login thread keeps running.
|
|
mock_queue_cls.return_value.get.side_effect = queue.Empty
|
|
wrapper._startup_login()
|
|
assert wrapper._auth_state == "unauthenticated"
|
|
|
|
release.set() # the slow login now completes, after the timeout
|
|
for _ in range(100):
|
|
if wrapper._auth_state == "authenticated":
|
|
break
|
|
time.sleep(0.01)
|
|
assert wrapper._auth_state == "authenticated"
|
|
|
|
|
|
def test_startup_login_late_success_never_overrides_explicit_auth_flow():
|
|
"""If an explicit authenticate/MFA flow moved the state while the
|
|
startup resume was still in flight, the late success must not clobber
|
|
it -- the explicit flow owns the state once it has moved it."""
|
|
env = {"GARMIN_EMAIL": "test@example.com", "GARMIN_PASSWORD": "secret"}
|
|
release = threading.Event()
|
|
mock_client = MagicMock()
|
|
mock_client.login.side_effect = lambda **kwargs: release.wait(timeout=5)
|
|
wrapper._auth_state = "unauthenticated"
|
|
with patch.dict("os.environ", env):
|
|
with patch("wrapper.Garmin", return_value=mock_client):
|
|
with patch("wrapper.queue.Queue") as mock_queue_cls:
|
|
mock_queue_cls.return_value.get.side_effect = queue.Empty
|
|
wrapper._startup_login()
|
|
|
|
wrapper._auth_state = "mfa_pending" # an explicit flow took over meanwhile
|
|
release.set()
|
|
time.sleep(0.2) # give the thread ample time to (wrongly) flip it
|
|
assert wrapper._auth_state == "mfa_pending"
|
|
|
|
|
|
def test_log_stamps_emitting_method(capsys):
|
|
"""Every wrapper log line carries the emitting function as "method" --
|
|
the Go side forwards it into the unified log schema."""
|
|
|
|
def some_emitter():
|
|
wrapper._log("info", "hello", extra=1)
|
|
|
|
some_emitter()
|
|
entry = json.loads(capsys.readouterr().err.strip())
|
|
assert entry == {"level": "info", "msg": "hello", "method": "some_emitter", "extra": 1}
|