try and create a cache for layer pushing again

This commit is contained in:
Evan Jarrett
2025-11-24 13:25:24 -06:00
parent ecf84ed8bc
commit fb7ddd0d53
14 changed files with 1429 additions and 120 deletions
+1 -1
View File
@@ -1,6 +1,6 @@
when:
- event: ["push"]
branch: ["main", "test"]
branch: ["*"]
- event: ["pull_request"]
branch: ["main"]
+1 -1
View File
@@ -388,7 +388,7 @@ func serveRegistry(cmd *cobra.Command, args []string) error {
mainRouter.Get("/auth/oauth/callback", oauthServer.ServeCallback)
// OAuth client metadata endpoint
mainRouter.Get("/client-metadata.json", func(w http.ResponseWriter, r *http.Request) {
mainRouter.Get("/oauth-client-metadata.json", func(w http.ResponseWriter, r *http.Request) {
config := oauthClientApp.Config
metadata := config.ClientMetadata()
+532
View File
@@ -0,0 +1,532 @@
# Bluesky PDS OAuth Provider Clock Tolerance Bug Report
**Status:** Confirmed Bug
**Severity:** High (blocks OAuth authentication)
**Affects:** `@atproto/oauth-provider@0.13.4` (and likely earlier versions)
**Date Identified:** 2025-11-18
**Reported By:** ATCR Project
---
## Executive Summary
The Bluesky PDS OAuth provider (`@atproto/oauth-provider`) incorrectly rejects valid client assertion JWTs when the client's system clock is even milliseconds ahead of the PDS server clock. This occurs because the `jose` library's `jwtVerify` function is called with `maxTokenAge` (which triggers `iat` validation) but without setting `clockTolerance`, causing it to default to 0 seconds.
**Impact:** OAuth authentication fails for any client with normal clock drift ahead of the PDS, violating the ATProto OAuth specification and industry standards (FAPI 2.0, RFC 9068).
**Fix:** Add `clockTolerance: 30` (or 60) parameter to the `jwtVerify` call in `client.ts`.
---
## Problem Description
### Observed Behavior
OAuth client assertion validation fails with the error:
```
InvalidClientError: Validation of "client_assertion" failed: "iat" claim timestamp check failed (it should be in the past)
```
This occurs even when:
- Both systems have proper NTP synchronization
- Clock drift is minimal (observed: 115 milliseconds)
- The drift is well within industry-standard tolerances (30-60 seconds)
### Root Cause
**File:** `packages/oauth/oauth-provider/src/client/client.ts`
**Line:** ~240 (in `authenticate` method)
```typescript
const result = await this.jwtVerify<{
jti: string
exp?: number
}>(input.client_assertion, {
subject: this.id,
audience: checks.authorizationServerIdentifier,
requiredClaims: ['jti'],
maxTokenAge: CLIENT_ASSERTION_MAX_AGE / 1000,
// Missing: clockTolerance parameter
})
```
**The Issue:**
1. `maxTokenAge` is set, which triggers `iat` (Issued At) claim validation in the `jose` library
2. `clockTolerance` is **not set**, so `jose` defaults to `0 seconds`
3. Any client clock drift ahead of the PDS (even 1ms) causes rejection
4. The validation logic in `jose` is: `if (iat > now + clockTolerance) reject()`
---
## Evidence
### Timeline from Production Logs
**Example 1: Failed Authentication (ATCR AppView)**
```json
{
"time": 1763433826885, // PDS received request: 2025-11-18 02:43:46.885 UTC
"error": "iat claim timestamp check failed (it should be in the past)"
}
```
**Client assertion JWT payload:**
```json
{
"iat": 1763433827, // Token issued at: 2025-11-18 02:43:47.000 UTC
"exp": 1763433857
}
```
**Analysis:**
- PDS received request at: `02:43:46.885`
- JWT `iat` claim: `02:43:47.000`
- Time difference: **+115 milliseconds** (client ahead)
- Result: **REJECTED**
---
**Example 2: Successful Authentication (tangled.org server)**
```json
{
"time": 1763434370365, // PDS received request: 2025-11-18 02:52:50.365 UTC
}
```
**Client assertion JWT payload:**
```json
{
"iat": 1763434370, // Token issued at: 2025-11-18 02:52:50.000 UTC
"exp": 1763434400
}
```
**Analysis:**
- PDS received request at: `02:52:50.365`
- JWT `iat` claim: `02:52:50.000`
- Time difference: **-365 milliseconds** (client behind)
- Result: **ACCEPTED**
**Conclusion:** The PDS accepts tokens with `iat` in the past but rejects any token with `iat` in the future, regardless of how small the difference.
---
### Clock Synchronization Status
**ATCR AppView Server (Fedora, chronyd):**
- NTP Status: ✅ Synchronized
- Clock source: time.cloudflare.com
- Drift: Within normal NTP accuracy (5-100ms typical)
**Bluesky PDS (Kubernetes/Talos Linux):**
- NTP Status: ✅ Synchronized
- Clock source: time.cloudflare.com
- Talos node drift: +3.4ms ahead of NTP (observed)
**Both systems are properly synchronized.** The 115ms variance is normal for distributed systems with NTP.
---
## Specification Violations
### 1. ATProto OAuth Specification
**Quote from https://atproto.com/specs/oauth:**
> "Authorization Servers **should not reject client assertion JWTs generated less than a minute ago**"
**Interpretation:** The PDS should accept client assertions with `iat` timestamps within ~60 seconds (past or future) to account for clock skew.
**Current behavior:** Rejects any `iat` in the future, even by 1 millisecond.
**Verdict:****VIOLATES ATProto spec**
---
### 2. FAPI 2.0 Security Profile (Financial-grade API)
**Quote from FAPI 2.0 spec:**
> "Authorization servers **MUST accept** JWTs with an `iat` or `nbf` timestamp between 0 and **10 seconds in the future**"
> "Authorization servers **SHALL reject** JWTs with an `iat` or `nbf` timestamp greater than **60 seconds in the future**"
**Rationale from spec:**
> "Even a few hundred milliseconds can cause rejection with clock skew... 10 seconds chosen to not affect security while increasing interoperability... Some ecosystems need 30 seconds to fully eliminate issues"
**Current behavior:** Rejects tokens 115ms in the future.
**Verdict:****VIOLATES FAPI 2.0 minimum requirement (10s tolerance)**
---
### 3. RFC 9068 (JWT Profile for OAuth 2.0 Access Tokens)
**Quote:**
> "Implementers **MAY provide for some small leeway, usually no more than a few minutes**, to account for clock skew"
**Industry practice:** 30-60 seconds is the modern standard.
**Current behavior:** 0 seconds tolerance.
**Verdict:****Below recommended practice**
---
### 4. RFC 9449 (DPoP - OAuth 2.0 Demonstrating Proof-of-Possession)
**Quote:**
> "To accommodate for clock offsets, the server **MAY accept DPoP proofs** that carry an `iat` time in the **reasonably near future (on the order of seconds or minutes)**"
**Current behavior:** Client assertions use similar JWT structure to DPoP proofs but have 0 tolerance.
**Verdict:****Inconsistent with DPoP guidance**
---
## Industry Standards Analysis
### Library Defaults Comparison
| Library | Language | Default clockTolerance | Common Config |
|---------|----------|------------------------|---------------|
| **panva/jose** (PDS uses this) | JavaScript | **0s** ❌ | 30-60s |
| jsonwebtoken | Node.js | 0s | 30-60s |
| Spring Security | Java | 60s | 60s |
| nimbus-jose-jwt | Java | 60s | 60s |
| golang-jwt | Go | 0s | 60s |
| Okta JWT Verifier | Go | 120s | 120s |
**Key insight:** Modern libraries default to 0s (secure by default), but **application code must configure appropriate tolerance**. Enterprise libraries default to 60-120s for usability.
---
### OAuth Provider Recommendations
| Provider | Recommended clockTolerance |
|----------|---------------------------|
| Google | 30 seconds |
| Microsoft Azure AD | 300 seconds (5 minutes) |
| Okta | 120 seconds (2 minutes) |
| Auth0 | 5-30 seconds |
| **FAPI 2.0 (Banking)** | **10-60 seconds (10s minimum)** |
**Consensus:** 30-60 seconds is the modern standard for production OAuth systems.
---
### Real-World Clock Drift Expectations
**NTP Synchronization Accuracy:**
- Internet: 5-100ms typical (90% < 10ms)
- Same cloud provider, different regions: 10-50ms
- Multi-cloud/hybrid: Up to 200ms
- Mobile/edge devices: Up to 5 seconds
**Natural Clock Drift:**
- Typical RTC accuracy: 1-5 ppm (parts per million)
- Daily drift without NTP: ~0.4 seconds/day
- Network latency: Adds milliseconds to seconds
**Conclusion:** 115ms of drift with proper NTP is **completely normal** and expected in distributed systems.
---
## Proposed Fix
### One-Line Code Change
**File:** `packages/oauth/oauth-provider/src/client/client.ts`
**Location:** `authenticate` method (around line 240)
**Current code:**
```typescript
const result = await this.jwtVerify<{
jti: string
exp?: number
}>(input.client_assertion, {
subject: this.id,
audience: checks.authorizationServerIdentifier,
requiredClaims: ['jti'],
maxTokenAge: CLIENT_ASSERTION_MAX_AGE / 1000,
})
```
**Proposed fix:**
```typescript
const result = await this.jwtVerify<{
jti: string
exp?: number
}>(input.client_assertion, {
subject: this.id,
audience: checks.authorizationServerIdentifier,
requiredClaims: ['jti'],
maxTokenAge: CLIENT_ASSERTION_MAX_AGE / 1000,
clockTolerance: 30, // Accept tokens up to 30s in the future (FAPI-compliant)
})
```
**Alternative values:**
- **`clockTolerance: 10`** - FAPI 2.0 minimum requirement
- **`clockTolerance: 30`** - Recommended default (Google's practice)
- **`clockTolerance: 60`** - Maximum per FAPI 2.0, ATProto spec guidance
---
### Justification for 30 Seconds
**Security considerations:**
- 30 seconds is negligible for token expiration windows (typically 5-15 minutes)
- Does not meaningfully increase replay attack window
- Well within FAPI 2.0 maximum (60 seconds)
**Operational benefits:**
- Eliminates 99%+ of clock skew issues
- Accommodates normal NTP accuracy (5-100ms) with huge margin
- Handles network latency (typically <100ms)
- Prevents user-facing authentication failures
**Standards compliance:**
- ✅ Meets FAPI 2.0 minimum (10s) and maximum (60s)
- ✅ Aligns with ATProto spec ("less than a minute ago")
- ✅ Matches industry best practice (30-60s range)
- ✅ Consistent with Google's documented practice
---
## Testing Methodology
### Reproduction Steps
1. Set up two servers with independent NTP synchronization
2. Ensure Server A's clock is 100-500ms ahead of Server B
3. Configure OAuth client on Server A to authenticate against PDS on Server B
4. Attempt client assertion-based OAuth flow
5. Observe validation failure with `iat` error
### Verification After Fix
1. Apply the proposed code change (add `clockTolerance: 30`)
2. Rebuild and deploy PDS
3. Retry OAuth flow from Step 3 above
4. Confirm successful authentication
### Test Cases
**Should ACCEPT (with 30s tolerance):**
-`iat` 115ms in the future (observed case)
-`iat` 5 seconds in the future
-`iat` 29 seconds in the future
-`iat` exactly 30 seconds in the future
-`iat` 1 second in the past
-`iat` 5 minutes in the past (within `maxTokenAge`)
**Should REJECT:**
-`iat` 31 seconds in the future
-`iat` more than `maxTokenAge` seconds in the past
- ❌ Invalid JWT signature
- ❌ Missing required claims
---
## Impact Assessment
### Severity: HIGH
**User impact:**
- OAuth authentication fails intermittently based on clock variance
- Affects any OAuth client whose clock is ahead of PDS
- Unpredictable failures (works sometimes, fails other times)
- Poor developer experience (confusing error message)
**Affected scenarios:**
- Docker/Podman registries authenticating to ATCR
- Third-party OAuth clients (tangled.org works only because clock is behind)
- Distributed systems with independent time synchronization
- Cloud environments with clock drift (VMs, containers)
**Current workarounds:**
1. Ensure OAuth client clock is always behind PDS (impractical)
2. Fork indigo library to send older `iat` timestamps (client-side hack)
3. Patch PDS with custom Docker image (deployment complexity)
**None of these are acceptable long-term solutions.**
---
## Recommended Actions
### Immediate (Bluesky Team)
1. **Apply the one-line fix** to `oauth-provider/src/client/client.ts`
2. **Add `clockTolerance: 30`** to the `jwtVerify` call
3. **Publish new version** of `@atproto/oauth-provider` package
4. **Update PDS** to use fixed version
### Short-term (Bluesky Team)
1. **Add configuration option** for `clockTolerance` (allow deployments to adjust)
2. **Document the setting** in PDS configuration docs
3. **Add logging** to track clock skew patterns (for monitoring)
### Long-term (Bluesky Team)
1. **Add comprehensive time validation tests** covering clock skew scenarios
2. **Document OAuth timing requirements** in ATProto spec
3. **Consider** implementing server-provided nonces (DPoP pattern) for stricter validation without clock dependency
### For ATCR Project
**Until upstream fix:**
1. Document this issue in ATCR troubleshooting guide
2. Implement client-side workaround (fork indigo with `-1s` offset in `iat`)
3. Monitor for PDS updates with the fix
**After upstream fix:**
1. Update to fixed PDS version
2. Remove client-side workaround
3. Document resolution in changelog
---
## References
### Official Specifications
1. **ATProto OAuth Specification**
https://atproto.com/specs/oauth
Section: Client Assertion Validation
2. **FAPI 2.0 Security Profile**
https://openid.net/specs/fapi-security-profile-2_0-final.html
Section 5.2.2.1: Authorization Server - Time Validation
3. **RFC 7519 - JSON Web Token (JWT)**
https://datatracker.ietf.org/doc/html/rfc7519
Section 4.1.6: "iat" (Issued At) Claim
4. **RFC 9068 - JWT Profile for OAuth 2.0 Access Tokens**
https://datatracker.ietf.org/doc/rfc9068/
Section 2.2.2: Clock Skew
5. **RFC 9449 - OAuth 2.0 Demonstrating Proof-of-Possession (DPoP)**
https://datatracker.ietf.org/doc/html/rfc9449
Section 4.3: Checking DPoP Proofs
### Library Documentation
6. **panva/jose - JWT Verify Options**
https://github.com/panva/jose/blob/main/docs/jwt/verify/interfaces/JWTVerifyOptions.md
Documentation for `clockTolerance` parameter
7. **jose Source Code - JWT Claims Validation**
https://github.com/panva/jose/blob/main/src/lib/jwt_claims_set.ts
Shows default `clockTolerance = 0` when undefined
### Related Issues
8. **Bluesky atproto Repository**
https://github.com/bluesky-social/atproto
(Issue to be filed with this report)
9. **ATCR Project Documentation**
https://github.com/your-org/atcr
OAuth troubleshooting guide
---
## Appendix: Alternative Solutions Considered
### Option 1: Client-side Workaround (Fork indigo)
**Implementation:** Modify indigo's `NewClientAssertion` to subtract 1 second from `iat`
**Pros:**
- Quick fix for ATCR
- No PDS changes needed
- Full control over timing offset
**Cons:**
- Doesn't fix root cause
- Must maintain fork
- Other OAuth clients still affected
- Not a proper solution
**Verdict:** ⚠️ Temporary workaround only
---
### Option 2: Use Server-Provided Nonces
**Implementation:** PDS provides time-based nonce in error response, client includes in retry
**Pros:**
- Eliminates clock skew dependency entirely
- Stronger security model
- DPoP already uses this pattern
**Cons:**
- Requires significant changes to OAuth flow
- Adds latency (extra round trip)
- Not backward compatible
- Complex implementation
**Verdict:** 🔄 Consider for future enhancement, not immediate fix
---
### Option 3: Disable `maxTokenAge` Validation
**Implementation:** Remove `maxTokenAge` parameter from `jwtVerify` call
**Pros:**
- Eliminates `iat` validation
- Simple one-line change
**Cons:**
- ❌ Removes important security check (token age validation)
- ❌ Allows arbitrarily old tokens to be used
- ❌ Not a proper fix
**Verdict:** ❌ Not recommended - security regression
---
### Option 4: Add `clockTolerance` Parameter (Recommended)
**Implementation:** Add `clockTolerance: 30` to existing `jwtVerify` call
**Pros:**
- ✅ Minimal code change (one line)
- ✅ Fixes root cause
- ✅ Spec-compliant (FAPI 2.0, ATProto, RFCs)
- ✅ Industry standard practice
- ✅ No security regression
- ✅ Benefits all OAuth clients
**Cons:**
- None significant
**Verdict:****Recommended solution**
---
## Conclusion
The Bluesky PDS OAuth provider has a clear bug: it validates client assertion JWTs with zero clock tolerance, causing authentication failures for properly synchronized systems with normal clock drift. This violates the ATProto OAuth specification, FAPI 2.0 requirements, and industry best practices.
The fix is trivial (one line of code), has no security downsides, and will improve interoperability for all OAuth clients authenticating to Bluesky PDS instances.
**Recommended action:** Add `clockTolerance: 30` to the `jwtVerify` call in `oauth-provider/src/client/client.ts`.
---
**Report Version:** 1.0
**Last Updated:** 2025-11-18
**Contact:** ATCR Project Team
+433
View File
@@ -0,0 +1,433 @@
# ATCR Troubleshooting Guide
This document provides troubleshooting guidance for common ATCR deployment and operational issues.
## OAuth Authentication Failures
### JWT Timestamp Validation Errors
**Symptom:**
```
error: invalid_client
error_description: Validation of "client_assertion" failed: "iat" claim timestamp check failed (it should be in the past)
```
**Root Cause:**
The AppView server's system clock is ahead of the PDS server's clock. When the AppView generates a JWT for OAuth client authentication (confidential client mode), the "iat" (issued at) claim appears to be in the future from the PDS's perspective.
**Diagnosis:**
1. Check AppView system time:
```bash
date -u
timedatectl status
```
2. Check if NTP is active and synchronized:
```bash
timedatectl show-timesync --all
```
3. Compare AppView time with PDS time (if accessible):
```bash
# On AppView
date +%s
# On PDS (or via HTTP headers)
curl -I https://your-pds.example.com | grep -i date
```
4. Check AppView logs for clock information (logged at startup):
```bash
docker logs atcr-appview 2>&1 | grep "Configured confidential OAuth client"
```
Example log output:
```
level=INFO msg="Configured confidential OAuth client"
key_id=did:key:z...
system_time_unix=1731844215
system_time_rfc3339=2025-11-17T14:30:15Z
timezone=UTC
```
**Solution:**
1. **Enable NTP synchronization** (recommended):
On most Linux systems using systemd:
```bash
# Enable and start systemd-timesyncd
sudo timedatectl set-ntp true
# Verify NTP is active
timedatectl status
```
Expected output:
```
System clock synchronized: yes
NTP service: active
```
2. **Alternative: Use chrony** (if systemd-timesyncd is not available):
```bash
# Install chrony
sudo apt-get install chrony # Debian/Ubuntu
sudo yum install chrony # RHEL/CentOS
# Enable and start chronyd
sudo systemctl enable chronyd
sudo systemctl start chronyd
# Check sync status
chronyc tracking
```
3. **Force immediate sync**:
```bash
# systemd-timesyncd
sudo systemctl restart systemd-timesyncd
# Or with chrony
sudo chronyc makestep
```
4. **In Docker/Kubernetes environments:**
The container inherits the host's system clock, so fix NTP on the **host** machine:
```bash
# On Docker host
sudo timedatectl set-ntp true
# Restart AppView container to pick up correct time
docker restart atcr-appview
```
5. **Verify clock skew is resolved**:
```bash
# Should show clock offset < 1 second
timedatectl timesync-status
```
**Acceptable Clock Skew:**
- Most OAuth implementations tolerate ±30-60 seconds of clock skew
- DPoP proof validation is typically stricter (±10 seconds)
- Aim for < 1 second skew for reliable operation
**Prevention:**
- Configure NTP synchronization in your infrastructure-as-code (Terraform, Ansible, etc.)
- Monitor clock skew in production (e.g., Prometheus node_exporter includes clock metrics)
- Use managed container platforms (ECS, GKE, AKS) that handle NTP automatically
---
### DPoP Nonce Mismatch Errors
**Symptom:**
```
error: use_dpop_nonce
error_description: DPoP "nonce" mismatch
```
Repeated multiple times, potentially followed by:
```
error: server_error
error_description: Server error
```
**Root Cause:**
DPoP (Demonstrating Proof-of-Possession) requires a server-provided nonce for replay protection. These errors typically occur when:
1. Multiple concurrent requests create a DPoP nonce race condition
2. Clock skew causes DPoP proof timestamps to fail validation
3. PDS session state becomes corrupted after repeated failures
**Diagnosis:**
1. Check if errors occur during concurrent operations:
```bash
# During docker push with multiple layers
docker logs atcr-appview 2>&1 | grep "use_dpop_nonce" | wc -l
```
2. Check for clock skew (see section above):
```bash
timedatectl status
```
3. Look for session lock acquisition in logs:
```bash
docker logs atcr-appview 2>&1 | grep "Acquired session lock"
```
**Solution:**
1. **If caused by clock skew**: Fix NTP synchronization (see section above)
2. **If caused by session corruption**:
```bash
# The AppView will automatically delete corrupted sessions
# User just needs to re-authenticate
docker login atcr.io
```
3. **If persistent despite clock sync**:
- Check PDS health and logs (may be a PDS-side issue)
- Verify network connectivity between AppView and PDS
- Check if PDS supports latest OAuth/DPoP specifications
**What ATCR does automatically:**
- Per-DID locking prevents concurrent DPoP nonce races
- Indigo library automatically retries with fresh nonces
- Sessions are auto-deleted after repeated failures
- Service token cache prevents excessive PDS requests
**Prevention:**
- Ensure reliable NTP synchronization
- Use a stable, well-maintained PDS implementation
- Monitor AppView error rates for DPoP-related issues
---
### OAuth Session Not Found
**Symptom:**
```
error: failed to get OAuth session: no session found for DID
```
**Root Cause:**
- User has never authenticated via OAuth
- OAuth session was deleted due to corruption or expiry
- Database migration cleared sessions
**Solution:**
1. User re-authenticates via OAuth flow:
```bash
docker login atcr.io
# Or for web UI: visit https://atcr.io/login
```
2. If using app passwords (legacy), verify token is cached:
```bash
# Check if app-password token exists
docker logout atcr.io
docker login atcr.io -u your.handle -p your-app-password
```
---
## AppView Deployment Issues
### Client Metadata URL Not Accessible
**Symptom:**
```
error: unauthorized_client
error_description: Client metadata endpoint returned 404
```
**Root Cause:**
PDS cannot fetch OAuth client metadata from `{ATCR_BASE_URL}/client-metadata.json`
**Diagnosis:**
1. Verify client metadata endpoint is accessible:
```bash
curl https://your-atcr-instance.com/client-metadata.json
```
2. Check AppView logs for startup errors:
```bash
docker logs atcr-appview 2>&1 | grep "client-metadata"
```
3. Verify `ATCR_BASE_URL` is set correctly:
```bash
echo $ATCR_BASE_URL
```
**Solution:**
1. Ensure `ATCR_BASE_URL` matches your public URL:
```bash
export ATCR_BASE_URL=https://atcr.example.com
```
2. Verify reverse proxy (nginx, Caddy, etc.) routes `/.well-known/*` and `/client-metadata.json`:
```nginx
location / {
proxy_pass http://localhost:5000;
proxy_set_header Host $host;
proxy_set_header X-Forwarded-Proto $scheme;
}
```
3. Check firewall rules allow inbound HTTPS:
```bash
sudo ufw status
sudo iptables -L -n | grep 443
```
---
## Hold Service Issues
### Blob Storage Connectivity
**Symptom:**
```
error: failed to upload blob: connection refused
```
**Diagnosis:**
1. Check hold service logs:
```bash
docker logs atcr-hold 2>&1 | grep -i error
```
2. Verify S3 credentials are correct:
```bash
# Test S3 access
aws s3 ls s3://your-bucket --endpoint-url=$S3_ENDPOINT
```
3. Check hold configuration:
```bash
env | grep -E "(S3_|AWS_|STORAGE_)"
```
**Solution:**
1. Verify environment variables in hold service:
```bash
export AWS_ACCESS_KEY_ID=your-key
export AWS_SECRET_ACCESS_KEY=your-secret
export S3_BUCKET=your-bucket
export S3_ENDPOINT=https://s3.us-west-2.amazonaws.com
```
2. Test S3 connectivity from hold container:
```bash
docker exec atcr-hold curl -v $S3_ENDPOINT
```
3. Check S3 bucket permissions (requires PutObject, GetObject, DeleteObject)
---
## Performance Issues
### High Database Lock Contention
**Symptom:**
Slow Docker push/pull operations, high CPU usage on AppView
**Diagnosis:**
1. Check SQLite database size:
```bash
ls -lh /var/lib/atcr/ui.db
```
2. Look for long-running queries:
```bash
docker logs atcr-appview 2>&1 | grep "database is locked"
```
**Solution:**
1. For production, migrate to PostgreSQL (recommended):
```bash
export ATCR_UI_DATABASE_TYPE=postgres
export ATCR_UI_DATABASE_URL=postgresql://user:pass@localhost/atcr
```
2. Or increase SQLite busy timeout:
```go
// In code: db.SetMaxOpenConns(1) for SQLite
```
3. Vacuum the database to reclaim space:
```bash
sqlite3 /var/lib/atcr/ui.db "VACUUM;"
```
---
## Logging and Debugging
### Enable Debug Logging
Set log level to debug for detailed troubleshooting:
```bash
export ATCR_LOG_LEVEL=debug
docker restart atcr-appview
```
### Useful Log Queries
**OAuth token exchange errors:**
```bash
docker logs atcr-appview 2>&1 | grep "OAuth callback failed"
```
**Service token request failures:**
```bash
docker logs atcr-appview 2>&1 | grep "OAuth authentication failed during service token request"
```
**Clock diagnostics:**
```bash
docker logs atcr-appview 2>&1 | grep "system_time"
```
**DPoP nonce issues:**
```bash
docker logs atcr-appview 2>&1 | grep -E "(use_dpop_nonce|DPoP)"
```
### Health Checks
**AppView health:**
```bash
curl http://localhost:5000/v2/
# Should return: {"errors":[{"code":"UNAUTHORIZED",...}]}
```
**Hold service health:**
```bash
curl http://localhost:8080/.well-known/did.json
# Should return DID document
```
---
## Getting Help
If issues persist after following this guide:
1. **Check GitHub Issues**: https://github.com/ericvolp12/atcr/issues
2. **Collect logs**: Include output from `docker logs` for AppView and Hold services
3. **Include diagnostics**:
- `timedatectl status` output
- AppView version: `docker exec atcr-appview cat /VERSION` (if available)
- PDS version and implementation (Bluesky PDS, other)
4. **File an issue** with reproducible steps
---
## Common Error Reference
| Error Code | Component | Common Cause | Fix |
|------------|-----------|--------------|-----|
| `invalid_client` (iat timestamp) | OAuth | Clock skew | Enable NTP sync |
| `use_dpop_nonce` | OAuth/DPoP | Concurrent requests or clock skew | Fix NTP, wait for auto-retry |
| `server_error` (500) | PDS | PDS internal error | Check PDS logs |
| `invalid_grant` | OAuth | Expired auth code | Retry OAuth flow |
| `unauthorized_client` | OAuth | Client metadata unreachable | Check ATCR_BASE_URL and firewall |
| `RecordNotFound` | ATProto | Manifest doesn't exist | Verify repository name |
| Connection refused | Hold/S3 | Network/credentials | Check S3 config and connectivity |
+18
View File
@@ -63,6 +63,11 @@ func (h *StarRepositoryHandler) ServeHTTP(w http.ResponseWriter, r *http.Request
// Write star record to user's PDS
_, err = pdsClient.PutRecord(r.Context(), atproto.StarCollection, rkey, starRecord)
if err != nil {
// Check if OAuth error - if so, invalidate sessions and return 401
if handleOAuthError(r.Context(), h.Refresher, user.DID, err) {
http.Error(w, "Authentication failed, please log in again", http.StatusUnauthorized)
return
}
slog.Error("Failed to create star record", "error", err)
http.Error(w, fmt.Sprintf("Failed to create star: %v", err), http.StatusInternalServerError)
return
@@ -121,6 +126,11 @@ func (h *UnstarRepositoryHandler) ServeHTTP(w http.ResponseWriter, r *http.Reque
if err != nil {
// If record doesn't exist, still return success (idempotent)
if !errors.Is(err, atproto.ErrRecordNotFound) {
// Check if OAuth error - if so, invalidate sessions and return 401
if handleOAuthError(r.Context(), h.Refresher, user.DID, err) {
http.Error(w, "Authentication failed, please log in again", http.StatusUnauthorized)
return
}
slog.Error("Failed to delete star record", "error", err)
http.Error(w, fmt.Sprintf("Failed to delete star: %v", err), http.StatusInternalServerError)
return
@@ -180,6 +190,14 @@ func (h *CheckStarHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
rkey := atproto.StarRecordKey(ownerDID, repository)
_, err = pdsClient.GetRecord(r.Context(), atproto.StarCollection, rkey)
// Check if OAuth error - if so, invalidate sessions
if err != nil && handleOAuthError(r.Context(), h.Refresher, user.DID, err) {
// For a read operation, just return not starred instead of error
w.Header().Set("Content-Type", "application/json")
json.NewEncoder(w).Encode(map[string]bool{"starred": false})
return
}
starred := err == nil
// Return result
+15
View File
@@ -47,6 +47,11 @@ func (h *DeleteTagHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
// Delete from PDS first
if err := pdsClient.DeleteRecord(r.Context(), atproto.TagCollection, rkey); err != nil {
// Check if OAuth error - if so, invalidate sessions and return 401
if handleOAuthError(r.Context(), h.Refresher, user.DID, err) {
http.Error(w, "Authentication failed, please log in again", http.StatusUnauthorized)
return
}
http.Error(w, fmt.Sprintf("Failed to delete tag from PDS: %v", err), http.StatusInternalServerError)
return
}
@@ -127,6 +132,11 @@ func (h *DeleteManifestHandler) ServeHTTP(w http.ResponseWriter, r *http.Request
// Delete from PDS
tagRKey := fmt.Sprintf("%s:%s", repo, tag)
if err := pdsClient.DeleteRecord(r.Context(), atproto.TagCollection, tagRKey); err != nil {
// Check if OAuth error - if so, invalidate sessions and return 401
if handleOAuthError(r.Context(), h.Refresher, user.DID, err) {
http.Error(w, "Authentication failed, please log in again", http.StatusUnauthorized)
return
}
http.Error(w, fmt.Sprintf("Failed to delete tag '%s' from PDS: %v", tag, err), http.StatusInternalServerError)
return
}
@@ -144,6 +154,11 @@ func (h *DeleteManifestHandler) ServeHTTP(w http.ResponseWriter, r *http.Request
// Delete from PDS first
if err := pdsClient.DeleteRecord(r.Context(), atproto.ManifestCollection, rkey); err != nil {
// Check if OAuth error - if so, invalidate sessions and return 401
if handleOAuthError(r.Context(), h.Refresher, user.DID, err) {
http.Error(w, "Authentication failed, please log in again", http.StatusUnauthorized)
return
}
http.Error(w, fmt.Sprintf("Failed to delete manifest from PDS: %v", err), http.StatusInternalServerError)
return
}
+6 -38
View File
@@ -1,21 +1,16 @@
package handlers
import (
"log/slog"
"net/http"
"atcr.io/pkg/appview/db"
"atcr.io/pkg/auth/oauth"
indigooauth "github.com/bluesky-social/indigo/atproto/auth/oauth"
"github.com/bluesky-social/indigo/atproto/syntax"
)
// LogoutHandler handles user logout with proper OAuth token revocation
// LogoutHandler handles user logout from the web UI
// This only clears the current UI session cookie - it does NOT revoke OAuth tokens
// OAuth sessions remain intact so other browser tabs/devices stay logged in
type LogoutHandler struct {
OAuthClientApp *indigooauth.ClientApp
Refresher *oauth.Refresher
SessionStore *db.SessionStore
OAuthStore *db.OAuthStore
SessionStore *db.SessionStore
}
func (h *LogoutHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
@@ -27,35 +22,8 @@ func (h *LogoutHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
return
}
// Get UI session to extract OAuth session ID and user info
uiSession, ok := h.SessionStore.Get(uiSessionID)
if ok && uiSession != nil && uiSession.DID != "" {
// Parse DID for OAuth logout
did, err := syntax.ParseDID(uiSession.DID)
if err != nil {
slog.Warn("Failed to parse DID for logout", "component", "logout", "did", uiSession.DID, "error", err)
} else {
// Attempt to revoke OAuth tokens on PDS side
if uiSession.OAuthSessionID != "" {
// Call indigo's Logout to revoke tokens on PDS
if err := h.OAuthClientApp.Logout(r.Context(), did, uiSession.OAuthSessionID); err != nil {
// Log error but don't block logout - best effort revocation
slog.Warn("Failed to revoke OAuth tokens on PDS", "component", "logout", "did", uiSession.DID, "error", err)
} else {
slog.Info("Successfully revoked OAuth tokens on PDS", "component", "logout", "did", uiSession.DID)
}
// Delete OAuth session from database (cleanup, might already be done by Logout)
if err := h.OAuthStore.DeleteSession(r.Context(), did, uiSession.OAuthSessionID); err != nil {
slog.Warn("Failed to delete OAuth session from database", "component", "logout", "error", err)
}
} else {
slog.Warn("No OAuth session ID found for user", "component", "logout", "did", uiSession.DID)
}
}
}
// Always delete UI session and clear cookie, even if OAuth revocation failed
// Delete only this UI session and clear cookie
// OAuth session remains intact for other browser tabs/devices
h.SessionStore.Delete(uiSessionID)
db.ClearCookie(w)
-1
View File
@@ -57,7 +57,6 @@ func TestLogoutHandler_WithSession(t *testing.T) {
handler := &LogoutHandler{
SessionStore: sessionStore,
OAuthStore: db.NewOAuthStore(database),
}
req := httptest.NewRequest("GET", "/auth/logout", nil)
+49
View File
@@ -0,0 +1,49 @@
package handlers
import (
"context"
"log/slog"
"strings"
"atcr.io/pkg/auth/oauth"
)
// isOAuthError checks if an error indicates OAuth authentication failure
// These errors indicate the OAuth session is invalid and should be cleaned up
func isOAuthError(err error) bool {
if err == nil {
return false
}
errStr := strings.ToLower(err.Error())
return strings.Contains(errStr, "401") ||
strings.Contains(errStr, "403") ||
strings.Contains(errStr, "invalid_token") ||
strings.Contains(errStr, "invalid_grant") ||
strings.Contains(errStr, "use_dpop_nonce") ||
strings.Contains(errStr, "unauthorized") ||
strings.Contains(errStr, "token") && strings.Contains(errStr, "expired") ||
strings.Contains(errStr, "authentication failed")
}
// handleOAuthError checks if an error is OAuth-related and invalidates UI sessions if so
// Returns true if the error was an OAuth error (caller should return early)
func handleOAuthError(ctx context.Context, refresher *oauth.Refresher, did string, err error) bool {
if !isOAuthError(err) {
return false
}
slog.Warn("OAuth error detected, invalidating sessions",
"component", "handlers",
"did", did,
"error", err)
// Invalidate all UI sessions for this DID
if delErr := refresher.DeleteSession(ctx, did); delErr != nil {
slog.Warn("Failed to delete OAuth session after error",
"component", "handlers",
"did", did,
"error", delErr)
}
return true
}
+223 -56
View File
@@ -7,6 +7,8 @@ import (
"log/slog"
"net/http"
"strings"
"sync"
"time"
"github.com/distribution/distribution/v3"
"github.com/distribution/distribution/v3/registry/api/errcode"
@@ -27,6 +29,144 @@ const holdDIDKey contextKey = "hold.did"
// authMethodKey is the context key for storing auth method from JWT
const authMethodKey contextKey = "auth.method"
// validationCacheEntry stores a validated service token with expiration
type validationCacheEntry struct {
serviceToken string
validUntil time.Time
err error // Cached error for fast-fail
mu sync.Mutex // Per-entry lock to serialize cache population
inFlight bool // True if another goroutine is fetching the token
done chan struct{} // Closed when fetch completes
}
// validationCache provides request-level caching for service tokens
// This prevents concurrent layer uploads from racing on OAuth/DPoP requests
type validationCache struct {
mu sync.RWMutex
entries map[string]*validationCacheEntry // key: "did:holdDID"
}
// newValidationCache creates a new validation cache
func newValidationCache() *validationCache {
return &validationCache{
entries: make(map[string]*validationCacheEntry),
}
}
// getOrFetch retrieves a service token from cache or fetches it
// Multiple concurrent requests for the same DID:holdDID will share the fetch operation
func (vc *validationCache) getOrFetch(ctx context.Context, cacheKey string, fetchFunc func() (string, error)) (string, error) {
// Fast path: check cache with read lock
vc.mu.RLock()
entry, exists := vc.entries[cacheKey]
vc.mu.RUnlock()
if exists {
// Entry exists, check if it's still valid
entry.mu.Lock()
// If another goroutine is fetching, wait for it
if entry.inFlight {
done := entry.done
entry.mu.Unlock()
select {
case <-done:
// Fetch completed, check result
entry.mu.Lock()
defer entry.mu.Unlock()
if entry.err != nil {
return "", entry.err
}
if time.Now().Before(entry.validUntil) {
return entry.serviceToken, nil
}
// Fall through to refetch
case <-ctx.Done():
return "", ctx.Err()
}
} else {
// Check if cached token is still valid
if entry.err != nil && time.Now().Before(entry.validUntil) {
// Return cached error (fast-fail)
entry.mu.Unlock()
return "", entry.err
}
if entry.err == nil && time.Now().Before(entry.validUntil) {
// Return cached token
token := entry.serviceToken
entry.mu.Unlock()
return token, nil
}
entry.mu.Unlock()
}
}
// Slow path: need to fetch token
vc.mu.Lock()
entry, exists = vc.entries[cacheKey]
if !exists {
// Create new entry
entry = &validationCacheEntry{
inFlight: true,
done: make(chan struct{}),
}
vc.entries[cacheKey] = entry
}
vc.mu.Unlock()
// Lock the entry to perform fetch
entry.mu.Lock()
// Double-check: another goroutine may have fetched while we waited
if !entry.inFlight {
if entry.err != nil && time.Now().Before(entry.validUntil) {
err := entry.err
entry.mu.Unlock()
return "", err
}
if entry.err == nil && time.Now().Before(entry.validUntil) {
token := entry.serviceToken
entry.mu.Unlock()
return token, nil
}
}
// Mark as in-flight and create done channel if needed
if entry.done == nil {
entry.done = make(chan struct{})
}
entry.inFlight = true
done := entry.done
entry.mu.Unlock()
// Perform the fetch (outside the lock to allow other operations)
serviceToken, err := fetchFunc()
// Update the entry with result
entry.mu.Lock()
entry.inFlight = false
if err != nil {
// Cache errors for 5 seconds (fast-fail for subsequent requests)
entry.err = err
entry.validUntil = time.Now().Add(5 * time.Second)
entry.serviceToken = ""
} else {
// Cache token for 45 seconds (covers typical Docker push operation)
entry.err = nil
entry.serviceToken = serviceToken
entry.validUntil = time.Now().Add(45 * time.Second)
}
// Signal completion to waiting goroutines
close(done)
entry.mu.Unlock()
return serviceToken, err
}
// Global variables for initialization only
// These are set by main.go during startup and copied into NamespaceResolver instances.
// After initialization, request handling uses the NamespaceResolver's instance fields.
@@ -69,13 +209,14 @@ func init() {
// NamespaceResolver wraps a namespace and resolves names
type NamespaceResolver struct {
distribution.Namespace
defaultHoldDID string // Default hold DID (e.g., "did:web:hold01.atcr.io")
baseURL string // Base URL for error messages (e.g., "https://atcr.io")
testMode bool // If true, fallback to default hold when user's hold is unreachable
refresher *oauth.Refresher // OAuth session manager (copied from global on init)
database storage.DatabaseMetrics // Metrics database (copied from global on init)
authorizer auth.HoldAuthorizer // Hold authorization (copied from global on init)
readmeCache storage.ReadmeCache // README cache (copied from global on init)
defaultHoldDID string // Default hold DID (e.g., "did:web:hold01.atcr.io")
baseURL string // Base URL for error messages (e.g., "https://atcr.io")
testMode bool // If true, fallback to default hold when user's hold is unreachable
refresher *oauth.Refresher // OAuth session manager (copied from global on init)
database storage.DatabaseMetrics // Metrics database (copied from global on init)
authorizer auth.HoldAuthorizer // Hold authorization (copied from global on init)
readmeCache storage.ReadmeCache // README cache (copied from global on init)
validationCache *validationCache // Request-level service token cache
}
// initATProtoResolver initializes the name resolution middleware
@@ -102,14 +243,15 @@ func initATProtoResolver(ctx context.Context, ns distribution.Namespace, _ drive
// Copy shared services from globals into the instance
// This avoids accessing globals during request handling
return &NamespaceResolver{
Namespace: ns,
defaultHoldDID: defaultHoldDID,
baseURL: baseURL,
testMode: testMode,
refresher: globalRefresher,
database: globalDatabase,
authorizer: globalAuthorizer,
readmeCache: globalReadmeCache,
Namespace: ns,
defaultHoldDID: defaultHoldDID,
baseURL: baseURL,
testMode: testMode,
refresher: globalRefresher,
database: globalDatabase,
authorizer: globalAuthorizer,
readmeCache: globalReadmeCache,
validationCache: newValidationCache(),
}, nil
}
@@ -165,61 +307,86 @@ func (nr *NamespaceResolver) Repository(ctx context.Context, name reference.Name
}(ctx, client, nr.refresher, holdDID)
}
// Get service token for hold authentication
// Get service token for hold authentication (only if authenticated)
// Use validation cache to prevent concurrent requests from racing on OAuth/DPoP
// Route based on auth method from JWT token
var serviceToken string
authMethod, _ := ctx.Value(authMethodKey).(string)
if authMethod == token.AuthMethodAppPassword {
// App-password flow: use Bearer token authentication
slog.Debug("Using app-password flow for service token",
"component", "registry/middleware",
"did", did)
// Only fetch service token if user is authenticated
// Unauthenticated requests (like /v2/ ping) should not trigger token fetching
if authMethod != "" {
// Create cache key: "did:holdDID"
cacheKey := fmt.Sprintf("%s:%s", did, holdDID)
var err error
serviceToken, err = token.GetOrFetchServiceTokenWithAppPassword(ctx, did, holdDID, pdsEndpoint)
if err != nil {
slog.Error("Failed to get service token with app-password",
"component", "registry/middleware",
"did", did,
"holdDID", holdDID,
"pdsEndpoint", pdsEndpoint,
"error", err)
// Fetch service token through validation cache
// This ensures only ONE request per DID:holdDID pair fetches the token
// Concurrent requests will wait for the first request to complete
var fetchErr error
serviceToken, fetchErr = nr.validationCache.getOrFetch(ctx, cacheKey, func() (string, error) {
if authMethod == token.AuthMethodAppPassword {
// App-password flow: use Bearer token authentication
slog.Debug("Using app-password flow for service token",
"component", "registry/middleware",
"did", did,
"cacheKey", cacheKey)
// Check if app-password is expired/invalid
errMsg := err.Error()
if strings.Contains(errMsg, "expired or invalid") || strings.Contains(errMsg, "no app-password") {
return nil, nr.authErrorMessage("App-password authentication failed. Please re-authenticate with: docker login")
token, err := token.GetOrFetchServiceTokenWithAppPassword(ctx, did, holdDID, pdsEndpoint)
if err != nil {
slog.Error("Failed to get service token with app-password",
"component", "registry/middleware",
"did", did,
"holdDID", holdDID,
"pdsEndpoint", pdsEndpoint,
"error", err)
return "", err
}
return token, nil
} else if nr.refresher != nil {
// OAuth flow: use DPoP authentication
slog.Debug("Using OAuth flow for service token",
"component", "registry/middleware",
"did", did,
"cacheKey", cacheKey)
token, err := token.GetOrFetchServiceToken(ctx, nr.refresher, did, holdDID, pdsEndpoint)
if err != nil {
slog.Error("Failed to get service token with OAuth",
"component", "registry/middleware",
"did", did,
"holdDID", holdDID,
"pdsEndpoint", pdsEndpoint,
"error", err)
return "", err
}
return token, nil
}
return "", fmt.Errorf("no authentication method available")
})
// Handle errors from cached fetch
if fetchErr != nil {
errMsg := fetchErr.Error()
// Check for app-password specific errors
if authMethod == token.AuthMethodAppPassword {
if strings.Contains(errMsg, "expired or invalid") || strings.Contains(errMsg, "no app-password") {
return nil, nr.authErrorMessage("App-password authentication failed. Please re-authenticate with: docker login")
}
}
// Generic service token error
return nil, nr.authErrorMessage(fmt.Sprintf("Failed to obtain storage credentials: %v", err))
}
} else if nr.refresher != nil {
// OAuth flow: use DPoP authentication
slog.Debug("Using OAuth flow for service token",
"component", "registry/middleware",
"did", did)
var err error
serviceToken, err = token.GetOrFetchServiceToken(ctx, nr.refresher, did, holdDID, pdsEndpoint)
if err != nil {
slog.Error("Failed to get service token with OAuth",
"component", "registry/middleware",
"did", did,
"holdDID", holdDID,
"pdsEndpoint", pdsEndpoint,
"error", err)
// Check if this is likely an OAuth session expiration
errMsg := err.Error()
// Check for OAuth specific errors
if strings.Contains(errMsg, "OAuth session") || strings.Contains(errMsg, "OAuth validation") {
return nil, nr.authErrorMessage("OAuth session expired or invalidated by PDS. Your session has been cleared")
}
// Generic service token error
return nil, nr.authErrorMessage(fmt.Sprintf("Failed to obtain storage credentials: %v", err))
return nil, nr.authErrorMessage(fmt.Sprintf("Failed to obtain storage credentials: %v", fetchErr))
}
} else {
slog.Debug("Skipping service token fetch for unauthenticated request",
"component", "registry/middleware",
"did", did)
}
// Create a new reference with identity/image format
+3 -5
View File
@@ -201,12 +201,10 @@ func RegisterUIRoutes(router chi.Router, deps UIDependencies) {
})
// Logout endpoint (supports both GET and POST)
// Properly revokes OAuth tokens on PDS side before clearing local session
// Only clears the current UI session cookie - does NOT revoke OAuth tokens
// OAuth sessions remain intact so other browser tabs/devices stay logged in
logoutHandler := &uihandlers.LogoutHandler{
OAuthClientApp: deps.OAuthClientApp,
Refresher: deps.Refresher,
SessionStore: deps.SessionStore,
OAuthStore: deps.OAuthStore,
SessionStore: deps.SessionStore,
}
router.Get("/auth/logout", logoutHandler.ServeHTTP)
router.Post("/auth/logout", logoutHandler.ServeHTTP)
+17 -2
View File
@@ -27,7 +27,7 @@ func NewClientApp(baseURL string, store oauth.ClientAuthStore, scopes []string,
// If production (not localhost), automatically set up confidential client
if !isLocalhost(baseURL) {
clientID := baseURL + "/client-metadata.json"
clientID := baseURL + "/oauth-client-metadata.json"
config = oauth.NewPublicConfig(clientID, redirectURI, scopes)
// Generate or load P-256 key
@@ -47,7 +47,14 @@ func NewClientApp(baseURL string, store oauth.ClientAuthStore, scopes []string,
return nil, fmt.Errorf("failed to configure confidential client: %w", err)
}
slog.Info("Configured confidential OAuth client", "key_id", keyID, "key_path", keyPath)
// Log clock information for debugging timestamp issues
now := time.Now()
slog.Info("Configured confidential OAuth client",
"key_id", keyID,
"key_path", keyPath,
"system_time_unix", now.Unix(),
"system_time_rfc3339", now.Format(time.RFC3339),
"timezone", now.Location().String())
} else {
config = oauth.NewLocalhostConfig(redirectURI, scopes)
@@ -241,6 +248,14 @@ func (r *Refresher) resumeSession(ctx context.Context, did string) (*oauth.Clien
slog.Warn("Failed to delete session with mismatched scopes", "error", err, "did", did)
}
// Also invalidate UI sessions since OAuth is now invalid
if r.uiSessionStore != nil {
r.uiSessionStore.DeleteByDID(did)
slog.Info("Invalidated UI sessions due to scope mismatch",
"component", "oauth/refresher",
"did", did)
}
return nil, fmt.Errorf("OAuth scopes changed, re-authentication required")
}
+50
View File
@@ -2,6 +2,7 @@ package oauth
import (
"context"
"errors"
"fmt"
"html/template"
"log/slog"
@@ -10,12 +11,41 @@ import (
"time"
"atcr.io/pkg/atproto"
"github.com/bluesky-social/indigo/atproto/atclient"
"github.com/bluesky-social/indigo/atproto/auth/oauth"
)
// UISessionStore is the interface for UI session management
// UISessionStore is defined in client.go (session management section)
// getOAuthErrorHint provides troubleshooting hints for OAuth errors during token exchange
func getOAuthErrorHint(apiErr *atclient.APIError) string {
switch apiErr.Name {
case "invalid_client":
if strings.Contains(apiErr.Message, "iat") && strings.Contains(apiErr.Message, "timestamp") {
return "JWT timestamp validation failed - AppView system clock may be ahead of PDS clock. Check NTP sync: timedatectl status. Typical tolerance is ±30 seconds."
}
return "OAuth client authentication failed during token exchange - check client key and PDS OAuth configuration"
case "invalid_grant":
return "Authorization code is invalid, expired, or already used - user should retry OAuth flow from beginning"
case "use_dpop_nonce":
return "DPoP nonce challenge during token exchange - indigo should retry automatically, persistent failures indicate PDS issue"
case "invalid_dpop_proof":
return "DPoP proof validation failed - check system clock sync between AppView and PDS"
case "unauthorized_client":
return "PDS rejected the client - check client metadata URL is accessible and scopes are supported"
case "invalid_request":
return "Malformed token request - check OAuth flow parameters (code, redirect_uri, state)"
case "server_error":
return "PDS internal error during token exchange - check PDS logs for root cause"
default:
if apiErr.StatusCode == 400 {
return "Bad request during OAuth token exchange - check error details and PDS logs"
}
return "OAuth token exchange failed - see errorName and errorMessage for PDS response"
}
}
// UserStore is the interface for user management
type UserStore interface {
UpsertUser(did, handle, pdsEndpoint, avatar string) error
@@ -112,8 +142,28 @@ func (s *Server) ServeCallback(w http.ResponseWriter, r *http.Request) {
}
// Process OAuth callback via indigo (handles state validation internally)
// This performs token exchange with the PDS using authorization code
sessionData, err := s.clientApp.ProcessCallback(r.Context(), r.URL.Query())
if err != nil {
// Detailed error logging for token exchange failures
var apiErr *atclient.APIError
if errors.As(err, &apiErr) {
slog.Error("OAuth callback failed - token exchange error",
"component", "oauth/server",
"error", err,
"httpStatus", apiErr.StatusCode,
"errorName", apiErr.Name,
"errorMessage", apiErr.Message,
"hint", getOAuthErrorHint(apiErr),
"queryParams", r.URL.Query().Encode())
} else {
slog.Error("OAuth callback failed - unknown error",
"component", "oauth/server",
"error", err,
"errorType", fmt.Sprintf("%T", err),
"queryParams", r.URL.Query().Encode())
}
s.renderError(w, fmt.Sprintf("Failed to process OAuth callback: %v", err))
return
}
+81 -16
View File
@@ -3,6 +3,7 @@ package token
import (
"context"
"encoding/json"
"errors"
"fmt"
"io"
"log/slog"
@@ -13,8 +14,36 @@ import (
"atcr.io/pkg/atproto"
"atcr.io/pkg/auth"
"atcr.io/pkg/auth/oauth"
"github.com/bluesky-social/indigo/atproto/atclient"
)
// getErrorHint provides context-specific troubleshooting hints based on API error type
func getErrorHint(apiErr *atclient.APIError) string {
switch apiErr.Name {
case "use_dpop_nonce":
return "DPoP nonce mismatch - indigo library should automatically retry with new nonce. If this persists, check for concurrent request issues or PDS session corruption."
case "invalid_client":
if apiErr.Message != "" && apiErr.Message == "Validation of \"client_assertion\" failed: \"iat\" claim timestamp check failed (it should be in the past)" {
return "JWT timestamp validation failed - system clock on AppView may be ahead of PDS clock. Check NTP sync with: timedatectl status"
}
return "OAuth client authentication failed - check client key configuration and PDS OAuth server status"
case "invalid_token", "invalid_grant":
return "OAuth tokens expired or invalidated - user will need to re-authenticate via OAuth flow"
case "server_error":
if apiErr.StatusCode == 500 {
return "PDS returned internal server error - this may occur after repeated DPoP nonce failures or other PDS-side issues. Check PDS logs for root cause."
}
return "PDS server error - check PDS health and logs"
case "invalid_dpop_proof":
return "DPoP proof validation failed - check system clock sync and DPoP key configuration"
default:
if apiErr.StatusCode == 401 || apiErr.StatusCode == 403 {
return "Authentication/authorization failed - OAuth session may be expired or revoked"
}
return "PDS rejected the request - see errorName and errorMessage for details"
}
}
// GetOrFetchServiceToken gets a service token for hold authentication.
// Checks cache first, then fetches from PDS with OAuth/DPoP if needed.
// This is the canonical implementation used by both middleware and crew registration.
@@ -49,13 +78,30 @@ func GetOrFetchServiceToken(
if err != nil {
// OAuth session unavailable - fail
InvalidateServiceToken(did, holdDID)
slog.Error("Failed to get OAuth session for service token",
"component", "token/servicetoken",
"did", did,
"holdDID", holdDID,
"pdsEndpoint", pdsEndpoint,
"error", err,
"errorType", fmt.Sprintf("%T", err))
// Try to extract detailed error information
var apiErr *atclient.APIError
if errors.As(err, &apiErr) {
slog.Error("Failed to get OAuth session for service token",
"component", "token/servicetoken",
"did", did,
"holdDID", holdDID,
"pdsEndpoint", pdsEndpoint,
"error", err,
"httpStatus", apiErr.StatusCode,
"errorName", apiErr.Name,
"errorMessage", apiErr.Message,
"hint", getErrorHint(apiErr))
} else {
slog.Error("Failed to get OAuth session for service token",
"component", "token/servicetoken",
"did", did,
"holdDID", holdDID,
"pdsEndpoint", pdsEndpoint,
"error", err,
"errorType", fmt.Sprintf("%T", err),
"hint", "OAuth session not found in database or token refresh failed")
}
// Delete the stale OAuth session to force re-authentication
// This also invalidates the UI session automatically
@@ -92,15 +138,34 @@ func GetOrFetchServiceToken(
if err != nil {
// Auth error - may indicate expired tokens or corrupted session
InvalidateServiceToken(did, holdDID)
slog.Error("OAuth authentication failed during service token request",
"component", "token/servicetoken",
"did", did,
"holdDID", holdDID,
"pdsEndpoint", pdsEndpoint,
"url", serviceAuthURL,
"error", err,
"errorType", fmt.Sprintf("%T", err),
"hint", "This likely means the PDS rejected the OAuth session - refresh token may be expired or invalidated")
// Inspect the error to extract detailed information from indigo's APIError
var apiErr *atclient.APIError
if errors.As(err, &apiErr) {
// Log detailed API error information
slog.Error("OAuth authentication failed during service token request",
"component", "token/servicetoken",
"did", did,
"holdDID", holdDID,
"pdsEndpoint", pdsEndpoint,
"url", serviceAuthURL,
"error", err,
"httpStatus", apiErr.StatusCode,
"errorName", apiErr.Name,
"errorMessage", apiErr.Message,
"hint", getErrorHint(apiErr))
} else {
// Fallback for non-API errors (network errors, etc.)
slog.Error("OAuth authentication failed during service token request",
"component", "token/servicetoken",
"did", did,
"holdDID", holdDID,
"pdsEndpoint", pdsEndpoint,
"url", serviceAuthURL,
"error", err,
"errorType", fmt.Sprintf("%T", err),
"hint", "Network error or unexpected failure during OAuth request")
}
// Delete the stale OAuth session to force re-authentication
// This also invalidates the UI session automatically