Files
XQKqueue/server/internal/httpapi/http_logging.go

481 lines
13 KiB
Go

package httpapi
import (
"bytes"
"encoding/json"
"errors"
"io"
"net/http"
"regexp"
"strconv"
"strings"
"time"
"calllinesystem/server/internal/security"
)
const (
maxLoggedBody = 64 << 10
redactedLogText = "[REDACTED]"
)
var (
phoneInLogTextPattern = regexp.MustCompile(`(?:\+[0-9][0-9 ()-]{6,20}[0-9]|[0-9]{10,15})`)
importantLogRoutes = map[string]struct{}{
"POST /api/staff/auth/login": {},
"POST /api/staff/auth/logout": {},
"GET /api/staff/auth/me": {},
"POST /api/admin/auth/login": {},
"POST /api/admin/auth/logout": {},
"GET /api/admin/auth/me": {},
"GET /api/staff/projects": {},
"GET /api/staff/projects/{id}/queue": {},
"POST /api/staff/projects/{id}/tickets": {},
"POST /api/staff/projects/{id}/call-next": {},
"GET /api/public/status/{token}": {},
"GET /api/public/projects": {},
"POST /api/public/projects/{id}/tickets": {},
"POST /api/public/status/search": {},
"POST /api/internal/status/search": {},
"GET /api/display/{token}/snapshot": {},
"GET /api/events": {},
"GET /api/admin/overview": {},
"GET /api/admin/users": {},
"POST /api/admin/users": {},
"PUT /api/admin/users/{id}": {},
"POST /api/admin/projects": {},
"PUT /api/admin/projects/{id}": {},
"PUT /api/admin/projects/{id}/settings": {},
"GET /api/admin/history/tickets": {},
"GET /api/admin/history/tickets/{id}": {},
"GET /api/admin/history/batches": {},
"GET /api/admin/history/batches/{id}": {},
"GET /api/admin/history/summary": {},
"GET /api/admin/history/export.csv": {},
}
)
type logBodyCapture struct {
body bytes.Buffer
total int
truncated bool
}
func (capture *logBodyCapture) Write(value []byte) (int, error) {
capture.total += len(value)
remaining := maxLoggedBody - capture.body.Len()
if remaining <= 0 {
if len(value) > 0 {
capture.truncated = true
}
return len(value), nil
}
toCopy := min(remaining, len(value))
if toCopy > 0 {
_, _ = capture.body.Write(value[:toCopy])
}
if toCopy < len(value) {
capture.truncated = true
}
return len(value), nil
}
type logCaptureReadCloser struct {
io.ReadCloser
capture *logBodyCapture
}
func (reader *logCaptureReadCloser) Read(value []byte) (int, error) {
n, err := reader.ReadCloser.Read(value)
if n > 0 {
_, _ = reader.capture.Write(value[:n])
}
return n, err
}
func shouldCaptureLogBody(r *http.Request) bool {
if !strings.HasPrefix(r.URL.Path, "/api/") {
return false
}
return r.URL.Path != "/api/events" && r.URL.Path != "/api/admin/history/export.csv"
}
func isImportantLogRoute(r *http.Request) bool {
_, ok := importantLogRoutes[logRoutePattern(r)]
return ok
}
func logRoutePattern(r *http.Request) string {
if route := strings.TrimSpace(r.Pattern); route != "" {
return route
}
return r.Method + " " + r.URL.Path
}
func logPath(r *http.Request) string {
pattern := strings.TrimSpace(r.Pattern)
if pattern != "" {
if _, path, found := strings.Cut(pattern, " "); found {
return path
}
return pattern
}
switch {
case strings.HasPrefix(r.URL.Path, "/api/public/status/"):
return "/api/public/status/{token}"
case strings.HasPrefix(r.URL.Path, "/api/display/") && strings.HasSuffix(r.URL.Path, "/snapshot"):
return "/api/display/{token}/snapshot"
default:
return r.URL.Path
}
}
func requestLogDetails(r *http.Request, capture *logBodyCapture) map[string]any {
details := make(map[string]any)
pathParams := make(map[string]any)
if id := strings.TrimSpace(r.PathValue("id")); id != "" {
if validateUUID(id) == nil {
pathParams["id"] = id
} else {
pathParams["id"] = "[INVALID]"
}
}
if token := strings.TrimSpace(r.PathValue("token")); token != "" {
pathParams["token"] = redactedLogText
}
if len(pathParams) > 0 {
details["path_params"] = pathParams
}
if values := r.URL.Query(); len(values) > 0 {
query := make(map[string]any, len(values))
omitted := 0
for field, items := range values {
if !allowedLogQueryField(logRoutePattern(r), field) {
omitted += len(items)
continue
}
sanitized := make([]any, 0, len(items))
for _, item := range items {
sanitized = append(sanitized, sanitizeLogQueryValue(field, item))
}
query[field] = sanitized
}
if omitted > 0 {
query["_omitted_parameter_count"] = omitted
}
details["query"] = query
}
if strings.TrimSpace(r.Header.Get("Idempotency-Key")) != "" {
details["idempotency_key_present"] = true
}
appendCapturedLogBody(details, capture, r.Header.Get("Content-Type"), func(value any) (any, bool) {
return sanitizeRequestLogBody(r, capture.body.Bytes(), value)
})
if len(details) == 0 {
return nil
}
return details
}
func responseLogDetails(r *http.Request, recorder *statusRecorder) map[string]any {
if recorder.body == nil {
switch r.URL.Path {
case "/api/events":
return map[string]any{"body_omitted": "event_stream"}
case "/api/admin/history/export.csv":
return map[string]any{"body_omitted": "file_download"}
default:
return nil
}
}
details := make(map[string]any)
appendCapturedLogBody(details, recorder.body, recorder.Header().Get("Content-Type"), func(value any) (any, bool) {
return sanitizeLogValue("", value), true
})
if len(details) == 0 {
return nil
}
return details
}
func appendCapturedLogBody(
target map[string]any,
capture *logBodyCapture,
contentType string,
sanitize func(any) (any, bool),
) {
if capture == nil || capture.total == 0 {
return
}
target["body_bytes"] = capture.total
if contentType != "" {
target["content_type"] = contentType
}
if capture.truncated {
target["body_truncated"] = true
return
}
var value any
if err := json.Unmarshal(capture.body.Bytes(), &value); err != nil {
target["body_omitted"] = "invalid_or_non_json"
return
}
sanitized, ok := sanitize(value)
if !ok {
target["body_omitted"] = "invalid_or_unsupported_request_json"
return
}
target["body"] = sanitized
}
func sanitizeRequestLogBody(r *http.Request, raw []byte, value any) (any, bool) {
schema := requestLogSchema(logRoutePattern(r))
if schema == nil {
return nil, false
}
decoder := json.NewDecoder(bytes.NewReader(raw))
decoder.DisallowUnknownFields()
if err := decoder.Decode(schema); err != nil {
return nil, false
}
if err := decoder.Decode(&struct{}{}); !errors.Is(err, io.EOF) {
return nil, false
}
return sanitizeLogValue("", value), true
}
func requestLogSchema(route string) any {
switch route {
case "POST /api/staff/auth/login", "POST /api/admin/auth/login":
return &loginRequest{}
case "POST /api/staff/projects/{id}/tickets", "POST /api/public/projects/{id}/tickets":
return &createTicketRequest{}
case "POST /api/staff/projects/{id}/call-next":
return &callNextRequest{}
case "POST /api/public/status/search", "POST /api/internal/status/search":
return &publicPhoneQueryRequest{}
case "POST /api/admin/users", "PUT /api/admin/users/{id}":
return &adminUserRequest{}
case "POST /api/admin/projects", "PUT /api/admin/projects/{id}":
return &adminProjectRequest{}
case "PUT /api/admin/projects/{id}/settings":
return &updateProjectSettingsRequest{}
default:
return nil
}
}
func allowedLogQueryField(route, field string) bool {
switch route {
case "GET /api/events":
return field == "project_id"
case "GET /api/admin/history/tickets":
return isLogQueryField(field, "from", "to", "project_id", "status", "query", "page", "page_size")
case "GET /api/admin/history/tickets/{id}":
return field == "reveal"
case "GET /api/admin/history/batches":
return isLogQueryField(field, "from", "to", "project_id", "status", "query", "page", "page_size")
case "GET /api/admin/history/summary":
return isLogQueryField(field, "from", "to", "project_id", "status", "query")
case "GET /api/admin/history/export.csv":
return isLogQueryField(field, "from", "to", "project_id", "status", "query", "include_personal", "confirm")
default:
return false
}
}
func isLogQueryField(field string, allowed ...string) bool {
for _, candidate := range allowed {
if field == candidate {
return true
}
}
return false
}
func sanitizeLogQueryValue(field, value string) any {
switch field {
case "project_id":
if validateUUID(value) != nil {
return "[INVALID]"
}
return value
case "from", "to":
if _, err := time.Parse("2006-01-02", value); err != nil {
return "[INVALID]"
}
return value
case "status":
status := strings.ToUpper(strings.TrimSpace(value))
if !historyTicketStatuses[status] && !historyBatchStatuses[status] {
return "[INVALID]"
}
return status
case "page", "page_size":
number, err := strconv.Atoi(value)
if err != nil || number < 1 {
return "[INVALID]"
}
return number
case "include_personal", "confirm", "reveal":
switch strings.ToLower(strings.TrimSpace(value)) {
case "true", "1":
return true
case "false", "0":
return false
default:
return "[INVALID]"
}
case "query":
if normalized, err := security.NormalizePhone(value); err == nil {
return maskPhoneForLog(normalized)
}
if value == "" {
return ""
}
return "[PRESENT]"
default:
return "[OMITTED]"
}
}
func sanitizeLogValue(field string, value any) any {
normalizedField := normalizeLogField(field)
switch {
case isPhoneLogField(normalizedField):
if strings.Contains(normalizedField, "hmac") ||
strings.Contains(normalizedField, "cipher") ||
strings.Contains(normalizedField, "nonce") {
return redactedLogText
}
phone, ok := value.(string)
if !ok {
return redactedLogText
}
return maskPhoneForLog(phone)
case normalizedField == "last_name" ||
normalizedField == "surname" ||
normalizedField == "honorific" ||
normalizedField == "public_url" ||
normalizedField == "status_path":
return redactedLogText
case isUserIdentifierLogField(normalizedField):
identifier, ok := value.(string)
if !ok {
return redactedLogText
}
return maskIdentifierForLog(identifier)
case normalizedField == "query" ||
normalizedField == "search" ||
normalizedField == "q":
query, ok := value.(string)
if ok {
if normalized, err := security.NormalizePhone(query); err == nil {
return maskPhoneForLog(normalized)
}
}
case normalizedField == "visitor_notice":
return "[OMITTED]"
case isCredentialLogField(normalizedField):
return redactedLogText
}
switch typed := value.(type) {
case map[string]any:
sanitized := make(map[string]any, len(typed))
for childField, childValue := range typed {
sanitized[childField] = sanitizeLogValue(childField, childValue)
}
return sanitized
case []any:
sanitized := make([]any, 0, len(typed))
for _, childValue := range typed {
sanitized = append(sanitized, sanitizeLogValue(field, childValue))
}
return sanitized
case string:
return sanitizeLogString(field, typed)
default:
return value
}
}
func sanitizeLogString(field string, value string) string {
if strings.Contains(value, "/visitor/") ||
strings.Contains(value, "/api/public/status/") ||
strings.Contains(value, "/api/display/") {
return redactedLogText
}
return phoneInLogTextPattern.ReplaceAllStringFunc(value, maskPhoneForLog)
}
func normalizeLogField(field string) string {
return strings.ToLower(strings.ReplaceAll(strings.TrimSpace(field), "-", "_"))
}
func isPhoneLogField(field string) bool {
return strings.Contains(field, "phone") ||
strings.Contains(field, "mobile") ||
strings.Contains(field, "contact") ||
field == "tel" ||
strings.HasSuffix(field, "_tel")
}
func isCredentialLogField(field string) bool {
return strings.Contains(field, "password") ||
strings.Contains(field, "passwd") ||
strings.Contains(field, "token") ||
strings.Contains(field, "cookie") ||
strings.Contains(field, "authorization") ||
strings.Contains(field, "secret") ||
strings.Contains(field, "ciphertext") ||
strings.HasSuffix(field, "_nonce") ||
strings.Contains(field, "hmac") ||
strings.HasSuffix(field, "_hash") ||
strings.Contains(field, "digest") ||
field == "key" ||
strings.HasSuffix(field, "_key") ||
field == "pin" ||
strings.Contains(field, "otp") ||
strings.Contains(field, "captcha") ||
strings.Contains(field, "verification_code")
}
func isUserIdentifierLogField(field string) bool {
switch field {
case "username", "display_name", "created_by", "created_by_name", "requested_by", "requested_by_name":
return true
default:
return strings.HasSuffix(field, "_username")
}
}
func maskPhoneForLog(value string) string {
digits := make([]byte, 0, len(value))
for i := 0; i < len(value); i++ {
if value[i] >= '0' && value[i] <= '9' {
digits = append(digits, value[i])
}
}
if len(digits) < 4 {
return redactedLogText
}
return "****" + string(digits[len(digits)-4:])
}
func maskIdentifierForLog(value string) string {
runes := []rune(strings.TrimSpace(value))
switch len(runes) {
case 0:
return ""
case 1:
return "***"
case 2:
return string(runes[0]) + "***"
default:
return string(runes[0]) + "***" + string(runes[len(runes)-1])
}
}