+14 -1

internal/handlers/brew.go

··· 504 504 } 505 505 506 506 if err := r.ParseForm(); err != nil { 507 507 + log.Warn().Err(err).Msg("Failed to parse brew create form") 507 508 http.Error(w, "Invalid form data", http.StatusBadRequest) 508 509 return 509 510 } ··· 511 512 // Validate input 512 513 temperature, waterAmount, coffeeAmount, timeSeconds, rating, pours, validationErrs := validateBrewRequest(r) 513 514 if len(validationErrs) > 0 { 514 514 - // Return first validation error 515 515 + log.Warn().Str("field", validationErrs[0].Field).Str("error", validationErrs[0].Message).Msg("Brew create validation failed") 515 516 http.Error(w, validationErrs[0].Message, http.StatusBadRequest) 516 517 return 517 518 } ··· 519 520 // Validate required fields 520 521 beanRKey := r.FormValue("bean_rkey") 521 522 if beanRKey == "" { 523 523 + log.Warn().Msg("Brew create: missing bean_rkey") 522 524 http.Error(w, "Bean selection is required", http.StatusBadRequest) 523 525 return 524 526 } 525 527 if !atproto.ValidateRKey(beanRKey) { 528 528 + log.Warn().Str("bean_rkey", beanRKey).Msg("Brew create: invalid bean rkey format") 526 529 http.Error(w, "Invalid bean selection", http.StatusBadRequest) 527 530 return 528 531 } ··· 530 533 // Validate optional rkeys 531 534 grinderRKey := r.FormValue("grinder_rkey") 532 535 if errMsg := validateOptionalRKey(grinderRKey, "Grinder selection"); errMsg != "" { 536 536 + log.Warn().Str("grinder_rkey", grinderRKey).Msg("Brew create: invalid grinder rkey") 533 537 http.Error(w, errMsg, http.StatusBadRequest) 534 538 return 535 539 } 536 540 brewerRKey := r.FormValue("brewer_rkey") 537 541 if errMsg := validateOptionalRKey(brewerRKey, "Brewer selection"); errMsg != "" { 542 542 + log.Warn().Str("brewer_rkey", brewerRKey).Msg("Brew create: invalid brewer rkey") 538 543 http.Error(w, errMsg, http.StatusBadRequest) 539 544 return 540 545 } ··· 555 560 } 556 561 557 562 if err := req.Validate(); err != nil { 563 563 + log.Warn().Err(err).Msg("Brew create request validation failed") 558 564 http.Error(w, err.Error(), http.StatusBadRequest) 559 565 return 560 566 } ··· 586 592 } 587 593 588 594 if err := r.ParseForm(); err != nil { 595 595 + log.Warn().Err(err).Str("rkey", rkey).Msg("Failed to parse brew update form") 589 596 http.Error(w, "Invalid form data", http.StatusBadRequest) 590 597 return 591 598 } ··· 593 600 // Validate input 594 601 temperature, waterAmount, coffeeAmount, timeSeconds, rating, pours, validationErrs := validateBrewRequest(r) 595 602 if len(validationErrs) > 0 { 603 603 + log.Warn().Str("rkey", rkey).Str("field", validationErrs[0].Field).Str("error", validationErrs[0].Message).Msg("Brew update validation failed") 596 604 http.Error(w, validationErrs[0].Message, http.StatusBadRequest) 597 605 return 598 606 } ··· 600 608 // Validate required fields 601 609 beanRKey := r.FormValue("bean_rkey") 602 610 if beanRKey == "" { 611 611 + log.Warn().Str("rkey", rkey).Msg("Brew update: missing bean_rkey") 603 612 http.Error(w, "Bean selection is required", http.StatusBadRequest) 604 613 return 605 614 } 606 615 if !atproto.ValidateRKey(beanRKey) { 616 616 + log.Warn().Str("rkey", rkey).Str("bean_rkey", beanRKey).Msg("Brew update: invalid bean rkey format") 607 617 http.Error(w, "Invalid bean selection", http.StatusBadRequest) 608 618 return 609 619 } ··· 611 621 // Validate optional rkeys 612 622 grinderRKey := r.FormValue("grinder_rkey") 613 623 if errMsg := validateOptionalRKey(grinderRKey, "Grinder selection"); errMsg != "" { 624 624 + log.Warn().Str("rkey", rkey).Str("grinder_rkey", grinderRKey).Msg("Brew update: invalid grinder rkey") 614 625 http.Error(w, errMsg, http.StatusBadRequest) 615 626 return 616 627 } 617 628 brewerRKey := r.FormValue("brewer_rkey") 618 629 if errMsg := validateOptionalRKey(brewerRKey, "Brewer selection"); errMsg != "" { 630 630 + log.Warn().Str("rkey", rkey).Str("brewer_rkey", brewerRKey).Msg("Brew update: invalid brewer rkey") 619 631 http.Error(w, errMsg, http.StatusBadRequest) 620 632 return 621 633 } ··· 636 648 } 637 649 638 650 if err := req.Validate(); err != nil { 651 651 + log.Warn().Err(err).Str("rkey", rkey).Msg("Brew update request validation failed") 639 652 http.Error(w, err.Error(), http.StatusBadRequest) 640 653 return 641 654 }

+18

internal/handlers/entities.go

··· 177 177 Msg("Parsed bean create form") 178 178 return nil 179 179 }); err != nil { 180 180 + log.Warn().Err(err).Msg("Failed to decode bean create request") 180 181 http.Error(w, "Invalid request body", http.StatusBadRequest) 181 182 return 182 183 } 183 184 184 185 // Validate request 185 186 if err := req.Validate(); err != nil { 187 187 + log.Warn().Err(err).Str("name", req.Name).Msg("Bean create validation failed") 186 188 http.Error(w, err.Error(), http.StatusBadRequest) 187 189 return 188 190 } 189 191 190 192 // Validate optional roaster rkey 191 193 if errMsg := validateOptionalRKey(req.RoasterRKey, "Roaster selection"); errMsg != "" { 194 194 + log.Warn().Str("roaster_rkey", req.RoasterRKey).Msg("Bean create: invalid roaster rkey") 192 195 http.Error(w, errMsg, http.StatusBadRequest) 193 196 return 194 197 } ··· 223 226 } 224 227 return nil 225 228 }); err != nil { 229 229 + log.Warn().Err(err).Msg("Failed to decode roaster create request") 226 230 http.Error(w, "Invalid request body", http.StatusBadRequest) 227 231 return 228 232 } 229 233 230 234 // Validate request 231 235 if err := req.Validate(); err != nil { 236 236 + log.Warn().Err(err).Str("name", req.Name).Msg("Roaster create validation failed") 232 237 http.Error(w, err.Error(), http.StatusBadRequest) 233 238 return 234 239 } ··· 299 304 Msg("Parsed bean update form") 300 305 return nil 301 306 }); err != nil { 307 307 + log.Warn().Err(err).Str("rkey", rkey).Msg("Failed to decode bean update request") 302 308 http.Error(w, "Invalid request body", http.StatusBadRequest) 303 309 return 304 310 } 305 311 306 312 // Validate request 307 313 if err := req.Validate(); err != nil { 314 314 + log.Warn().Err(err).Str("rkey", rkey).Msg("Bean update validation failed") 308 315 http.Error(w, err.Error(), http.StatusBadRequest) 309 316 return 310 317 } 311 318 312 319 // Validate optional roaster rkey 313 320 if errMsg := validateOptionalRKey(req.RoasterRKey, "Roaster selection"); errMsg != "" { 321 321 + log.Warn().Str("rkey", rkey).Str("roaster_rkey", req.RoasterRKey).Msg("Bean update: invalid roaster rkey") 314 322 http.Error(w, errMsg, http.StatusBadRequest) 315 323 return 316 324 } ··· 365 373 } 366 374 return nil 367 375 }); err != nil { 376 376 + log.Warn().Err(err).Str("rkey", rkey).Msg("Failed to decode roaster update request") 368 377 http.Error(w, "Invalid request body", http.StatusBadRequest) 369 378 return 370 379 } 371 380 372 381 // Validate request 373 382 if err := req.Validate(); err != nil { 383 383 + log.Warn().Err(err).Str("rkey", rkey).Msg("Roaster update validation failed") 374 384 http.Error(w, err.Error(), http.StatusBadRequest) 375 385 return 376 386 } ··· 421 431 } 422 432 return nil 423 433 }); err != nil { 434 434 + log.Warn().Err(err).Msg("Failed to decode grinder create request") 424 435 http.Error(w, "Invalid request body", http.StatusBadRequest) 425 436 return 426 437 } 427 438 428 439 // Validate request 429 440 if err := req.Validate(); err != nil { 441 441 + log.Warn().Err(err).Str("name", req.Name).Msg("Grinder create validation failed") 430 442 http.Error(w, err.Error(), http.StatusBadRequest) 431 443 return 432 444 } ··· 466 478 } 467 479 return nil 468 480 }); err != nil { 481 481 + log.Warn().Err(err).Str("rkey", rkey).Msg("Failed to decode grinder update request") 469 482 http.Error(w, "Invalid request body", http.StatusBadRequest) 470 483 return 471 484 } 472 485 473 486 // Validate request 474 487 if err := req.Validate(); err != nil { 488 488 + log.Warn().Err(err).Str("rkey", rkey).Msg("Grinder update validation failed") 475 489 http.Error(w, err.Error(), http.StatusBadRequest) 476 490 return 477 491 } ··· 521 535 } 522 536 return nil 523 537 }); err != nil { 538 538 + log.Warn().Err(err).Msg("Failed to decode brewer create request") 524 539 http.Error(w, "Invalid request body", http.StatusBadRequest) 525 540 return 526 541 } 527 542 528 543 // Validate request 529 544 if err := req.Validate(); err != nil { 545 545 + log.Warn().Err(err).Str("name", req.Name).Msg("Brewer create validation failed") 530 546 http.Error(w, err.Error(), http.StatusBadRequest) 531 547 return 532 548 } ··· 565 581 } 566 582 return nil 567 583 }); err != nil { 584 584 + log.Warn().Err(err).Str("rkey", rkey).Msg("Failed to decode brewer update request") 568 585 http.Error(w, "Invalid request body", http.StatusBadRequest) 569 586 return 570 587 } 571 588 572 589 // Validate request 573 590 if err := req.Validate(); err != nil { 591 591 + log.Warn().Err(err).Str("rkey", rkey).Msg("Brewer update validation failed") 574 592 http.Error(w, err.Error(), http.StatusBadRequest) 575 593 return 576 594 }

+17 -4

internal/handlers/feed.go

··· 87 87 88 88 if h.feedService != nil { 89 89 if isAuthenticated { 90 90 - result, _ := h.feedService.GetFeedWithQuery(r.Context(), feed.FeedQuery{ 90 90 + result, err := h.feedService.GetFeedWithQuery(r.Context(), feed.FeedQuery{ 91 91 Limit: feed.FeedLimit, 92 92 Cursor: cursor, 93 93 TypeFilter: typeFilter, 94 94 Sort: sortBy, 95 95 }) 96 96 + if err != nil { 97 97 + log.Error().Err(err).Str("sort", string(sortBy)).Str("type", string(typeFilter)).Msg("Failed to query feed") 98 98 + } 96 99 if result != nil { 97 100 feedItems = result.Items 98 101 nextCursor = result.NextCursor 99 102 } 100 103 } else { 101 104 // Unauthenticated users get a limited feed from the cache (no filtering) 102 102 - feedItems, _ = h.feedService.GetCachedPublicFeed(r.Context()) 105 105 + var err error 106 106 + feedItems, err = h.feedService.GetCachedPublicFeed(r.Context()) 107 107 + if err != nil { 108 108 + log.Error().Err(err).Msg("Failed to get cached public feed") 109 109 + } 103 110 } 104 111 } 105 112 ··· 155 162 didStr, _ := atproto.GetAuthenticatedDID(r.Context()) 156 163 157 164 if err := r.ParseForm(); err != nil { 165 165 + log.Warn().Err(err).Msg("Failed to parse like toggle form") 158 166 http.Error(w, "Invalid form data", http.StatusBadRequest) 159 167 return 160 168 } ··· 163 171 subjectCID := r.FormValue("subject_cid") 164 172 165 173 if subjectURI == "" || subjectCID == "" { 174 174 + log.Warn().Str("subject_uri", subjectURI).Str("subject_cid", subjectCID).Msg("Like toggle: missing required fields") 166 175 http.Error(w, "subject_uri and subject_cid are required", http.StatusBadRequest) 167 176 return 168 177 } ··· 190 199 191 200 // Update firehose index 192 201 if h.feedIndex != nil { 193 193 - _ = h.feedIndex.DeleteLike(didStr, subjectURI) 202 202 + if err := h.feedIndex.DeleteLike(didStr, subjectURI); err != nil { 203 203 + log.Warn().Err(err).Str("did", didStr).Str("subject_uri", subjectURI).Msg("Failed to delete like from feed index") 204 204 + } 194 205 likeCount = h.feedIndex.GetLikeCount(subjectURI) 195 206 } 196 207 } else { ··· 210 221 211 222 // Update firehose index 212 223 if h.feedIndex != nil { 213 213 - _ = h.feedIndex.UpsertLike(didStr, like.RKey, subjectURI) 224 224 + if err := h.feedIndex.UpsertLike(didStr, like.RKey, subjectURI); err != nil { 225 225 + log.Warn().Err(err).Str("did", didStr).Str("subject_uri", subjectURI).Msg("Failed to upsert like in feed index") 226 226 + } 214 227 likeCount = h.feedIndex.GetLikeCount(subjectURI) 215 228 } 216 229 }

+11 -2

internal/handlers/handlers.go

··· 270 270 didStr, _ := atproto.GetAuthenticatedDID(r.Context()) 271 271 272 272 if err := r.ParseForm(); err != nil { 273 273 + log.Warn().Err(err).Msg("Failed to parse comment create form") 273 274 http.Error(w, "Invalid form data", http.StatusBadRequest) 274 275 return 275 276 } ··· 281 282 parentCID := r.FormValue("parent_cid") 282 283 283 284 if subjectURI == "" || subjectCID == "" { 285 285 + log.Warn().Str("subject_uri", subjectURI).Str("subject_cid", subjectCID).Msg("Comment create: missing required fields") 284 286 http.Error(w, "subject_uri and subject_cid are required", http.StatusBadRequest) 285 287 return 286 288 } 287 289 288 290 if text == "" { 291 291 + log.Warn().Str("subject_uri", subjectURI).Msg("Comment create: empty text") 289 292 http.Error(w, "comment text is required", http.StatusBadRequest) 290 293 return 291 294 } 292 295 293 296 if len(text) > models.MaxCommentLength { 297 297 + log.Warn().Int("length", len(text)).Int("max", models.MaxCommentLength).Msg("Comment create: text too long") 294 298 http.Error(w, "comment text is too long", http.StatusBadRequest) 295 299 return 296 300 } 297 301 298 302 // Validate that parent fields are either both present or both absent 299 303 if (parentURI != "" && parentCID == "") || (parentURI == "" && parentCID != "") { 304 304 + log.Warn().Str("parent_uri", parentURI).Str("parent_cid", parentCID).Msg("Comment create: incomplete parent reference") 300 305 http.Error(w, "both parent_uri and parent_cid must be provided together", http.StatusBadRequest) 301 306 return 302 307 } ··· 320 325 321 326 // Update firehose index (pass parent URI and comment's CID for threading) 322 327 if h.feedIndex != nil { 323 323 - _ = h.feedIndex.UpsertComment(didStr, comment.RKey, subjectURI, parentURI, comment.CID, text, comment.CreatedAt) 328 328 + if err := h.feedIndex.UpsertComment(didStr, comment.RKey, subjectURI, parentURI, comment.CID, text, comment.CreatedAt); err != nil { 329 329 + log.Warn().Err(err).Str("did", didStr).Str("rkey", comment.RKey).Str("subject_uri", subjectURI).Msg("Failed to upsert comment in feed index") 330 330 + } 324 331 } 325 332 326 333 // Return the updated comment section with threaded comments ··· 398 405 399 406 // Update firehose index 400 407 if h.feedIndex != nil { 401 401 - _ = h.feedIndex.DeleteComment(didStr, rkey, subjectURI) 408 408 + if err := h.feedIndex.DeleteComment(didStr, rkey, subjectURI); err != nil { 409 409 + log.Warn().Err(err).Str("did", didStr).Str("rkey", rkey).Str("subject_uri", subjectURI).Msg("Failed to delete comment from feed index") 410 410 + } 402 411 } 403 412 404 413 // Return empty response (the comment element will be removed via hx-swap="outerHTML")

+23 -7

internal/middleware/logging.go

··· 78 78 Str("client_ip", GetClientIP(r)). 79 79 Str("user_agent", r.UserAgent()). 80 80 Int64("bytes_written", rw.bytesWritten). 81 81 - Str("proto", r.Proto) 81 81 + Str("proto", r.Proto). 82 82 + Str("arabica_cookies", getCookies(r)) 82 83 83 84 // Add optional fields only if present 84 85 if referer := r.Referer(); referer != "" { ··· 90 91 if contentType := r.Header.Get("Content-Type"); contentType != "" { 91 92 logEvent.Str("content_type", contentType) 92 93 } 94 94 + // FIX: this doesn't seem to be logging correctly? 93 95 if did, err := atproto.GetAuthenticatedDID(r.Context()); err == nil && did != "" { 94 96 logEvent.Str("user_did", did) 95 97 } 96 98 97 97 - // Log all request headers for debugging malicious traffic 98 98 - headers := make(map[string]string) 99 99 - for name, values := range r.Header { 100 100 - headers[name] = strings.Join(values, ", ") 99 99 + if logger.GetLevel() == zerolog.DebugLevel { 100 100 + // Log all request headers for debugging malicious traffic (debug mode only) 101 101 + headers := make(map[string]string) 102 102 + for name, values := range r.Header { 103 103 + headers[name] = strings.Join(values, ", ") 104 104 + } 105 105 + logEvent.Interface("headers", headers) 101 106 } 102 102 - logEvent.Interface("headers", headers) 103 107 104 104 - logEvent.Msg("HTTP request") 108 108 + logEvent.Msgf("Incoming HTTP request: %s %s %d", r.Method, r.URL.Path, rw.statusCode) 105 109 106 110 // Record Prometheus metrics 107 111 normalizedPath := metrics.NormalizePath(r.URL.Path) ··· 135 139 rw.bytesWritten += int64(n) 136 140 return n, err 137 141 } 142 142 + 143 143 + func getCookies(r *http.Request) string { 144 144 + sb := strings.Builder{} 145 145 + loggedCookies := []string{"account_did", "session_id"} 146 146 + for _, name := range loggedCookies { 147 147 + // TODO: check if `c.Domain == "arabica.social"` if we start adding it 148 148 + if c, err := r.Cookie(name); err == nil { 149 149 + _, _ = sb.WriteString(c.Value + "; ") 150 150 + } 151 151 + } 152 152 + return sb.String() 153 153 + }