chore(logging): sanitize diagnostics and reduce noise

go_backend/cover.go

@@ -24,7 +24,6 @@ func downloadCoverToMemory(coverURL string) ([]byte, error) {
 		return nil, fmt.Errorf("no cover URL provided")
 	}
 
-	GoLog("[Cover] Provider URL: %s", coverURL)
 	data, err := fetchCoverCached(coverURL)
 	if err != nil {
 		return nil, err

go_backend/cover_test.go

@@ -110,7 +110,6 @@ func TestFetchCoverCachedTTLExpiry(t *testing.T) {
 	if _, err := fetchCoverCached(url); err != nil {
 		t.Fatalf("first fetch error: %v", err)
 	}
-	// second call served from cache
 	if _, err := fetchCoverCached(url); err != nil {
 		t.Fatalf("second fetch error: %v", err)
 	}
@@ -118,7 +117,6 @@ func TestFetchCoverCachedTTLExpiry(t *testing.T) {
 		t.Fatalf("expected cache hit, got %d fetches", got)
 	}
 
-	// expire the entry and confirm a refetch
 	coverMu.Lock()
 	coverCache[url].expiresAt = time.Now().Add(-time.Minute)
 	coverMu.Unlock()

go_backend/exports_metadata.go

@@ -551,7 +551,6 @@ func DownloadCoverToFileSized(coverURL string, outputPath string, maxDimension i
 		return fmt.Errorf("failed to write cover file: %w", err)
 	}
 
-	GoLog("[Cover] Downloaded cover to: %s (%d KB)\n", outputPath, len(data)/1024)
 	return nil
 }
 
@@ -586,6 +585,5 @@ func ExtractCoverToFile(audioPath string, outputPath string) error {
 		return fmt.Errorf("failed to write cover file: %w", err)
 	}
 
-	GoLog("[Cover] Extracted cover art to: %s (%d KB)\n", outputPath, len(coverData)/1024)
 	return nil
 }

go_backend/exports_reenrich.go

@@ -651,7 +651,7 @@ func ReEnrichFile(requestJSON string) (string, error) {
 		return "", fmt.Errorf("file_path is required")
 	}
 
-	GoLog("[ReEnrich] Starting re-enrichment for: %s\n", req.FilePath)
+	GoLog("[ReEnrich] Starting re-enrichment\n")
 
 	if req.SearchOnline {
 		found := false
@@ -659,21 +659,19 @@ func ReEnrichFile(requestJSON string) (string, error) {
 		GoLog("[ReEnrich] Trying metadata providers in configured priority...\n")
 		manager := getExtensionManager()
 		if identifierTrack, err := resolveReEnrichTrackFromIdentifiers(req); err == nil && identifierTrack != nil {
-			GoLog("[ReEnrich] Identifier-first metadata match (%s): %s - %s (album: %s, date: %s)\n",
-				identifierTrack.ProviderID, identifierTrack.Name, identifierTrack.Artists, identifierTrack.AlbumName, identifierTrack.ReleaseDate)
+			GoLog("[ReEnrich] Identifier-first metadata match via %s\n", identifierTrack.ProviderID)
 			applyReEnrichTrackMetadata(&req, *identifierTrack)
 			found = true
 		}
 
 		searchQuery := buildReEnrichSearchQuery(req)
 		if searchQuery != "" {
-			GoLog("[ReEnrich] Searching online metadata for query: %s\n", searchQuery)
+			GoLog("[ReEnrich] Searching online metadata\n")
 			tracks, searchErr := manager.SearchTracksWithMetadataProviders(searchQuery, 5, true)
 			if searchErr == nil && len(tracks) > 0 {
 				track := selectBestReEnrichTrack(req, tracks)
 				if track != nil {
-					GoLog("[ReEnrich] Metadata match (%s): %s - %s (album: %s, date: %s)\n",
-						track.ProviderID, track.Name, track.Artists, track.AlbumName, track.ReleaseDate)
+					GoLog("[ReEnrich] Metadata match via %s\n", track.ProviderID)
 					applyReEnrichTrackMetadata(&req, *track)
 					found = true
 				}
@@ -690,7 +688,7 @@ func ReEnrichFile(requestJSON string) (string, error) {
 				GoLog("[ReEnrich] Failed to get album artist from MusicBrainz: %v\n", err)
 			} else if strings.TrimSpace(albumArtist) != "" {
 				req.AlbumArtist = strings.TrimSpace(albumArtist)
-				GoLog("[ReEnrich] Album artist fallback from MusicBrainz: %s\n", req.AlbumArtist)
+				GoLog("[ReEnrich] Applied album artist fallback from MusicBrainz\n")
 				found = true
 			}
 		}
@@ -705,11 +703,6 @@ func ReEnrichFile(requestJSON string) (string, error) {
 		}
 	}
 
-	GoLog("[ReEnrich] Metadata to embed: title=%s, artist=%s, album=%s, albumArtist=%s\n",
-		req.TrackName, req.ArtistName, req.AlbumName, req.AlbumArtist)
-	GoLog("[ReEnrich] track=%d, disc=%d, date=%s, isrc=%s, genre=%s, label=%s\n",
-		req.TrackNumber, req.DiscNumber, req.ReleaseDate, req.ISRC, req.Genre, req.Label)
-
 	enrichedMeta := buildReEnrichResultMetadata(&req)
 	if req.PreviewOnly {
 		result := map[string]any{

go_backend/extension_manager.go

@@ -1045,7 +1045,17 @@ func (m *extensionManager) InvokeAction(extensionID string, actionName string) (
 
 	exported := result.Export()
 	if resultMap, ok := exported.(map[string]any); ok {
-		GoLog("[Extension] InvokeAction %s.%s result: %v\n", extensionID, actionName, resultMap)
+		status := "unspecified"
+		if success, present := resultMap["success"].(bool); present {
+			status = strconv.FormatBool(success)
+		}
+		GoLog(
+			"[Extension] InvokeAction %s.%s completed (success=%s, fields=%d)\n",
+			extensionID,
+			actionName,
+			status,
+			len(resultMap),
+		)
 		return resultMap, nil
 	}
 

go_backend/extension_manager_runtime.go

@@ -82,11 +82,7 @@ func initializeVMLocked(ext *loadedExtension) error {
 
 	console := vm.NewObject()
 	console.Set("log", func(call goja.FunctionCall) goja.Value {
-		args := make([]any, len(call.Arguments))
-		for i, arg := range call.Arguments {
-			args[i] = arg.Export()
-		}
-		GoLog("[Extension:%s] %v\n", ext.ID, args)
+		GoLog("[Extension:%s] %s\n", ext.ID, formatExtensionLogArgs(call.Arguments))
 		return goja.Undefined()
 	})
 	vm.Set("console", console)
@@ -153,11 +149,7 @@ func newIsolatedExtensionRuntime(ext *loadedExtension) (*goja.Runtime, *extensio
 
 	console := vm.NewObject()
 	console.Set("log", func(call goja.FunctionCall) goja.Value {
-		args := make([]any, len(call.Arguments))
-		for i, arg := range call.Arguments {
-			args[i] = arg.Export()
-		}
-		GoLog("[Extension:%s] %v\n", ext.ID, args)
+		GoLog("[Extension:%s] %s\n", ext.ID, formatExtensionLogArgs(call.Arguments))
 		return goja.Undefined()
 	})
 	vm.Set("console", console)

go_backend/extension_runtime_supplement_test.go

@@ -1145,6 +1145,12 @@ func TestExtensionRuntimeUtilityAPIs(t *testing.T) {
 	if msg := runtime.formatLogArgs([]goja.Value{vm.ToValue("a"), vm.ToValue(1)}); msg != "a 1" {
 		t.Fatalf("formatLogArgs = %q", msg)
 	}
+	objectLog := runtime.formatLogArgs([]goja.Value{
+		vm.ToValue(map[string]any{"access_token": "must-not-be-exported"}),
+	})
+	if strings.Contains(objectLog, "must-not-be-exported") || !strings.HasPrefix(objectLog, "<") {
+		t.Fatalf("object log was not summarized: %q", objectLog)
+	}
 	runtime.logDebug(goja.FunctionCall{Arguments: []goja.Value{vm.ToValue("debug")}})
 	runtime.logInfo(goja.FunctionCall{Arguments: []goja.Value{vm.ToValue("info")}})
 	runtime.logWarn(goja.FunctionCall{Arguments: []goja.Value{vm.ToValue("warn")}})

go_backend/extension_runtime_utils.go

@@ -11,6 +11,7 @@ import (
 	"encoding/json"
 	"fmt"
 	"math"
+	"reflect"
 	"strings"
 	"time"
 
@@ -365,11 +366,43 @@ func (r *extensionRuntime) logError(call goja.FunctionCall) goja.Value {
 }
 
 func (r *extensionRuntime) formatLogArgs(args []goja.Value) string {
-	parts := make([]string, len(args))
-	for i, arg := range args {
-		parts[i] = fmt.Sprintf("%v", arg.Export())
+	return formatExtensionLogArgs(args)
+}
+
+const (
+	maxExtensionLogArgs      = 8
+	maxExtensionLogArgLength = 512
+)
+
+func formatExtensionLogArgs(args []goja.Value) string {
+	limit := len(args)
+	if limit > maxExtensionLogArgs {
+		limit = maxExtensionLogArgs
 	}
-	return strings.Join(parts, " ")
+	parts := make([]string, 0, limit+1)
+	for _, arg := range args[:limit] {
+		value := "<value>"
+		if exportType := arg.ExportType(); exportType != nil {
+			switch exportType.Kind() {
+			case reflect.Bool,
+				reflect.Int, reflect.Int8, reflect.Int16, reflect.Int32, reflect.Int64,
+				reflect.Uint, reflect.Uint8, reflect.Uint16, reflect.Uint32, reflect.Uint64,
+				reflect.Float32, reflect.Float64,
+				reflect.String:
+				value = arg.String()
+			default:
+				value = "<" + exportType.String() + ">"
+			}
+		}
+		if len(value) > maxExtensionLogArgLength {
+			value = value[:maxExtensionLogArgLength] + "...[truncated]"
+		}
+		parts = append(parts, value)
+	}
+	if len(args) > limit {
+		parts = append(parts, fmt.Sprintf("...[%d more args]", len(args)-limit))
+	}
+	return truncateLogMessage(sanitizeSensitiveLogText(strings.Join(parts, " ")))
 }
 
 func (r *extensionRuntime) RegisterGoBackendAPIs(vm *goja.Runtime) {

go_backend/log_progress_timeout_supplement_test.go

@@ -28,6 +28,8 @@ func TestLogBufferExportedHelpersAndRedaction(t *testing.T) {
 	GoLog("[GoTag] success token=abc")
 	LogError("json", `{"access_token":"json-secret","session_secret":"session-secret"}`)
 	LogError("query", "https://example.test/?X-Amz-Signature=signed-secret&X-Amz-Security-Token=session-token")
+	LogError("ffmpeg", "-decryption_key raw-media-key -i https://example.test/audio")
+	LogError("bounded", "%s", strings.Repeat("x", maxLogMessageLength+500))
 
 	var entries []LogEntry
 	if err := json.Unmarshal([]byte(GetLogBuffer().GetAll()), &entries); err != nil {
@@ -37,9 +39,12 @@ func TestLogBufferExportedHelpersAndRedaction(t *testing.T) {
 		t.Fatalf("expected log entries, got %#v", entries)
 	}
 	for _, entry := range entries {
-		if strings.Contains(entry.Message, "secret-token") || strings.Contains(entry.Message, "api_key=value") || strings.Contains(entry.Message, "password=secret") || strings.Contains(entry.Message, "json-secret") || strings.Contains(entry.Message, "session-secret") || strings.Contains(entry.Message, "signed-secret") || strings.Contains(entry.Message, "session-token") {
+		if strings.Contains(entry.Message, "secret-token") || strings.Contains(entry.Message, "api_key=value") || strings.Contains(entry.Message, "password=secret") || strings.Contains(entry.Message, "json-secret") || strings.Contains(entry.Message, "session-secret") || strings.Contains(entry.Message, "signed-secret") || strings.Contains(entry.Message, "session-token") || strings.Contains(entry.Message, "raw-media-key") {
 			t.Fatalf("log was not redacted: %#v", entry)
 		}
+		if len(entry.Message) > maxLogMessageLength+len("...[truncated]") {
+			t.Fatalf("log was not bounded: %d bytes", len(entry.Message))
+		}
 	}
 
 	sinceJSON := GetLogsSince(1)

go_backend/logbuffer.go

@@ -7,6 +7,7 @@ import (
 	"strings"
 	"sync"
 	"time"
+	"unicode/utf8"
 )
 
 type LogEntry struct {
@@ -28,6 +29,7 @@ type LogBuffer struct {
 
 const (
 	defaultLogBufferSize = 500
+	maxLogMessageLength  = 4000
 )
 
 var (
@@ -35,9 +37,10 @@ var (
 	logBufferOnce   sync.Once
 
 	authorizationBearerPattern = regexp.MustCompile(`(?i)\bAuthorization\b\s*[:=]\s*Bearer\s+[A-Za-z0-9._~+/\-]+=*`)
-	genericKeyValuePattern     = regexp.MustCompile(`(?i)("?(?:access[_\s-]?token|refresh[_\s-]?token|id[_\s-]?token|client[_\s-]?secret|authorization|password|api[_\s-]?key|session[_\s-]?secret|cookie|set-cookie)"?)(\s*[:=]\s*)("(?:\\.|[^"\\])*"|[^\s,;}\]]+)`)
+	genericKeyValuePattern     = regexp.MustCompile(`(?i)("?(?:access[_\s-]?token|refresh[_\s-]?token|id[_\s-]?token|client[_\s-]?secret|authorization|password|api[_\s-]?key|session[_\s-]?secret|decryption[_\s-]?key|cookie|set-cookie)"?)(\s*[:=]\s*)("(?:\\.|[^"\\])*"|[^\s,;}\]]+)`)
 	queryTokenPattern          = regexp.MustCompile(`(?i)([?&](?:access_token|refresh_token|id_token|token|client_secret|api_key|apikey|password|code|grant|sig|signature|x-amz-signature|x-amz-credential|x-amz-security-token|awsaccesskeyid|googleaccessid|policy|key-pair-id)=)[^&\s]+`)
 	bearerTokenPattern         = regexp.MustCompile(`(?i)\bBearer\s+[A-Za-z0-9._~+/\-]+=*`)
+	decryptionKeyFlagPattern   = regexp.MustCompile(`(?i)(-decryption_key\s+)[^\s]+`)
 )
 
 func sanitizeSensitiveLogText(message string) string {
@@ -46,9 +49,21 @@ func sanitizeSensitiveLogText(message string) string {
 	redacted = genericKeyValuePattern.ReplaceAllString(redacted, `${1}${2}[REDACTED]`)
 	redacted = queryTokenPattern.ReplaceAllString(redacted, `${1}[REDACTED]`)
 	redacted = bearerTokenPattern.ReplaceAllString(redacted, "Bearer [REDACTED]")
+	redacted = decryptionKeyFlagPattern.ReplaceAllString(redacted, `${1}[REDACTED]`)
 	return redacted
 }
 
+func truncateLogMessage(message string) string {
+	if len(message) <= maxLogMessageLength {
+		return message
+	}
+	truncated := message[:maxLogMessageLength]
+	for !utf8.ValidString(truncated) {
+		truncated = truncated[:len(truncated)-1]
+	}
+	return truncated + "...[truncated]"
+}
+
 func GetLogBuffer() *LogBuffer {
 	logBufferOnce.Do(func() {
 		globalLogBuffer = &LogBuffer{
@@ -80,7 +95,7 @@ func (lb *LogBuffer) Add(level, tag, message string) {
 		return
 	}
 
-	message = sanitizeSensitiveLogText(message)
+	message = truncateLogMessage(sanitizeSensitiveLogText(message))
 
 	entry := LogEntry{
 		Timestamp: time.Now().Format("15:04:05.000"),

go_backend/lyrics.go

@@ -370,7 +370,6 @@ func (c *LyricsClient) fetchLyricsAllSourcesUncoalesced(spotifyID, trackName, ar
 			}
 		}
 		if (!isExtensionCache && selectedExtensionCount == 0) || cachedProviderSelected {
-			fmt.Printf("[Lyrics] Cache hit for: %s - %s\n", artistName, trackName)
 			cachedCopy := *cached
 			cachedCopy.Source = cached.Source + " (cached)"
 			return &cachedCopy, nil

go_backend/metadata.go

@@ -287,14 +287,12 @@ func EmbedMetadata(filePath string, metadata Metadata, coverPath string) error {
 			if fileExists(coverPath) {
 				coverData, err := os.ReadFile(coverPath)
 				if err != nil {
-					fmt.Printf("[Metadata] Warning: Failed to read cover file %s: %v\n", coverPath, err)
+					LogWarn("Metadata", "Failed to read cover file: %v", err)
 				} else if err := replaceFlacPictures(f, coverPath, coverData); err != nil {
-					fmt.Printf("[Metadata] Warning: skipping cover art: %v\n", err)
-				} else {
-					fmt.Printf("[Metadata] Cover art embedded successfully (%d bytes)\n", len(coverData))
+					LogWarn("Metadata", "Skipping cover art: %v", err)
 				}
 			} else {
-				fmt.Printf("[Metadata] Warning: Cover file does not exist: %s\n", coverPath)
+				LogWarn("Metadata", "Cover file does not exist")
 			}
 		}
 		return nil
@@ -307,9 +305,7 @@ func EmbedMetadataWithCoverData(filePath string, metadata Metadata, coverData []
 
 		if len(coverData) > 0 {
 			if err := replaceFlacPictures(f, "", coverData); err != nil {
-				fmt.Printf("[Metadata] Warning: skipping cover art: %v\n", err)
-			} else {
-				fmt.Printf("[Metadata] Cover art embedded successfully (%d bytes)\n", len(coverData))
+				LogWarn("Metadata", "Skipping cover art: %v", err)
 			}
 		}
 		return nil