diff --git a/pkg/diagnosticlog/diagnosticlog.go b/pkg/diagnosticlog/diagnosticlog.go index a8e5727..12422a6 100644 --- a/pkg/diagnosticlog/diagnosticlog.go +++ b/pkg/diagnosticlog/diagnosticlog.go @@ -21,7 +21,9 @@ func SQLSummary(query string) string { } func SafeLogValue(rawValue string) string { - cleanValue := strings.TrimSpace(rawValue) + cleanValue := strings.ReplaceAll(rawValue, "\r", "") + cleanValue = strings.ReplaceAll(cleanValue, "\n", "") + cleanValue = strings.TrimSpace(cleanValue) if cleanValue == "" { return "-" } diff --git a/pkg/diagnosticlog/diagnosticlog_test.go b/pkg/diagnosticlog/diagnosticlog_test.go new file mode 100644 index 0000000..11525c5 --- /dev/null +++ b/pkg/diagnosticlog/diagnosticlog_test.go @@ -0,0 +1,16 @@ +package diagnosticlog + +import ( + "strings" + "testing" +) + +func TestSafeLogValueRemovesLogEntryDelimiters(t *testing.T) { + safeValue := SafeLogValue("first\r\nforged\x00entry") + if strings.ContainsAny(safeValue, "\r\n\x00") { + t.Fatalf("safe log value contains a control character: %q", safeValue) + } + if safeValue != "firstforgedentry" { + t.Fatalf("safe log value = %q, want %q", safeValue, "firstforgedentry") + } +} diff --git a/pkg/dirprotect/dirprotect.go b/pkg/dirprotect/dirprotect.go index 692290d..ca260bd 100644 --- a/pkg/dirprotect/dirprotect.go +++ b/pkg/dirprotect/dirprotect.go @@ -1,13 +1,16 @@ package dirprotect import ( + "crypto/hmac" "crypto/sha256" - "crypto/subtle" "fmt" + "hash/fnv" "path" "strconv" "strings" "time" + + "golang.org/x/crypto/bcrypt" ) type Rule struct { @@ -40,18 +43,29 @@ func HasProtectedPrefix(pagePath, protectedPrefix string) bool { return pagePath == protectedPrefix || strings.HasPrefix(pagePath, protectedPrefix+"/") } -func Hash(password string) string { - hashedBytes := sha256.Sum256([]byte("sitebrush page password\n" + password)) - return fmt.Sprintf("sha256:%x", hashedBytes) +func Hash(password string) (string, error) { + hashedBytes, err := bcrypt.GenerateFromPassword(passwordPrehash(password), bcrypt.DefaultCost) + if err != nil { + return "", fmt.Errorf("hash page password: %w", err) + } + return string(hashedBytes), nil } func Matches(storedHash, password string) bool { - return strings.TrimSpace(storedHash) == Hash(password) + err := bcrypt.CompareHashAndPassword([]byte(strings.TrimSpace(storedHash)), passwordPrehash(password)) + return err == nil +} + +func passwordPrehash(password string) []byte { + prehash := hmac.New(sha256.New, []byte("sitebrush page password bcrypt prehash v1")) + _, _ = prehash.Write([]byte(password)) + return prehash.Sum(nil) } func CookieName(domain, pagePath string) string { - hashedBytes := sha256.Sum256([]byte(NormalizeDomain(domain) + "\n" + CleanPath(pagePath))) - return "sitebrush_page_password_" + fmt.Sprintf("%x", hashedBytes)[:16] + cookieIdentifier := fnv.New64a() + _, _ = cookieIdentifier.Write([]byte(NormalizeDomain(domain) + "\n" + CleanPath(pagePath))) + return "sitebrush_page_password_" + fmt.Sprintf("%016x", cookieIdentifier.Sum64()) } func BoundSessionToken(rule Rule, clientIP, userAgent string, issuedAt time.Time) string { @@ -80,7 +94,7 @@ func BoundSessionTokenValid(rule Rule, token, clientIP, userAgent string, now ti return false } expectedToken := BoundSessionToken(rule, clientIP, userAgent, issuedAt) - return subtle.ConstantTimeCompare([]byte(expectedToken), []byte(strings.TrimSpace(token))) == 1 + return hmac.Equal([]byte(expectedToken), []byte(strings.TrimSpace(token))) } func FailureDomain(domain, pagePath string) string { @@ -171,13 +185,13 @@ func NormalizeDomain(domain string) string { } func boundSessionSignature(rule Rule, clientIP string, issuedUnix int64) string { - hashedBytes := sha256.Sum256([]byte(strings.Join([]string{ + signature := hmac.New(sha256.New, []byte(strings.TrimSpace(rule.PasswordHash))) + _, _ = signature.Write([]byte(strings.Join([]string{ "sitebrush page password session v2", NormalizeDomain(rule.Domain), CleanPath(rule.Path), - strings.TrimSpace(rule.PasswordHash), strings.TrimSpace(clientIP), strconv.FormatInt(issuedUnix, 10), }, "\n"))) - return fmt.Sprintf("%x", hashedBytes) + return fmt.Sprintf("%x", signature.Sum(nil)) } diff --git a/pkg/dirprotect/dirprotect_test.go b/pkg/dirprotect/dirprotect_test.go index 2c2710e..ea7162b 100644 --- a/pkg/dirprotect/dirprotect_test.go +++ b/pkg/dirprotect/dirprotect_test.go @@ -8,8 +8,8 @@ import ( func TestFindBestRuleUsesPathBoundaries(t *testing.T) { rules := []Rule{ - {Domain: "localhost", Path: "/passport", PasswordHash: Hash("secret")}, - {Domain: "localhost", Path: "/passport/deep", PasswordHash: Hash("deeper")}, + {Domain: "localhost", Path: "/passport", PasswordHash: mustHashForTest(t, "secret")}, + {Domain: "localhost", Path: "/passport/deep", PasswordHash: mustHashForTest(t, "deeper")}, } rule, found := FindBestRule("localhost", "/passport/deep/page", rules) @@ -26,7 +26,7 @@ func TestFindBestRuleUsesPathBoundaries(t *testing.T) { } func TestPrefixFileRoundTrip(t *testing.T) { - rule := Rule{Domain: "localhost", Path: "/passport", PasswordHash: Hash("secret")} + rule := Rule{Domain: "localhost", Path: "/passport", PasswordHash: mustHashForTest(t, "secret")} body := PrefixFileBody([]Rule{rule}) parsedRule, found := FindBestRuleInPrefixData("localhost", "/passport/one", body) if !found { @@ -41,7 +41,7 @@ func TestPrefixFileRoundTrip(t *testing.T) { } func TestBoundSessionTokenRequiresSameClientConditions(t *testing.T) { - rule := Rule{Domain: "Example.COM.", Path: "/passport", PasswordHash: Hash("secret")} + rule := Rule{Domain: "Example.COM.", Path: "/passport", PasswordHash: mustHashForTest(t, "secret")} issuedAt := time.Unix(1_700_000_000, 0).UTC() token := BoundSessionToken(rule, "198.51.100.10", "Test Browser", issuedAt) if !strings.HasPrefix(token, "v2:") { @@ -59,10 +59,36 @@ func TestBoundSessionTokenRequiresSameClientConditions(t *testing.T) { } func TestBoundSessionTokenExpiresAfterTTL(t *testing.T) { - rule := Rule{Domain: "localhost", Path: "/passport", PasswordHash: Hash("secret")} + rule := Rule{Domain: "localhost", Path: "/passport", PasswordHash: mustHashForTest(t, "secret")} issuedAt := time.Unix(1_700_000_000, 0).UTC() token := BoundSessionToken(rule, "198.51.100.10", "Test Browser", issuedAt) if BoundSessionTokenValid(rule, token, "198.51.100.10", "Test Browser", issuedAt.Add(time.Hour+time.Second), time.Hour) { t.Fatal("token should expire after the configured TTL") } } + +func TestHashUsesPasswordHashingAlgorithm(t *testing.T) { + password := strings.Repeat("long password ", 20) + passwordHash := mustHashForTest(t, password) + if strings.HasPrefix(passwordHash, "sha256:") { + t.Fatalf("password hash uses legacy fast digest: %s", passwordHash) + } + if !Matches(passwordHash, password) { + t.Fatal("password hash did not match its password") + } + if Matches(passwordHash, "incorrect") { + t.Fatal("password hash matched an incorrect password") + } + if Matches("sha256:09e591c2a216e7264dd10d10b65a0092d7a0c5b5c9927642df8c29c10c30aeb2", "secret") { + t.Fatal("legacy fast password digest was accepted") + } +} + +func mustHashForTest(t *testing.T, password string) string { + t.Helper() + passwordHash, err := Hash(password) + if err != nil { + t.Fatalf("hash password: %v", err) + } + return passwordHash +} diff --git a/sitebrush.go b/sitebrush.go index 0b0933f..b39c1af 100644 --- a/sitebrush.go +++ b/sitebrush.go @@ -1188,36 +1188,44 @@ func siteDBWorkloadName(kind siteDBWorkloadKind) string { } func (db *siteFileDatabase) logDatabaseOperationWaiting(stage string, operation siteDBOperation, duration time.Duration) { - log.Printf("%sDB WORKER%s waiting stage=%s path=%s domain=%s kind=%s duration=%s queues=write:%d,read:%d,general:%d sql=%q", - terminalYellow(), terminalReset(), stage, db.path, domainFromContext(operation.ctx), siteDBWorkloadName(operation.kind), duration.String(), - len(db.writeQueue), len(db.readQueue), len(db.generalQueue), diagnosticlog.SQLSummary(operation.query)) + log.Printf("%sDB WORKER%s waiting stage=%s path=%s domain=%s kind=%s duration=%s queues=write:%d,read:%d,general:%d", + terminalYellow(), terminalReset(), diagnosticlog.SafeLogValue(stage), diagnosticlog.SafeLogValue(db.path), + diagnosticlog.SafeLogValue(domainFromContext(operation.ctx)), siteDBWorkloadName(operation.kind), duration.String(), + len(db.writeQueue), len(db.readQueue), len(db.generalQueue)) } func (db *siteFileDatabase) logDatabaseOperationFinished(operation siteDBOperation, duration time.Duration, err error) { status := "ok" logColor := terminalCyan() if err != nil { - status = err.Error() + status = diagnosticlog.SafeLogValue(err.Error()) logColor = terminalRed() } - log.Printf("%sDB WORKER%s operation finished path=%s domain=%s kind=%s duration=%s status=%q sql=%q", - logColor, terminalReset(), db.path, domainFromContext(operation.ctx), siteDBWorkloadName(operation.kind), duration.String(), status, diagnosticlog.SQLSummary(operation.query)) + log.Printf("%sDB WORKER%s operation finished path=%s domain=%s kind=%s duration=%s status=%q", + logColor, terminalReset(), diagnosticlog.SafeLogValue(db.path), diagnosticlog.SafeLogValue(domainFromContext(operation.ctx)), + siteDBWorkloadName(operation.kind), duration.String(), status) } func (db *siteFileDatabase) logDatabaseOperationResponse(operation siteDBOperation, duration time.Duration, err error) { status := "ok" logColor := terminalCyan() if err != nil { - status = err.Error() + status = diagnosticlog.SafeLogValue(err.Error()) logColor = terminalRed() } - log.Printf("%sDB WORKER%s response delivered path=%s domain=%s kind=%s duration=%s status=%q sql=%q", - logColor, terminalReset(), db.path, domainFromContext(operation.ctx), siteDBWorkloadName(operation.kind), duration.String(), status, diagnosticlog.SQLSummary(operation.query)) + log.Printf("%sDB WORKER%s response delivered path=%s domain=%s kind=%s duration=%s status=%q", + logColor, terminalReset(), diagnosticlog.SafeLogValue(db.path), diagnosticlog.SafeLogValue(domainFromContext(operation.ctx)), + siteDBWorkloadName(operation.kind), duration.String(), status) } func (db *siteFileDatabase) logDatabaseOperationCanceled(operation siteDBOperation) { - log.Printf("%sDB WORKER%s operation skipped path=%s domain=%s kind=%s status=%q sql=%q", - terminalYellow(), terminalReset(), db.path, domainFromContext(operation.ctx), siteDBWorkloadName(operation.kind), operation.ctx.Err(), diagnosticlog.SQLSummary(operation.query)) + status := "-" + if operation.ctx.Err() != nil { + status = diagnosticlog.SafeLogValue(operation.ctx.Err().Error()) + } + log.Printf("%sDB WORKER%s operation skipped path=%s domain=%s kind=%s status=%q", + terminalYellow(), terminalReset(), diagnosticlog.SafeLogValue(db.path), diagnosticlog.SafeLogValue(domainFromContext(operation.ctx)), + siteDBWorkloadName(operation.kind), status) } // perSiteDBRouter resolves a separate sqlite file per domain and keeps the map @@ -1736,14 +1744,17 @@ func (r *perSiteDBRouter) QueryRowContext(ctx context.Context, query string, arg database, err := r.databaseForContext(ctx) if err != nil { if r.debug { - log.Printf("%sDB ROUTER%s query-row fallback domain=%s err=%v sql=%q", terminalYellow(), terminalReset(), domainFromContext(ctx), err, diagnosticlog.SQLSummary(query)) + log.Printf("%sDB ROUTER%s query-row fallback domain=%s err=%s", + terminalYellow(), terminalReset(), diagnosticlog.SafeLogValue(domainFromContext(ctx)), diagnosticlog.SafeLogValue(err.Error())) } return r.noopDatabase.QueryRowContext(ctx, `SELECT 1 WHERE 0`) } row, err := database.QueryRowContext(ctx, query, args...) if err != nil { if r.debug { - log.Printf("%sDB ROUTER%s query-row fallback domain=%s path=%s err=%v sql=%q", terminalYellow(), terminalReset(), domainFromContext(ctx), database.path, err, diagnosticlog.SQLSummary(query)) + log.Printf("%sDB ROUTER%s query-row fallback domain=%s path=%s err=%s", + terminalYellow(), terminalReset(), diagnosticlog.SafeLogValue(domainFromContext(ctx)), + diagnosticlog.SafeLogValue(database.path), diagnosticlog.SafeLogValue(err.Error())) } return r.noopDatabase.QueryRowContext(ctx, `SELECT 1 WHERE 0`) } @@ -1782,10 +1793,13 @@ func (r *perSiteDBRouter) databaseForContext(ctx context.Context) (*siteFileData case r.requests <- request: sent = true case <-ctx.Done(): - log.Printf("%sDB ROUTER%s request canceled before send domain=%s duration=%s err=%v", terminalYellow(), terminalReset(), domain, time.Since(sendStartedAt).String(), ctx.Err()) + log.Printf("%sDB ROUTER%s request canceled before send domain=%s duration=%s err=%s", + terminalYellow(), terminalReset(), diagnosticlog.SafeLogValue(domain), time.Since(sendStartedAt).String(), + diagnosticlog.SafeLogValue(ctx.Err().Error())) return nil, ctx.Err() case <-sendTimer.C: - log.Printf("%sDB ROUTER%s waiting stage=send domain=%s duration=%s", terminalYellow(), terminalReset(), domain, time.Since(sendStartedAt).String()) + log.Printf("%sDB ROUTER%s waiting stage=send domain=%s duration=%s", + terminalYellow(), terminalReset(), diagnosticlog.SafeLogValue(domain), time.Since(sendStartedAt).String()) sendTimer.Reset(slowDatabaseOperationRepeatAfter) } } @@ -1796,12 +1810,15 @@ func (r *perSiteDBRouter) databaseForContext(ctx context.Context) (*siteFileData for { select { case <-ctx.Done(): - log.Printf("%sDB ROUTER%s request canceled while waiting domain=%s duration=%s err=%v", terminalYellow(), terminalReset(), domain, time.Since(waitStartedAt).String(), ctx.Err()) + log.Printf("%sDB ROUTER%s request canceled while waiting domain=%s duration=%s err=%s", + terminalYellow(), terminalReset(), diagnosticlog.SafeLogValue(domain), time.Since(waitStartedAt).String(), + diagnosticlog.SafeLogValue(ctx.Err().Error())) return nil, ctx.Err() case next := <-response: return next.db, next.err case <-waitTimer.C: - log.Printf("%sDB ROUTER%s waiting stage=response domain=%s duration=%s", terminalYellow(), terminalReset(), domain, time.Since(waitStartedAt).String()) + log.Printf("%sDB ROUTER%s waiting stage=response domain=%s duration=%s", + terminalYellow(), terminalReset(), diagnosticlog.SafeLogValue(domain), time.Since(waitStartedAt).String()) waitTimer.Reset(slowDatabaseOperationRepeatAfter) } } @@ -2411,16 +2428,20 @@ func (a *App) accessLogMiddleware(next http.Handler) http.Handler { colorReset = "\033[0m" ) startedAt := time.Now() - requestDomain := requestLogDomain(r) + requestDomain := diagnosticlog.SafeLogValue(requestLogDomain(r)) + requestMethod := diagnosticlog.SafeLogValue(r.Method) + requestPath := diagnosticlog.SafeLogValue(r.URL.Path) + requestQuery := diagnosticlog.SafeLogValue(r.URL.RawQuery) + requestRemoteAddress := diagnosticlog.SafeLogValue(r.RemoteAddr) if a.debug { requestFields := requestDiagnosticFields{ - Scheme: requestScheme(r), + Scheme: diagnosticlog.SafeLogValue(requestScheme(r)), Host: diagnosticlog.SafeLogValue(r.Host), Domain: requestDomain, - Method: r.Method, - Path: r.URL.Path, - Query: diagnosticlog.SafeLogValue(r.URL.RawQuery), - Remote: r.RemoteAddr, + Method: requestMethod, + Path: requestPath, + Query: requestQuery, + Remote: requestRemoteAddress, } done := make(chan struct{}) log.Printf("%sREQUEST [%s]%s started scheme=%s host=%s method=%s path=%s query=%s remote=%s", @@ -2451,12 +2472,16 @@ func (a *App) accessLogMiddleware(next http.Handler) http.Handler { } duration := time.Since(startedAt) if strings.TrimSpace(r.URL.RawQuery) == "" { - log.Printf("%s%s [%s]%s method=%s path=%s status=%d remote=%s duration=%s", logColor, logType, requestDomain, colorReset, r.Method, r.URL.Path, writer.statusCode, r.RemoteAddr, duration.String()) - a.writeDomainLog(requestDomain, "%s [%s] method=%s path=%s status=%d remote=%s duration=%s", logType, requestDomain, r.Method, r.URL.Path, writer.statusCode, r.RemoteAddr, duration.String()) + log.Printf("%s%s [%s]%s method=%s path=%s status=%d remote=%s duration=%s", + logColor, logType, requestDomain, colorReset, requestMethod, requestPath, writer.statusCode, requestRemoteAddress, duration.String()) + a.writeDomainLog(requestDomain, "%s [%s] method=%s path=%s status=%d remote=%s duration=%s", + logType, requestDomain, requestMethod, requestPath, writer.statusCode, requestRemoteAddress, duration.String()) return } - log.Printf("%s%s [%s]%s method=%s path=%s query=%s status=%d remote=%s duration=%s", logColor, logType, requestDomain, colorReset, r.Method, r.URL.Path, r.URL.RawQuery, writer.statusCode, r.RemoteAddr, duration.String()) - a.writeDomainLog(requestDomain, "%s [%s] method=%s path=%s query=%s status=%d remote=%s duration=%s", logType, requestDomain, r.Method, r.URL.Path, r.URL.RawQuery, writer.statusCode, r.RemoteAddr, duration.String()) + log.Printf("%s%s [%s]%s method=%s path=%s query=%s status=%d remote=%s duration=%s", + logColor, logType, requestDomain, colorReset, requestMethod, requestPath, requestQuery, writer.statusCode, requestRemoteAddress, duration.String()) + a.writeDomainLog(requestDomain, "%s [%s] method=%s path=%s query=%s status=%d remote=%s duration=%s", + logType, requestDomain, requestMethod, requestPath, requestQuery, writer.statusCode, requestRemoteAddress, duration.String()) }) } @@ -2500,7 +2525,8 @@ func (a *App) writeDomainLog(domain string, format string, args ...any) { if cleanDomain == "" { cleanDomain = "localhost" } - message := fmt.Sprintf(format, args...) + cleanDomain = diagnosticlog.SafeLogValue(cleanDomain) + message := diagnosticlog.SafeLogValue(fmt.Sprintf(format, args...)) if a.domainLogEvents == nil { return } @@ -2508,7 +2534,7 @@ func (a *App) writeDomainLog(domain string, format string, args ...any) { select { case a.domainLogEvents <- event: default: - log.Printf("domain log queue is full, skipped log for %s: %s", cleanDomain, message) + log.Printf("domain log queue is full, skipped log for domain=%s", cleanDomain) } } @@ -2517,7 +2543,8 @@ func (a *App) logDomainEvent(domain string, format string, args ...any) { if cleanDomain == "" { cleanDomain = "localhost" } - message := fmt.Sprintf(format, args...) + cleanDomain = diagnosticlog.SafeLogValue(cleanDomain) + message := diagnosticlog.SafeLogValue(fmt.Sprintf(format, args...)) log.Printf("domain=%s %s", cleanDomain, message) a.writeDomainLog(cleanDomain, "%s", message) } @@ -2559,6 +2586,8 @@ func (a *App) drainDomainLogEvents(events <-chan domainLogEvent) { } func (a *App) appendDomainLogEvent(event domainLogEvent) { + event.Domain = diagnosticlog.SafeLogValue(event.Domain) + event.Message = diagnosticlog.SafeLogValue(event.Message) logDir := a.domainLogDir(event.Domain) if err := a.mkdirAllInsideStorage(logDir, 0o755); err != nil { log.Printf("failed to create domain log dir for %s: %v", event.Domain, err) @@ -2611,7 +2640,7 @@ func (a *App) cleanupOldDomainLogs(domain string, now time.Time) { } func (a *App) logProblemEvent(format string, args ...any) { - message := fmt.Sprintf(format, args...) + message := diagnosticlog.SafeLogValue(fmt.Sprintf(format, args...)) log.Printf("PROBLEM %s", message) a.appendProblemLogEvent(time.Now().UTC(), message) } @@ -2620,6 +2649,7 @@ func (a *App) appendProblemLogEvent(occurredAt time.Time, message string) { if occurredAt.IsZero() { occurredAt = time.Now().UTC() } + message = diagnosticlog.SafeLogValue(message) logDir := a.problemLogDir() if err := a.mkdirAllInsideStorage(logDir, 0o755); err != nil { log.Printf("failed to create problem log dir: %v", err) @@ -5916,7 +5946,8 @@ func (a *App) migrate(ctx context.Context) error { if schemaVersion >= currentSiteDatabaseSchemaVersion && schemaComplete { a.migrateLoopbackDomainsToLocalhost(ctx) if a.debug { - log.Printf("%sDB MIGRATION%s skipped domain=%s version=%d", terminalCyan(), terminalReset(), domainFromContext(ctx), schemaVersion) + log.Printf("%sDB MIGRATION%s skipped domain=%s version=%d", + terminalCyan(), terminalReset(), diagnosticlog.SafeLogValue(domainFromContext(ctx)), schemaVersion) } return nil } @@ -7531,7 +7562,9 @@ func (a *App) ensureDemoSiteReady(ctx context.Context, controlDatabase *sql.DB, if settings.SourceURL != "" { seedFailedTotal, err := a.seedDemoSiteContent(ctx, domain, settings, progressToken) if err != nil { - log.Printf("demo site source import failed domain=%s source=%s error=%v", domain, settings.SourceURL, err) + log.Printf("demo site source import failed domain=%s source=%s error=%s", + diagnosticlog.SafeLogValue(domain), diagnosticlog.SafeLogValue(settings.SourceURL), + diagnosticlog.SafeLogValue(err.Error())) return "", 0, err } failedTotal = seedFailedTotal @@ -7542,7 +7575,8 @@ func (a *App) ensureDemoSiteReady(ctx context.Context, controlDatabase *sql.DB, return "", 0, fmt.Errorf("demo landing page was not created") } if err := a.createDemoSiteSnapshot(ctx, domain); err != nil { - log.Printf("demo site snapshot failed domain=%s error=%v", domain, err) + log.Printf("demo site snapshot failed domain=%s error=%s", + diagnosticlog.SafeLogValue(domain), diagnosticlog.SafeLogValue(err.Error())) } return adminEmail, failedTotal, nil } @@ -7850,7 +7884,8 @@ func (a *App) retryDemoFailedResources(ctx context.Context, settings demo.Settin a.applyRetriedResourcePageReplacements(domainContext, settings.Domain, replacements) a.rebuildDomainStorageUsage(domainContext, settings.Domain) if snapshotErr := a.createDemoSiteSnapshot(ctx, settings.Domain); snapshotErr != nil { - log.Printf("demo site retry snapshot failed domain=%s error=%v", settings.Domain, snapshotErr) + log.Printf("demo site retry snapshot failed domain=%s error=%s", + diagnosticlog.SafeLogValue(settings.Domain), diagnosticlog.SafeLogValue(snapshotErr.Error())) } if a.grabTracker != nil && progressToken != "" { stage := "done" @@ -8090,7 +8125,7 @@ func (a *App) scheduleDemoSiteDeletionForLogout(r *http.Request) { if err := a.enqueueDemoSessionEvent(r.Context(), demoSessionEvent{ kind: "logout", sessionToken: cookie.Value, resetAfter: time.Now().Add(demo.ResetDelay), }); err != nil { - log.Printf("demo site deletion schedule failed token=%s error=%v", diagnosticlog.SafeLogValue(cookie.Value), err) + log.Printf("demo site deletion schedule failed error=%s", diagnosticlog.SafeLogValue(err.Error())) } } @@ -14805,7 +14840,8 @@ func (a *App) applyLatestActiveRevision(ctx context.Context, domain string, page publishedStaticDelta = newHTMLBytes - a.fileSizeInsideStorage(filepath.Join(a.domainStaticDir(domain), staticRelativePathForPage(pagePath))) } if storageErr := a.applyDomainStorageDelta(ctx, domain, pageDelta, publishedPageDelta, 0, 0, publishedStaticDelta); storageErr != nil { - log.Printf("restore blocked by storage limit domain=%s path=%s error=%v", domain, pagePath, storageErr) + log.Printf("restore blocked by storage limit domain=%s path=%s error=%s", + diagnosticlog.SafeLogValue(domain), diagnosticlog.SafeLogValue(pagePath), diagnosticlog.SafeLogValue(storageErr.Error())) return } a.clearPageRedirectSource(ctx, domain, pagePath) @@ -15469,14 +15505,21 @@ func (a *App) enqueueServiceEmail(ctx context.Context, r *http.Request, codeKind } relayURL, err := a.sendServiceMailThroughRelayChain(ctx, route, &request) if err != nil { - log.Printf("service mail relay failed domain=%s relay=%s kind=%s to=%s reason=%s error=%v", domain, route.primaryRelayURL(), codeKind, recipient, route.Reason, err) + log.Printf("service mail relay failed domain=%s relay=%s kind=%s recipient_domain=%s reason=%s error=%s", + diagnosticlog.SafeLogValue(domain), diagnosticlog.SafeLogValue(route.primaryRelayURL()), + diagnosticlog.SafeLogValue(codeKind), diagnosticlog.SafeLogValue(emailAddressDomain(recipient)), + diagnosticlog.SafeLogValue(route.Reason), diagnosticlog.SafeLogValue(err.Error())) if !a.serviceMailLocalFallbackAllowed(ctx, domain, languageCode) { return fmt.Errorf("service mail relay failed and local SMTP fallback is not configured: %w", err) } - log.Printf("service mail local SMTP fallback used domain=%s kind=%s to=%s", domain, codeKind, recipient) + log.Printf("service mail local SMTP fallback used domain=%s kind=%s recipient_domain=%s", + diagnosticlog.SafeLogValue(domain), diagnosticlog.SafeLogValue(codeKind), + diagnosticlog.SafeLogValue(emailAddressDomain(recipient))) return a.enqueueEmail(ctx, message) } - log.Printf("service mail relayed domain=%s relay=%s kind=%s to=%s reason=%s", domain, relayURL, codeKind, recipient, route.Reason) + log.Printf("service mail relayed domain=%s relay=%s kind=%s recipient_domain=%s reason=%s", + diagnosticlog.SafeLogValue(domain), diagnosticlog.SafeLogValue(relayURL), diagnosticlog.SafeLogValue(codeKind), + diagnosticlog.SafeLogValue(emailAddressDomain(recipient)), diagnosticlog.SafeLogValue(route.Reason)) return nil } @@ -15505,18 +15548,25 @@ func (a *App) sendServiceEmailNow(ctx context.Context, r *http.Request, codeKind relayURL, err := a.sendServiceMailThroughRelayChain(sendCtx, route, &request) if err != nil { warning := fmt.Sprintf("service mail relay failed (%s); fallback to local SMTP", err.Error()) - log.Printf("service mail relay failed domain=%s relay=%s kind=%s to=%s reason=%s error=%v", domain, route.primaryRelayURL(), codeKind, recipient, route.Reason, err) + log.Printf("service mail relay failed domain=%s relay=%s kind=%s recipient_domain=%s reason=%s error=%s", + diagnosticlog.SafeLogValue(domain), diagnosticlog.SafeLogValue(route.primaryRelayURL()), + diagnosticlog.SafeLogValue(codeKind), diagnosticlog.SafeLogValue(emailAddressDomain(recipient)), + diagnosticlog.SafeLogValue(route.Reason), diagnosticlog.SafeLogValue(err.Error())) if !a.serviceMailLocalFallbackAllowed(ctx, domain, languageCode) { return emailDeliveryResult{Message: message, Err: fmt.Errorf("service mail relay failed and local SMTP fallback is not configured: %w", err)} } - log.Printf("service mail local SMTP fallback used domain=%s kind=%s to=%s", domain, codeKind, recipient) + log.Printf("service mail local SMTP fallback used domain=%s kind=%s recipient_domain=%s", + diagnosticlog.SafeLogValue(domain), diagnosticlog.SafeLogValue(codeKind), + diagnosticlog.SafeLogValue(emailAddressDomain(recipient))) result := a.sendEmailNow(ctx, message) if result.Err == nil { result.Warning = warning } return result } - log.Printf("service mail relayed domain=%s relay=%s kind=%s to=%s reason=%s", domain, relayURL, codeKind, recipient, route.Reason) + log.Printf("service mail relayed domain=%s relay=%s kind=%s recipient_domain=%s reason=%s", + diagnosticlog.SafeLogValue(domain), diagnosticlog.SafeLogValue(relayURL), diagnosticlog.SafeLogValue(codeKind), + diagnosticlog.SafeLogValue(emailAddressDomain(recipient)), diagnosticlog.SafeLogValue(route.Reason)) return emailDeliveryResult{Message: message} } @@ -15535,7 +15585,9 @@ func (a *App) markServiceMailRecipientVerified(ctx context.Context, domain, reci CreatedAt: time.Now().UTC().Format(time.RFC3339), } if _, err := a.sendServiceMailThroughRelayChain(ctx, route, &request); err != nil { - log.Printf("service mail recipient verification failed domain=%s relay=%s to=%s error=%v", domain, route.primaryRelayURL(), recipient, err) + log.Printf("service mail recipient verification failed domain=%s relay=%s recipient_domain=%s error=%s", + diagnosticlog.SafeLogValue(domain), diagnosticlog.SafeLogValue(route.primaryRelayURL()), + diagnosticlog.SafeLogValue(emailAddressDomain(recipient)), diagnosticlog.SafeLogValue(err.Error())) } } @@ -15587,10 +15639,11 @@ func (a *App) sendEmailNow(ctx context.Context, message mailout.Message) emailDe defer cancel() err := sender(sendCtx, message) if err != nil { - log.Printf("email delivery failed to=%s subject=%q error=%v", message.To, message.Subject, err) + log.Printf("email delivery failed recipient_domain=%s error=%s", + diagnosticlog.SafeLogValue(emailAddressDomain(message.To)), diagnosticlog.SafeLogValue(err.Error())) return emailDeliveryResult{Message: message, Err: err} } - log.Printf("email delivery accepted to=%s subject=%q", message.To, message.Subject) + log.Printf("email delivery accepted recipient_domain=%s", diagnosticlog.SafeLogValue(emailAddressDomain(message.To))) return emailDeliveryResult{Message: message} } @@ -17472,7 +17525,8 @@ func (a *App) notifyHostingSnapshotDiskThreshold(ctx context.Context, controlDat Body: body, }) if err != nil { - log.Printf("hosting disk alert email enqueue failed installation=%s owner=%s error=%v", snapshot.InstallationID, ownerEmail, err) + log.Printf("hosting disk alert email enqueue failed installation=%s error=%s", + diagnosticlog.SafeLogValue(snapshot.InstallationID), diagnosticlog.SafeLogValue(err.Error())) return } now := time.Now().UTC().Format(time.RFC3339) @@ -21342,7 +21396,10 @@ func (a *App) pagePasswordAction(w http.ResponseWriter, r *http.Request) { http.Error(w, "password is required", http.StatusBadRequest) return } - a.setPagePasswordRule(r.Context(), domain, pagePath, password) + if err := a.setPagePasswordRule(r.Context(), domain, pagePath, password); err != nil { + http.Error(w, "password could not be stored", http.StatusBadRequest) + return + } case "remove": if rule, found := a.pagePasswordRuleForPath(r.Context(), domain, pagePath); found { a.removePagePasswordRule(r.Context(), domain, rule.Path) @@ -21433,15 +21490,23 @@ func (a *App) pagePasswordSessionValid(r *http.Request, rule PagePasswordRule) b return dirprotect.BoundSessionTokenValid(rule, cookie.Value, clientIPAddress(r), r.UserAgent(), time.Now().UTC(), pagePasswordSessionTTL) } -func (a *App) setPagePasswordRule(ctx context.Context, domain, pagePath, password string) { +func (a *App) setPagePasswordRule(ctx context.Context, domain, pagePath, password string) error { normalizedPath := cleanPath(pagePath) + passwordHash, err := dirprotect.Hash(password) + if err != nil { + return err + } now := time.Now().UTC().Format(time.RFC3339) - _, _ = a.db.ExecContext(ctx, `INSERT INTO page_password_rules(domain,path,password_hash,created_at,updated_at) + _, err = a.db.ExecContext(ctx, `INSERT INTO page_password_rules(domain,path,password_hash,created_at,updated_at) VALUES(?,?,?,?,?) ON CONFLICT(domain,path) DO UPDATE SET password_hash=excluded.password_hash,updated_at=excluded.updated_at`, - domain, normalizedPath, dirprotect.Hash(password), now, now) + domain, normalizedPath, passwordHash, now, now) + if err != nil { + return err + } _, _ = a.db.ExecContext(ctx, `DELETE FROM page_password_sessions WHERE domain=? AND path=?`, domain, normalizedPath) a.writePagePasswordPrefixFile(ctx, domain) + return nil } func (a *App) removePagePasswordRule(ctx context.Context, domain, pagePath string) { @@ -23464,6 +23529,9 @@ func injectTemplatePropagationProgressModal(pageHTML []byte) []byte { injection := []byte(templatePropagationProgressModalHTML()) lowerPageHTML := bytes.ToLower(pageHTML) bodyCloseIndex := bytes.LastIndex(lowerPageHTML, []byte("")) + if len(pageHTML) > math.MaxInt-len(injection) { + return pageHTML + } if bodyCloseIndex < 0 { return append(pageHTML, injection...) } diff --git a/sitebrush_test.go b/sitebrush_test.go index cd48773..3ec4ceb 100644 --- a/sitebrush_test.go +++ b/sitebrush_test.go @@ -4676,7 +4676,11 @@ func TestGuestProtectedStaticRouteUsesPrefixFileWithoutDatabase(t *testing.T) { if err := os.MkdirAll(filepath.Dir(prefixFilePath), 0o700); err != nil { t.Fatal(err) } - rule := PagePasswordRule{Domain: "localhost", Path: "/passport", PasswordHash: dirprotect.Hash("secret")} + passwordHash, hashErr := dirprotect.Hash("secret") + if hashErr != nil { + t.Fatalf("hash password: %v", hashErr) + } + rule := PagePasswordRule{Domain: "localhost", Path: "/passport", PasswordHash: passwordHash} if err := os.WriteFile(prefixFilePath, []byte(rule.Path+"\t"+rule.PasswordHash+"\n"), 0o600); err != nil { t.Fatal(err) } @@ -4737,7 +4741,11 @@ func TestGuestProtectedStaticRouteUsesPrefixFileWithoutDatabase(t *testing.T) { } func TestPagePasswordSessionFollowsClientIPAddress(t *testing.T) { - rule := PagePasswordRule{Domain: "localhost", Path: "/passport", PasswordHash: dirprotect.Hash("secret")} + passwordHash, hashErr := dirprotect.Hash("secret") + if hashErr != nil { + t.Fatalf("hash password: %v", hashErr) + } + rule := PagePasswordRule{Domain: "localhost", Path: "/passport", PasswordHash: passwordHash} issuedAt := time.Now().UTC().Add(-time.Minute) originalRequest := httptest.NewRequest(http.MethodGet, "http://localhost:8080/passport", nil) originalRequest.RemoteAddr = "198.51.100.42:1234"