Add CI debug logging for versioning race condition investigation

- Add detailed logging for .versions metadata updates in putVersionedObject
- Add logging for latest version resolution in getLatestObjectVersion
- Add logging for HeadObject latest version requests
- All logs use glog.V(0) with CI-DEBUG prefix for easy filtering
- Will help diagnose timing issues between object creation and retrieval in CI

Debug logs will show:
- When .versions metadata updates start and complete
- When HeadObject tries to read latest version metadata
- Race conditions if HeadObject runs before metadata update completes
- Missing metadata if .versions directory exists but metadata keys are missing
- File access issues if version files exist but can't be accessed

weed/s3api/s3api_object_handlers.go

@@ -441,12 +441,15 @@ func (s3a *S3ApiServer) HeadObjectHandler(w http.ResponseWriter, r *http.Request
 		} else {
 			// Request for latest version
 			glog.V(2).Infof("HeadObject: requesting latest version for %s%s", bucket, object)
+			glog.V(0).Infof("CI-DEBUG: HeadObject: requesting latest version for %s/%s", bucket, object)
 			entry, err = s3a.getLatestObjectVersion(bucket, object)
 			if err != nil {
 				glog.Errorf("Failed to get latest version: %v", err)
+				glog.V(0).Infof("CI-DEBUG: HeadObject: FAILED to get latest version for %s/%s: %v", bucket, object, err)
 				s3err.WriteErrorResponse(w, r, s3err.ErrNoSuchKey)
 				return
 			}
+			glog.V(0).Infof("CI-DEBUG: HeadObject: successfully got latest version for %s/%s", bucket, object)
 			if entry.Extended != nil {
 				if versionIdBytes, exists := entry.Extended[s3_constants.ExtVersionIdKey]; exists {
 					targetVersionId = string(versionIdBytes)

weed/s3api/s3api_object_handlers_put.go

@@ -620,12 +620,15 @@ func (s3a *S3ApiServer) putVersionedObject(r *http.Request, bucket, object strin
 	}
 
 	// Update the .versions directory metadata to indicate this is the latest version
+	glog.V(0).Infof("CI-DEBUG: putVersionedObject: about to update latest version metadata for %s/%s version %s", bucket, object, versionId)
 	err = s3a.updateLatestVersionInDirectory(bucket, object, versionId, versionFileName)
 	if err != nil {
 		glog.Errorf("putVersionedObject: failed to update latest version in directory: %v", err)
+		glog.V(0).Infof("CI-DEBUG: putVersionedObject: FAILED to update latest version metadata for %s/%s version %s: %v", bucket, object, versionId, err)
 		return "", "", s3err.ErrInternalError
 	}
 
+	glog.V(0).Infof("CI-DEBUG: putVersionedObject: successfully updated latest version metadata for %s/%s version %s", bucket, object, versionId)
 	glog.V(2).Infof("putVersionedObject: successfully created version %s for %s/%s", versionId, bucket, object)
 	return versionId, etag, s3err.ErrNone
 }
@@ -635,13 +638,18 @@ func (s3a *S3ApiServer) updateLatestVersionInDirectory(bucket, object, versionId
 	bucketDir := s3a.option.BucketsPath + "/" + bucket
 	versionsObjectPath := object + ".versions"
 
+	glog.V(0).Infof("CI-DEBUG: updateLatestVersionInDirectory: starting update for %s/%s version %s file %s", bucket, object, versionId, versionFileName)
+
 	// Get the current .versions directory entry
 	versionsEntry, err := s3a.getEntry(bucketDir, versionsObjectPath)
 	if err != nil {
 		glog.Errorf("updateLatestVersionInDirectory: failed to get .versions directory for %s/%s: %v", bucket, object, err)
+		glog.V(0).Infof("CI-DEBUG: updateLatestVersionInDirectory: FAILED to get .versions entry for %s/%s: %v", bucket, object, err)
 		return fmt.Errorf("failed to get .versions directory: %w", err)
 	}
 
+	glog.V(0).Infof("CI-DEBUG: updateLatestVersionInDirectory: got .versions entry for %s/%s, updating metadata", bucket, object)
+
 	// Add or update the latest version metadata
 	if versionsEntry.Extended == nil {
 		versionsEntry.Extended = make(map[string][]byte)
@@ -657,9 +665,11 @@ func (s3a *S3ApiServer) updateLatestVersionInDirectory(bucket, object, versionId
 	})
 	if err != nil {
 		glog.Errorf("updateLatestVersionInDirectory: failed to update .versions directory metadata: %v", err)
+		glog.V(0).Infof("CI-DEBUG: updateLatestVersionInDirectory: FAILED to save .versions metadata for %s/%s: %v", bucket, object, err)
 		return fmt.Errorf("failed to update .versions directory metadata: %w", err)
 	}
 
+	glog.V(0).Infof("CI-DEBUG: updateLatestVersionInDirectory: successfully saved .versions metadata for %s/%s version %s", bucket, object, versionId)
 	return nil
 }
 

weed/s3api/s3api_object_versioning.go

@@ -780,6 +780,7 @@ func (s3a *S3ApiServer) getLatestObjectVersion(bucket, object string) (*filer_pb
 	versionsObjectPath := object + ".versions"
 
 	glog.V(1).Infof("getLatestObjectVersion: looking for latest version of %s/%s", bucket, object)
+	glog.V(0).Infof("CI-DEBUG: getLatestObjectVersion: starting lookup for %s/%s", bucket, object)
 
 	// Get the .versions directory entry to read latest version metadata
 	versionsEntry, err := s3a.getEntry(bucketDir, versionsObjectPath)
@@ -788,6 +789,7 @@ func (s3a *S3ApiServer) getLatestObjectVersion(bucket, object string) (*filer_pb
 		// before versioning was enabled on the bucket. Fall back to checking for a
 		// regular (non-versioned) object file.
 		glog.V(1).Infof("getLatestObjectVersion: no .versions directory for %s%s (error: %v), checking for pre-versioning object", bucket, object, err)
+		glog.V(0).Infof("CI-DEBUG: getLatestObjectVersion: no .versions directory for %s/%s (error: %v), falling back to pre-versioning", bucket, object, err)
 
 		regularEntry, regularErr := s3a.getEntry(bucketDir, object)
 		if regularErr != nil {
@@ -804,6 +806,7 @@ func (s3a *S3ApiServer) getLatestObjectVersion(bucket, object string) (*filer_pb
 		// No metadata means all versioned objects have been deleted.
 		// Fall back to checking for a pre-versioning object.
 		glog.V(2).Infof("getLatestObjectVersion: no Extended metadata in .versions directory for %s%s, checking for pre-versioning object", bucket, object)
+		glog.V(0).Infof("CI-DEBUG: getLatestObjectVersion: .versions directory exists but NO Extended metadata for %s/%s - possible race condition", bucket, object)
 
 		regularEntry, regularErr := s3a.getEntry(bucketDir, object)
 		if regularErr != nil {
@@ -817,10 +820,13 @@ func (s3a *S3ApiServer) getLatestObjectVersion(bucket, object string) (*filer_pb
 	latestVersionIdBytes, hasLatestVersionId := versionsEntry.Extended[s3_constants.ExtLatestVersionIdKey]
 	latestVersionFileBytes, hasLatestVersionFile := versionsEntry.Extended[s3_constants.ExtLatestVersionFileNameKey]
 
+	glog.V(0).Infof("CI-DEBUG: getLatestObjectVersion: .versions metadata check for %s/%s - hasLatestVersionId=%v, hasLatestVersionFile=%v", bucket, object, hasLatestVersionId, hasLatestVersionFile)
+
 	if !hasLatestVersionId || !hasLatestVersionFile {
 		// No version metadata means all versioned objects have been deleted.
 		// Fall back to checking for a pre-versioning object.
 		glog.V(2).Infof("getLatestObjectVersion: no version metadata in .versions directory for %s/%s, checking for pre-versioning object", bucket, object)
+		glog.V(0).Infof("CI-DEBUG: getLatestObjectVersion: MISSING version metadata keys for %s/%s - possible race condition", bucket, object)
 
 		regularEntry, regularErr := s3a.getEntry(bucketDir, object)
 		if regularErr != nil {
@@ -835,14 +841,17 @@ func (s3a *S3ApiServer) getLatestObjectVersion(bucket, object string) (*filer_pb
 	latestVersionFile := string(latestVersionFileBytes)
 
 	glog.V(2).Infof("getLatestObjectVersion: found latest version %s (file: %s) for %s/%s", latestVersionId, latestVersionFile, bucket, object)
+	glog.V(0).Infof("CI-DEBUG: getLatestObjectVersion: found metadata - version %s file %s for %s/%s", latestVersionId, latestVersionFile, bucket, object)
 
 	// Get the actual latest version file entry
 	latestVersionPath := versionsObjectPath + "/" + latestVersionFile
 	latestVersionEntry, err := s3a.getEntry(bucketDir, latestVersionPath)
 	if err != nil {
+		glog.V(0).Infof("CI-DEBUG: getLatestObjectVersion: FAILED to get version file %s: %v", latestVersionPath, err)
 		return nil, fmt.Errorf("failed to get latest version file %s: %v", latestVersionPath, err)
 	}
 
+	glog.V(0).Infof("CI-DEBUG: getLatestObjectVersion: successfully retrieved version file for %s/%s", bucket, object)
 	return latestVersionEntry, nil
 }