verbose logging to debug cache resolution

Author: zshannon

server/server.go

@@ -98,6 +98,7 @@ type s3FS struct {
 }
 
 func newS3FS(version string) *s3FS {
+	log.Printf("[newS3FS] Creating filesystem for version: %s", version)
 	return &s3FS{
 		version: version,
 		files: map[string]string{
@@ -115,7 +116,7 @@ func getFromCache(ctx context.Context, version, path string) *CacheEntry {
 	cacheKey := fmt.Sprintf("%s%s", version, strings.TrimPrefix(path, "/"))
 
 	// Log S3 access for debugging
-	// log.Printf("S3 lookup: bucket=%s, key=%s", s3Bucket, cacheKey)
+	log.Printf("[getFromCache] S3 lookup: bucket=%s, key=%s, version=%s, path=%s", s3Bucket, cacheKey, version, path)
 
 	// Check cache first
 	cacheMutex.RLock()
@@ -150,7 +151,7 @@ func getFromCache(ctx context.Context, version, path string) *CacheEntry {
 		defer result.Body.Close()
 		content, err := io.ReadAll(result.Body)
 		if err == nil {
-			// log.Printf("S3 file found: %s (%d bytes)", cacheKey, len(content))
+			log.Printf("[getFromCache] S3 file found: %s (%d bytes)", cacheKey, len(content))
 			entry := &CacheEntry{
 				Exists:    true,
 				IsFile:    true,
@@ -162,10 +163,10 @@ func getFromCache(ctx context.Context, version, path string) *CacheEntry {
 			cacheMutex.Unlock()
 			return entry
 		} else {
-			// log.Printf("S3 file read error for %s: %v", cacheKey, err)
+			log.Printf("[getFromCache] S3 file read error for %s: %v", cacheKey, err)
 		}
 	} else {
-		// log.Printf("S3 file fetch error for %s: %v", cacheKey, err)
+		log.Printf("[getFromCache] S3 file fetch error for %s: %v", cacheKey, err)
 	}
 
 	// Not a file, try as directory
@@ -184,7 +185,7 @@ func getFromCache(ctx context.Context, version, path string) *CacheEntry {
 
 	if err != nil {
 		s3ListErrors.Inc()
-		// log.Printf("S3 list error for key %s: %v", cacheKey, err)
+		log.Printf("[getFromCache] S3 list error for key %s: %v", cacheKey, err)
 		// Cache as non-existent with shorter TTL
 		entry := &CacheEntry{
 			Exists:    false,
@@ -197,6 +198,7 @@ func getFromCache(ctx context.Context, version, path string) *CacheEntry {
 	}
 
 	// Build directory entry
+	log.Printf("[getFromCache] S3 list results for %s: %d objects, %d prefixes", cacheKey, len(listResult.Contents), len(listResult.CommonPrefixes))
 	entry := &CacheEntry{
 		Exists: false,
 		IsFile: false,
@@ -235,6 +237,7 @@ func getFromCache(ctx context.Context, version, path string) *CacheEntry {
 	}
 
 	// Cache the result
+	log.Printf("[getFromCache] Caching result for %s: exists=%v, isFile=%v, files=%d, dirs=%d", cacheKey, entry.Exists, entry.IsFile, len(entry.Files), len(entry.Dirs))
 	cacheMutex.Lock()
 	cache.Add(cacheKey, entry)
 	cacheMutex.Unlock()
@@ -256,15 +259,21 @@ func (fs *s3FS) FileExists(path string) bool {
 		return false
 	}
 
+	// Log the file access for debugging
+	log.Printf("[FileExists] Checking path: %s (version: %s)", path, fs.version)
+	
 	// Check S3 cache
 	ctx := context.Background()
 	entry := getFromCache(ctx, fs.version, path)
-	return entry.Exists && entry.IsFile
+	result := entry.Exists && entry.IsFile
+	log.Printf("[FileExists] Path: %s -> exists=%v, isFile=%v", path, entry.Exists, entry.IsFile)
+	return result
 }
 
 func (fs *s3FS) ReadFile(path string) (string, bool) {
 	// Check in-memory cache first
 	if content, ok := fs.files[path]; ok {
+		log.Printf("[ReadFile] Found in memory: %s (%d bytes)", path, len(content))
 		return content, true
 	}
 
@@ -274,13 +283,16 @@ func (fs *s3FS) ReadFile(path string) (string, bool) {
 	}
 
 	// Check S3 cache
+	log.Printf("[ReadFile] Checking S3 for: %s (version: %s)", path, fs.version)
 	ctx := context.Background()
 	entry := getFromCache(ctx, fs.version, path)
 	if !entry.Exists || !entry.IsFile {
+		log.Printf("[ReadFile] Not found or not a file: %s (exists: %v, isFile: %v)", path, entry.Exists, entry.IsFile)
 		return "", false
 	}
 
 	contentStr := string(entry.Content)
+	log.Printf("[ReadFile] Found in S3: %s (%d bytes)", path, len(contentStr))
 	fs.files[path] = contentStr // Cache locally for this request
 	return contentStr, true
 }
@@ -299,11 +311,14 @@ func (fs *s3FS) DirectoryExists(path string) bool {
 	if path == "/" || path == "" {
 		return true
 	}
+	log.Printf("[DirectoryExists] Checking: %s (version: %s)", path, fs.version)
 
 	// Check S3 cache
 	ctx := context.Background()
 	entry := getFromCache(ctx, fs.version, path)
-	return entry.Exists && !entry.IsFile
+	result := entry.Exists && !entry.IsFile
+	log.Printf("[DirectoryExists] Path: %s -> exists=%v, isFile=%v, result=%v", path, entry.Exists, entry.IsFile, result)
+	return result
 }
 
 func (fs *s3FS) GetAccessibleEntries(path string) vfs.Entries {
@@ -448,7 +463,7 @@ func buildTypeScript(code string, version string) BuildResponse {
 
 	// Create virtual file resolver for esbuild
 	resolver := func(path string) (api.OnLoadResult, error) {
-		log.Printf("Resolving: %s", path)
+		log.Printf("[esbuild resolver] Resolving: %s", path)
 
 		// Track package resolutions
 		trackPackageResolution(path)
@@ -463,7 +478,7 @@ func buildTypeScript(code string, version string) BuildResponse {
 			} else if strings.HasSuffix(path, ".json") {
 				loader = api.LoaderJSON
 			}
-			log.Printf("Found exact path: %s", path)
+			log.Printf("[esbuild resolver] Found exact path: %s (loader: %v)", path, loader)
 			return api.OnLoadResult{
 				Contents: &content,
 				Loader:   loader,
@@ -484,7 +499,7 @@ func buildTypeScript(code string, version string) BuildResponse {
 					} else if ext == ".json" {
 						loader = api.LoaderJSON
 					}
-					log.Printf("Found with extension: %s", testPath)
+					log.Printf("[esbuild resolver] Found with extension: %s (loader: %v)", testPath, loader)
 					return api.OnLoadResult{
 						Contents: &content,
 						Loader:   loader,
@@ -590,15 +605,15 @@ func buildTypeScript(code string, version string) BuildResponse {
 					} else if strings.HasSuffix(pattern, ".json") {
 						loader = api.LoaderJSON
 					}
-					log.Printf("Found at: %s", pattern)
+					log.Printf("[esbuild resolver] Found at: %s (loader: %v)", pattern, loader)
 					return api.OnLoadResult{
 						Contents: &content,
 						Loader:   loader,
 					}, nil
 				}
 			}
 
-			log.Printf("Tried patterns: %v", patterns)
+			log.Printf("[esbuild resolver] Failed to find %s. Tried patterns: %v", path, patterns)
 		}
 
 		return api.OnLoadResult{}, fmt.Errorf("file not found: %s", path)
@@ -622,6 +637,7 @@ func buildTypeScript(code string, version string) BuildResponse {
 			Name: "virtual-fs",
 			Setup: func(pb api.PluginBuild) {
 				pb.OnResolve(api.OnResolveOptions{Filter: ".*"}, func(args api.OnResolveArgs) (api.OnResolveResult, error) {
+					log.Printf("[esbuild OnResolve] path=%s, importer=%s, kind=%v", args.Path, args.Importer, args.Kind)
 					// Track package resolutions in esbuild plugin
 					trackPackageResolution(args.Path)
 
@@ -676,11 +692,13 @@ func buildTypeScript(code string, version string) BuildResponse {
 				})
 
 				pb.OnLoad(api.OnLoadOptions{Filter: ".*", Namespace: "virtual"}, func(args api.OnLoadArgs) (api.OnLoadResult, error) {
+					log.Printf("[esbuild OnLoad] path=%s, namespace=%s", args.Path, args.Namespace)
 					return resolver(args.Path)
 				})
 
 				// Handle react global transform
 				pb.OnLoad(api.OnLoadOptions{Filter: ".*", Namespace: "use-crayon-react-global"}, func(args api.OnLoadArgs) (api.OnLoadResult, error) {
+					log.Printf("[esbuild OnLoad] React global transform for: %s", args.Path)
 					contents := "module.exports = _CRAYONCORE_$REACT"
 					return api.OnLoadResult{
 						Contents: &contents,