Skip to content

Commit df14c80

Browse files
tstrombergtstromberg
committed
improve logging
1 parent 58ef304 commit df14c80

3 files changed

Lines changed: 138 additions & 13 deletions

File tree

‎cmd/server/main.go‎

Lines changed: 30 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@ import (
66
"context"
77
"crypto/tls"
88
"flag"
9+
"fmt"
910
"log"
1011
"net/http"
1112
"os"
@@ -25,7 +26,9 @@ const (
2526
readTimeout = 10 * time.Second
2627
writeTimeout = 10 * time.Second
2728
idleTimeout = 120 * time.Second
28-
maxHeaderBytes = 20 // Max header size multiplier (1 << 20 = 1MB)
29+
maxHeaderBytes = 20 // Max header size multiplier (1 << 20 = 1MB)
30+
minTokenLength = 40 // Minimum GitHub token length
31+
maxTokenLength = 255 // Maximum GitHub token length
2932
)
3033

3134
var (
@@ -192,7 +195,32 @@ func main() {
192195
// Pre-validate authentication before WebSocket upgrade
193196
authHeader := r.Header.Get("Authorization")
194197
if !wsHandler.PreValidateAuth(r) {
195-
log.Printf("WebSocket 403: auth failed ip=%s auth_header=%q", ip, authHeader)
198+
// Determine specific failure reason for better debugging
199+
reason := "missing"
200+
if authHeader != "" {
201+
if !strings.HasPrefix(authHeader, "Bearer ") {
202+
reason = "invalid_format"
203+
} else {
204+
token := strings.TrimPrefix(authHeader, "Bearer ")
205+
if len(token) < minTokenLength || len(token) > maxTokenLength {
206+
reason = fmt.Sprintf("invalid_length_%d", len(token))
207+
} else {
208+
reason = "invalid_pattern"
209+
}
210+
}
211+
}
212+
213+
// Mask token for security (show only length and prefix if present)
214+
authHeaderLog := "missing"
215+
if authHeader != "" {
216+
if len(authHeader) > 20 {
217+
authHeaderLog = fmt.Sprintf("Bearer [REDACTED len=%d]", len(authHeader)-7)
218+
} else {
219+
authHeaderLog = "[REDACTED]"
220+
}
221+
}
222+
223+
log.Printf("WebSocket 403: auth failed ip=%s reason=%s auth_header=%q", ip, reason, authHeaderLog)
196224
w.WriteHeader(http.StatusForbidden)
197225
msg := "403 Forbidden: Invalid or missing GitHub token. " +
198226
"Please provide a valid token in the Authorization header as 'Bearer <token>'\n"

‎pkg/client/client.go‎

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -235,6 +235,22 @@ func (c *Client) connect(ctx context.Context) error {
235235
// Dial the server
236236
ws, err := websocket.DialConfig(wsConfig)
237237
if err != nil {
238+
// Check for HTTP status codes in the error message
239+
errStr := err.Error()
240+
if strings.Contains(errStr, "bad status") {
241+
errLower := strings.ToLower(errStr)
242+
// Extract status code if present
243+
if strings.Contains(errStr, "403") || strings.Contains(errLower, "forbidden") {
244+
return &AuthenticationError{
245+
message: fmt.Sprintf("Authentication failed (403 Forbidden): Check your GitHub token and organization membership. Original error: %v", err),
246+
}
247+
}
248+
if strings.Contains(errStr, "401") || strings.Contains(errLower, "unauthorized") {
249+
return &AuthenticationError{
250+
message: fmt.Sprintf("Authentication failed (401 Unauthorized): Invalid or missing token. Original error: %v", err),
251+
}
252+
}
253+
}
238254
return fmt.Errorf("dial: %w", err)
239255
}
240256
c.logger.Info("✓ WebSocket connection ESTABLISHED successfully!")

‎pkg/hub/websocket.go‎

Lines changed: 92 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,6 @@ package hub
33
import (
44
"context"
55
"crypto/rand"
6-
"errors"
76
"fmt"
87
"log"
98
"math/big"
@@ -219,17 +218,38 @@ func (h *WebSocketHandler) validateAuth(ctx context.Context, ws *websocket.Conn,
219218
if len(githubToken) >= tokenPrefixLength {
220219
tokenPrefix = githubToken[:tokenPrefixLength]
221220
}
221+
222+
// Determine specific error reason for better diagnostics
223+
errorMsg := "Authentication failed."
224+
225+
errStr := err.Error()
226+
var errorReason string
227+
switch {
228+
case strings.Contains(errStr, "invalid GitHub token"):
229+
errorMsg = "Invalid GitHub token."
230+
errorReason = "invalid_token"
231+
case strings.Contains(errStr, "access forbidden"):
232+
errorMsg = "Access forbidden. Check token permissions."
233+
errorReason = "forbidden"
234+
case strings.Contains(errStr, "rate limit"):
235+
errorMsg = "GitHub API rate limit exceeded. Try again later."
236+
errorReason = "rate_limit"
237+
default:
238+
errorReason = errStr
239+
}
240+
222241
logger.Error("GitHub auth failed for wildcard org subscription", err, logger.Fields{
223242
"ip": ip,
224243
"token_prefix": tokenPrefix,
225244
"token_length": len(githubToken),
245+
"reason": errorReason,
226246
})
227247

228248
// Send error response to client
229249
errorResp := map[string]string{
230250
"type": "error",
231251
"error": "authentication_failed",
232-
"message": "Authentication failed.",
252+
"message": errorMsg,
233253
}
234254

235255
// Set a write deadline to ensure we don't hang forever
@@ -243,8 +263,11 @@ func (h *WebSocketHandler) validateAuth(ctx context.Context, ws *websocket.Conn,
243263
return nil, sendErr
244264
}
245265

246-
logger.Info("sent authentication error to client", logger.Fields{"ip": ip})
247-
return nil, errors.New("authentication failed")
266+
logger.Info("sent authentication error to client", logger.Fields{
267+
"ip": ip,
268+
"reason": errorReason,
269+
})
270+
return nil, fmt.Errorf("authentication failed: %s: %w", errorReason, err)
248271
}
249272

250273
logger.Info("GitHub authentication successful for wildcard org subscription", logger.Fields{
@@ -271,18 +294,47 @@ func (h *WebSocketHandler) validateAuth(ctx context.Context, ws *websocket.Conn,
271294
if len(githubToken) >= tokenPrefixLength {
272295
tokenPrefix = githubToken[:tokenPrefixLength]
273296
}
297+
298+
// Determine specific error reason for better diagnostics
299+
errorCode := "access_denied"
300+
errorMsg := "Access denied."
301+
302+
errStr := err.Error()
303+
var errorReason string
304+
switch {
305+
case strings.Contains(errStr, "invalid GitHub token"):
306+
errorCode = "authentication_failed"
307+
errorMsg = "Invalid GitHub token."
308+
errorReason = "invalid_token"
309+
case strings.Contains(errStr, "access forbidden"):
310+
errorCode = "access_denied"
311+
errorMsg = "Access forbidden. Check token permissions."
312+
errorReason = "forbidden"
313+
case strings.Contains(errStr, "not a member"):
314+
errorCode = "access_denied"
315+
errorMsg = fmt.Sprintf("You are not a member of organization '%s'.", sub.Organization)
316+
errorReason = "not_org_member"
317+
case strings.Contains(errStr, "rate limit"):
318+
errorCode = "rate_limit_exceeded"
319+
errorMsg = "GitHub API rate limit exceeded. Try again later."
320+
errorReason = "rate_limit"
321+
default:
322+
errorReason = errStr
323+
}
324+
274325
logger.Error("GitHub auth/org membership validation failed", err, logger.Fields{
275326
"ip": ip,
276327
"org": sub.Organization,
277328
"token_prefix": tokenPrefix,
278329
"token_length": len(githubToken),
330+
"reason": errorReason,
279331
})
280332

281333
// Send error response to client
282334
errorResp := map[string]string{
283335
"type": "error",
284-
"error": "access_denied",
285-
"message": "Access denied.",
336+
"error": errorCode,
337+
"message": errorMsg,
286338
}
287339

288340
// Set a write deadline to ensure we don't hang forever
@@ -296,8 +348,13 @@ func (h *WebSocketHandler) validateAuth(ctx context.Context, ws *websocket.Conn,
296348
return nil, sendErr
297349
}
298350

299-
logger.Info("sent access denied error to client", logger.Fields{"ip": ip, "org": sub.Organization})
300-
return nil, errors.New("access denied")
351+
logger.Info("sent error to client", logger.Fields{
352+
"ip": ip,
353+
"org": sub.Organization,
354+
"error_code": errorCode,
355+
"error_reason": errorReason,
356+
})
357+
return nil, fmt.Errorf("%s: %w", errorReason, err)
301358
}
302359

303360
logger.Info("GitHub authentication and org membership validated successfully", logger.Fields{
@@ -326,17 +383,38 @@ func (h *WebSocketHandler) validateAuth(ctx context.Context, ws *websocket.Conn,
326383
if len(githubToken) >= tokenPrefixLength {
327384
tokenPrefix = githubToken[:tokenPrefixLength]
328385
}
386+
387+
// Determine specific error reason for better diagnostics
388+
errorMsg := "Authentication failed. Please check your GitHub token."
389+
390+
errStr := err.Error()
391+
var errorReason string
392+
switch {
393+
case strings.Contains(errStr, "invalid GitHub token"):
394+
errorMsg = "Invalid GitHub token."
395+
errorReason = "invalid_token"
396+
case strings.Contains(errStr, "access forbidden"):
397+
errorMsg = "Access forbidden. Check token permissions."
398+
errorReason = "forbidden"
399+
case strings.Contains(errStr, "rate limit"):
400+
errorMsg = "GitHub API rate limit exceeded. Try again later."
401+
errorReason = "rate_limit"
402+
default:
403+
errorReason = errStr
404+
}
405+
329406
logger.Error("GitHub auth failed (no specific org)", err, logger.Fields{
330407
"ip": ip,
331408
"token_prefix": tokenPrefix,
332409
"token_length": len(githubToken),
410+
"reason": errorReason,
333411
})
334412

335413
// Send error response to client
336414
errorResp := map[string]string{
337415
"type": "error",
338416
"error": "authentication_failed",
339-
"message": "Authentication failed. Please check your GitHub token.",
417+
"message": errorMsg,
340418
}
341419

342420
// Set a write deadline to ensure we don't hang forever
@@ -350,8 +428,11 @@ func (h *WebSocketHandler) validateAuth(ctx context.Context, ws *websocket.Conn,
350428
return nil, sendErr
351429
}
352430

353-
logger.Info("sent authentication error to client", logger.Fields{"ip": ip})
354-
return nil, errors.New("authentication failed")
431+
logger.Info("sent authentication error to client", logger.Fields{
432+
"ip": ip,
433+
"reason": errorReason,
434+
})
435+
return nil, fmt.Errorf("authentication failed: %s: %w", errorReason, err)
355436
}
356437

357438
logger.Info("GitHub authentication successful", logger.Fields{

0 commit comments

Comments
 (0)