Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 9 additions & 0 deletions research/caldav-probe/.env.example
Original file line number Diff line number Diff line change
@@ -0,0 +1,9 @@
# Copy to .env and fill in. .env is gitignored.
TEST_SERVER_HOST = "mail.thundermail.com"
TEST_ACCT_1_USERNAME = "username@thundermail.com"
TEST_ACCT_1_PASSWORD = "app password"

# Optional overrides:
# CALDAV_PATH = "/dav/cal/"
# PROBE_INTERVAL_SECONDS = 60
# PROBE_TIMEOUT_SECONDS = 30
3 changes: 3 additions & 0 deletions research/caldav-probe/.gitignore
Original file line number Diff line number Diff line change
@@ -0,0 +1,3 @@
# Local credentials and captured probe data -- never commit these.
.env
*.jsonl
47 changes: 47 additions & 0 deletions research/caldav-probe/README.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,47 @@
# CalDAV intermittent-connection probe

Diagnostic tooling for the intermittent *"failed to connect to server
mail.thundermail.com"* calendar errors that Thunderbird desktop users
occasionally see. A once-a-day integration test can't catch a failure that
happens roughly once every 2–3 hours, so this polls the CalDAV endpoint
frequently and records exactly which connection phase fails, then correlates any
failures against Stalwart's CloudWatch logs.

The point is to answer one question: **is the root cause Stalwart, the
network/edge, or the Thunderbird client?** The root cause may well be unrelated
to Stalwart — this is how we find out for sure.

## Contents

- `probe.py` — polls `https://<host>/dav/cal/` on an interval, timing each phase
(DNS → TCP → TLS → CalDAV `PROPFIND`) and classifying failures
(`DNS_FAIL`, `TCP_FAIL`, `TLS_FAIL`, `AUTH_FAIL`, `HTTP_5XX`, `TIMEOUT`,
`DAV_ERROR`, `OK`). Standard library only — no install step. Appends one JSON
line per attempt to `probe-YYYYMMDD.jsonl`.
- `correlate.py` — reads the JSONL, finds failures, and queries the Stalwart
CloudWatch log group in a window around each failure, filtered to this
machine's public IP.

## Usage

```bash
cd research/caldav-probe
cp .env.example .env # then fill in TEST_ACCT_1 credentials

# Run the probe (leave it going for several hours / overnight):
python3 probe.py

# Later, correlate failures against Stalwart logs (needs AWS SSO to legacy):
AWS_PROFILE=mzla-legacy python3 correlate.py probe-*.jsonl
```

## Reading the results

| Probe result | Stalwart logs | Verdict |
|---|---|---|
| Fails | error logged at our IP/time | **Server-side (Stalwart)** |
| `TLS_FAIL` (cert) | — | Cert / edge |
| `TCP_FAIL` / `TIMEOUT` | silent | **Network / edge / load balancer** |
| Always `OK` | — | **Client-side (Thunderbird)** or a layer not probed |

`.env` and the `*.jsonl` capture files are gitignored.
129 changes: 129 additions & 0 deletions research/caldav-probe/correlate.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,129 @@
#!/usr/bin/env python3
"""Correlate CalDAV probe failures against Stalwart's CloudWatch logs.

Reads the JSONL emitted by probe.py, finds every non-OK attempt, and for each one
queries the Stalwart CloudWatch log group in a window around the failure timestamp,
filtered to this machine's public IP. The report tells you, for each probe failure,
exactly what the server logged at that moment -- or that it logged nothing at all.

probe fails + server logged an error -> server-side (Stalwart)
probe fails (TCP/TLS/timeout) + silent -> network / edge / load balancer
probe never fails but users still do -> client-side (Thunderbird desktop)

Requires the AWS CLI, authenticated to the legacy profile:

AWS_PROFILE=mzla-legacy python3 correlate.py probe-YYYYMMDD.jsonl

Options:
--log-group CloudWatch log group (default: /tb/prod/stalwart)
--window seconds each side of the failure to search (default: 90)
--profile AWS profile to pass to the CLI (default: $AWS_PROFILE or mzla-legacy)
"""

from __future__ import annotations

import argparse
import json
import subprocess
import sys
from datetime import datetime, timezone
from pathlib import Path


def parse_ts(ts: str) -> int:
"""ISO 'YYYY-MM-DDTHH:MM:SSZ' -> epoch milliseconds."""
dt = datetime.strptime(ts, '%Y-%m-%dT%H:%M:%SZ').replace(tzinfo=timezone.utc)
return int(dt.timestamp() * 1000)


def query_logs(log_group: str, start_ms: int, end_ms: int, ip: str | None,
profile: str) -> list[dict]:
cmd = [
'aws', 'logs', 'filter-log-events',
'--log-group-name', log_group,
'--start-time', str(start_ms),
'--end-time', str(end_ms),
'--limit', '50',
'--output', 'json',
'--profile', profile,
]
if ip:
# Filter to events mentioning our probe's public IP so we only see the
# server's view of *our* connections.
cmd += ['--filter-pattern', f'"{ip}"']
proc = subprocess.run(cmd, capture_output=True, text=True)
if proc.returncode != 0:
print(f' ! aws query failed: {proc.stderr.strip()}', file=sys.stderr)
return []
return json.loads(proc.stdout or '{}').get('events', [])


def main() -> int:
ap = argparse.ArgumentParser(description=__doc__,
formatter_class=argparse.RawDescriptionHelpFormatter)
ap.add_argument('jsonl', nargs='+', help='probe-*.jsonl file(s) to analyze')
ap.add_argument('--log-group', default='/tb/prod/stalwart')
ap.add_argument('--window', type=int, default=90, help='seconds each side of failure')
ap.add_argument('--profile', default=None)
args = ap.parse_args()

import os
profile = args.profile or os.environ.get('AWS_PROFILE') or 'mzla-legacy'

failures = []
total = 0
for path_str in args.jsonl:
path = Path(path_str)
if not path.exists():
print(f'skipping missing file: {path}', file=sys.stderr)
continue
for line in path.read_text().splitlines():
line = line.strip()
if not line:
continue
rec = json.loads(line)
total += 1
if rec.get('outcome') != 'OK':
failures.append(rec)

print(f'Analyzed {total} probe attempts, {len(failures)} failures.\n')
if not failures:
print('No probe failures recorded -- if users still report errors, the '
'issue is likely client-side (Thunderbird desktop) or in a layer this '
'probe does not exercise.')
return 0

window_ms = args.window * 1000
server_confirmed = 0
server_silent = 0

for rec in failures:
ts = rec['ts']
ip = rec.get('public_ip')
print('=' * 78)
print(f'FAILURE {ts} outcome={rec["outcome"]} status={rec.get("http_status")}')
print(f' error : {rec.get("error")}')
print(f' phases: {rec.get("phases")} total={rec.get("total_ms")}ms probe_ip={ip}')
center = parse_ts(ts)
events = query_logs(args.log_group, center - window_ms, center + window_ms, ip, profile)
if not events:
server_silent += 1
print(f' SERVER SILENT: no {args.log_group} events for {ip} in '
f'+/-{args.window}s window --> points AWAY from Stalwart '
f'(network / edge / client).')
else:
server_confirmed += 1
print(f' SERVER LOGGED {len(events)} event(s) in window:')
for ev in events:
ev_ts = datetime.fromtimestamp(ev['timestamp'] / 1000, timezone.utc)
print(f' {ev_ts:%H:%M:%SZ} {ev["message"].strip()[:220]}')
print()

print('=' * 78)
print(f'SUMMARY: {len(failures)} failures | server-logged: {server_confirmed} | '
f'server-silent: {server_silent}')
return 0


if __name__ == '__main__':
raise SystemExit(main())
Loading
Loading