feat: add more logging to the collaboration service

changelog/unreleased/collaboration-logging.md

@@ -0,0 +1,5 @@
+Enhancement: Improve the collaboration service logging
+
+We added more debug log information to the collaboration service. This is vital for scenarios when we need to debug in remote setups.
+
+https://github.com/owncloud/ocis/pull/9653

services/collaboration/pkg/connector/contentconnector.go

@@ -67,7 +67,10 @@ func (c *ContentConnector) GetFile(ctx context.Context, writer io.Writer) error
 		return err
 	}
 
-	logger := zerolog.Ctx(ctx)
+	logger := zerolog.Ctx(ctx).With().
+		Interface("FileReference", wopiContext.FileReference).
+		Logger()
+	logger.Debug().Msg("GetFile: start")
 
 	// Initiate download request
 	req := &providerv1beta1.InitiateFileDownloadRequest{
@@ -201,7 +204,9 @@ func (c *ContentConnector) PutFile(ctx context.Context, stream io.Reader, stream
 	logger := zerolog.Ctx(ctx).With().
 		Str("RequestedLockID", lockID).
 		Int64("UploadLength", streamLength).
+		Interface("FileReference", wopiContext.FileReference).
 		Logger()
+	logger.Debug().Msg("PutFile: start")
 
 	// We need a stat call on the target file in order to get both the lock
 	// (if any) and the current size of the file

services/collaboration/pkg/connector/fileconnector.go

@@ -148,6 +148,7 @@ func (f *FileConnector) Lock(ctx context.Context, lockID, oldLockID string) (str
 		Str("RequestedLockID", lockID).
 		Str("RequestedOldLockID", oldLockID).
 		Logger()
+	logger.Debug().Msg("Lock: start")
 
 	if lockID == "" {
 		logger.Error().Msg("Lock failed due to empty lockID")
@@ -157,6 +158,7 @@ func (f *FileConnector) Lock(ctx context.Context, lockID, oldLockID string) (str
 	var setOrRefreshStatus *rpcv1beta1.Status
 	if oldLockID == "" {
 		// If the oldLockID is empty, this is a "LOCK" request
+		logger.Debug().Msg("Lock: this is a SetLock request")
 		req := &providerv1beta1.SetLockRequest{
 			Ref: wopiContext.FileReference,
 			Lock: &providerv1beta1.Lock{
@@ -178,6 +180,7 @@ func (f *FileConnector) Lock(ctx context.Context, lockID, oldLockID string) (str
 	} else {
 		// If the oldLockID isn't empty, this is a "UnlockAndRelock" request. We'll
 		// do a "RefreshLock" in reva and provide the old lock
+		logger.Debug().Msg("Lock: this is a RefreshLock request")
 		req := &providerv1beta1.RefreshLockRequest{
 			Ref: wopiContext.FileReference,
 			Lock: &providerv1beta1.Lock{
@@ -285,6 +288,7 @@ func (f *FileConnector) RefreshLock(ctx context.Context, lockID string) (string,
 	logger := zerolog.Ctx(ctx).With().
 		Str("RequestedLockID", lockID).
 		Logger()
+	logger.Debug().Msg("RefreshLock: start")
 
 	if lockID == "" {
 		logger.Error().Msg("RefreshLock failed due to empty lockID")
@@ -393,6 +397,7 @@ func (f *FileConnector) UnLock(ctx context.Context, lockID string) (string, erro
 	logger := zerolog.Ctx(ctx).With().
 		Str("RequestedLockID", lockID).
 		Logger()
+	logger.Debug().Msg("UnLock: start")
 
 	if lockID == "" {
 		logger.Error().Msg("Unlock failed due to empty lockID")
@@ -579,7 +584,7 @@ func (f *FileConnector) CheckFileInfo(ctx context.Context) (fileinfo.FileInfo, e
 
 	info.SetProperties(infoMap)
 
-	logger.Debug().Msg("CheckFileInfo: success")
+	logger.Debug().Interface("FileInfo", info).Msg("CheckFileInfo: success")
 	return info, nil
 }
 

services/collaboration/pkg/middleware/accesslog.go

@@ -27,6 +27,7 @@ func AccessLog(logger log.Logger) func(http.Handler) http.Handler {
 				Str("traceid", spanContext.TraceID().String()).
 				Str("remote-addr", r.RemoteAddr).
 				Str("method", r.Method).
+				Str("wopi-action", r.Header.Get("X-WOPI-Override")).
 				Int("status", wrap.Status()).
 				Str("path", r.URL.Path).
 				Dur("duration", time.Since(start)).