more trace spans

Signed-off-by: Jörn Friedrich Dreyer <[email protected]>

changelog/unreleased/more-traces.md

@@ -0,0 +1,3 @@
+Enhancement: we added more trace spans in decomposedfs
+
+https://github.com/cs3org/reva/pull/4978

pkg/storage/fs/posix/tree/tree.go

@@ -704,6 +704,8 @@ func (t *Tree) ResolveSpaceIDIndexEntry(spaceid, entry string) (string, string,
 
 // InitNewNode initializes a new node
 func (t *Tree) InitNewNode(ctx context.Context, n *node.Node, fsize uint64) (metadata.UnlockFunc, error) {
+	_, span := tracer.Start(ctx, "InitNewNode")
+	defer span.End()
 	// create folder structure (if needed)
 	if err := os.MkdirAll(filepath.Dir(n.InternalPath()), 0700); err != nil {
 		return nil, err

pkg/storage/utils/decomposedfs/grants.go

@@ -38,6 +38,8 @@ import (
 
 // DenyGrant denies access to a resource.
 func (fs *Decomposedfs) DenyGrant(ctx context.Context, ref *provider.Reference, grantee *provider.Grantee) error {
+	_, span := tracer.Start(ctx, "DenyGrant")
+	defer span.End()
 	log := appctx.GetLogger(ctx)
 
 	log.Debug().Interface("ref", ref).Interface("grantee", grantee).Msg("DenyGrant()")
@@ -74,6 +76,8 @@ func (fs *Decomposedfs) DenyGrant(ctx context.Context, ref *provider.Reference,
 
 // AddGrant adds a grant to a resource
 func (fs *Decomposedfs) AddGrant(ctx context.Context, ref *provider.Reference, g *provider.Grant) (err error) {
+	_, span := tracer.Start(ctx, "AddGrant")
+	defer span.End()
 	log := appctx.GetLogger(ctx)
 	log.Debug().Interface("ref", ref).Interface("grant", g).Msg("AddGrant()")
 	grantNode, unlockFunc, grant, err := fs.loadGrant(ctx, ref, g)
@@ -119,6 +123,8 @@ func (fs *Decomposedfs) AddGrant(ctx context.Context, ref *provider.Reference, g
 
 // ListGrants lists the grants on the specified resource
 func (fs *Decomposedfs) ListGrants(ctx context.Context, ref *provider.Reference) (grants []*provider.Grant, err error) {
+	_, span := tracer.Start(ctx, "ListGrants")
+	defer span.End()
 	var grantNode *node.Node
 	if grantNode, err = fs.lu.NodeFromResource(ctx, ref); err != nil {
 		return
@@ -174,6 +180,8 @@ func (fs *Decomposedfs) ListGrants(ctx context.Context, ref *provider.Reference)
 
 // RemoveGrant removes a grant from resource
 func (fs *Decomposedfs) RemoveGrant(ctx context.Context, ref *provider.Reference, g *provider.Grant) (err error) {
+	_, span := tracer.Start(ctx, "RemoveGrant")
+	defer span.End()
 	grantNode, unlockFunc, grant, err := fs.loadGrant(ctx, ref, g)
 	if err != nil {
 		return err
@@ -235,6 +243,8 @@ func isShareGrant(ctx context.Context) bool {
 // UpdateGrant updates a grant on a resource
 // TODO remove AddGrant or UpdateGrant grant from CS3 api, redundant? tracked in https://github.com/cs3org/cs3apis/issues/92
 func (fs *Decomposedfs) UpdateGrant(ctx context.Context, ref *provider.Reference, g *provider.Grant) error {
+	_, span := tracer.Start(ctx, "UpdateGrant")
+	defer span.End()
 	log := appctx.GetLogger(ctx)
 	log.Debug().Interface("ref", ref).Interface("grant", g).Msg("UpdateGrant()")
 
@@ -272,6 +282,8 @@ func (fs *Decomposedfs) UpdateGrant(ctx context.Context, ref *provider.Reference
 
 // checks if the given grant exists and returns it. Nil grant means it doesn't exist
 func (fs *Decomposedfs) loadGrant(ctx context.Context, ref *provider.Reference, g *provider.Grant) (*node.Node, metadata.UnlockFunc, *provider.Grant, error) {
+	_, span := tracer.Start(ctx, "loadGrant")
+	defer span.End()
 	n, err := fs.lu.NodeFromResource(ctx, ref)
 	if err != nil {
 		return nil, nil, nil, err
@@ -308,6 +320,8 @@ func (fs *Decomposedfs) loadGrant(ctx context.Context, ref *provider.Reference,
 }
 
 func (fs *Decomposedfs) storeGrant(ctx context.Context, n *node.Node, g *provider.Grant) error {
+	_, span := tracer.Start(ctx, "storeGrant")
+	defer span.End()
 	// if is a grant to a space root, the receiver needs the space type to update the indexes
 	spaceType, ok := storageprovider.SpaceTypeFromContext(ctx)
 	if !ok {

pkg/storage/utils/decomposedfs/metadata.go

@@ -38,6 +38,8 @@ import (
 
 // SetArbitraryMetadata sets the metadata on a resource
 func (fs *Decomposedfs) SetArbitraryMetadata(ctx context.Context, ref *provider.Reference, md *provider.ArbitraryMetadata) (err error) {
+	_, span := tracer.Start(ctx, "SetArbitraryMetadata")
+	defer span.End()
 	n, err := fs.lu.NodeFromResource(ctx, ref)
 	if err != nil {
 		return errors.Wrap(err, "Decomposedfs: error resolving ref")
@@ -131,6 +133,8 @@ func (fs *Decomposedfs) SetArbitraryMetadata(ctx context.Context, ref *provider.
 
 // UnsetArbitraryMetadata unsets the metadata on the given resource
 func (fs *Decomposedfs) UnsetArbitraryMetadata(ctx context.Context, ref *provider.Reference, keys []string) (err error) {
+	_, span := tracer.Start(ctx, "UnsetArbitraryMetadata")
+	defer span.End()
 	n, err := fs.lu.NodeFromResource(ctx, ref)
 	if err != nil {
 		return errors.Wrap(err, "Decomposedfs: error resolving ref")

pkg/storage/utils/decomposedfs/node/locks.go

@@ -38,6 +38,8 @@ import (
 
 // SetLock sets a lock on the node
 func (n *Node) SetLock(ctx context.Context, lock *provider.Lock) error {
+	ctx, span := tracer.Start(ctx, "SetLock")
+	defer span.End()
 	lockFilePath := n.LockFilePath()
 
 	// ensure parent path exists
@@ -89,6 +91,8 @@ func (n *Node) SetLock(ctx context.Context, lock *provider.Lock) error {
 
 // ReadLock reads the lock id for a node
 func (n Node) ReadLock(ctx context.Context, skipFileLock bool) (*provider.Lock, error) {
+	ctx, span := tracer.Start(ctx, "ReadLock")
+	defer span.End()
 
 	// ensure parent path exists
 	if err := os.MkdirAll(filepath.Dir(n.InternalPath()), 0700); err != nil {
@@ -142,6 +146,8 @@ func (n Node) ReadLock(ctx context.Context, skipFileLock bool) (*provider.Lock,
 
 // RefreshLock refreshes the node's lock
 func (n *Node) RefreshLock(ctx context.Context, lock *provider.Lock, existingLockID string) error {
+	ctx, span := tracer.Start(ctx, "RefreshLock")
+	defer span.End()
 
 	// ensure parent path exists
 	if err := os.MkdirAll(filepath.Dir(n.InternalPath()), 0700); err != nil {
@@ -204,6 +210,8 @@ func (n *Node) RefreshLock(ctx context.Context, lock *provider.Lock, existingLoc
 
 // Unlock unlocks the node
 func (n *Node) Unlock(ctx context.Context, lock *provider.Lock) error {
+	ctx, span := tracer.Start(ctx, "Unlock")
+	defer span.End()
 
 	// ensure parent path exists
 	if err := os.MkdirAll(filepath.Dir(n.InternalPath()), 0700); err != nil {

pkg/storage/utils/decomposedfs/node/node.go

@@ -218,6 +218,8 @@ func (n *Node) MarshalJSON() ([]byte, error) {
 
 // Type returns the node's resource type
 func (n *Node) Type(ctx context.Context) provider.ResourceType {
+	_, span := tracer.Start(ctx, "Type")
+	defer span.End()
 	if n.nodeType != nil {
 		return *n.nodeType
 	}
@@ -446,6 +448,8 @@ func (n *Node) Child(ctx context.Context, name string) (*Node, error) {
 
 // ParentWithReader returns the parent node
 func (n *Node) ParentWithReader(ctx context.Context, r io.Reader) (*Node, error) {
+	_, span := tracer.Start(ctx, "ParentWithReader")
+	defer span.End()
 	if n.ParentID == "" {
 		return nil, fmt.Errorf("decomposedfs: root has no parent")
 	}

pkg/storage/utils/decomposedfs/node/xattrs.go

@@ -68,6 +68,8 @@ func (md Attributes) Time(key string) (time.Time, error) {
 
 // SetXattrs sets multiple extended attributes on the write-through cache/node
 func (n *Node) SetXattrsWithContext(ctx context.Context, attribs map[string][]byte, acquireLock bool) (err error) {
+	_, span := tracer.Start(ctx, "SetXattrsWithContext")
+	defer span.End()
 	if n.xattrsCache != nil {
 		for k, v := range attribs {
 			n.xattrsCache[k] = v

pkg/storage/utils/decomposedfs/permissions/spacepermissions.go

@@ -60,6 +60,8 @@ func (p Permissions) AssemblePermissions(ctx context.Context, n *node.Node) (*pr
 
 // AssembleTrashPermissions is used to assemble file permissions
 func (p Permissions) AssembleTrashPermissions(ctx context.Context, n *node.Node) (*provider.ResourcePermissions, error) {
+	_, span := tracer.Start(ctx, "AssembleTrashPermissions")
+	defer span.End()
 	return p.item.AssembleTrashPermissions(ctx, n)
 }
 

pkg/storage/utils/decomposedfs/recycle.go

@@ -64,7 +64,8 @@ func (tb *DecomposedfsTrashbin) Setup(fs storage.FS) error {
 // ListRecycle returns the list of available recycle items
 // ref -> the space (= resourceid), key -> deleted node id, relativePath = relative to key
 func (tb *DecomposedfsTrashbin) ListRecycle(ctx context.Context, ref *provider.Reference, key, relativePath string) ([]*provider.RecycleItem, error) {
-
+	_, span := tracer.Start(ctx, "ListRecycle")
+	defer span.End()
 	if ref == nil || ref.ResourceId == nil || ref.ResourceId.OpaqueId == "" {
 		return nil, errtypes.BadRequest("spaceid required")
 	}
@@ -346,6 +347,8 @@ func (tb *DecomposedfsTrashbin) listTrashRoot(ctx context.Context, spaceID strin
 
 // RestoreRecycleItem restores the specified item
 func (tb *DecomposedfsTrashbin) RestoreRecycleItem(ctx context.Context, ref *provider.Reference, key, relativePath string, restoreRef *provider.Reference) error {
+	_, span := tracer.Start(ctx, "RestoreRecycleItem")
+	defer span.End()
 	if ref == nil {
 		return errtypes.BadRequest("missing reference, needs a space id")
 	}
@@ -399,6 +402,8 @@ func (tb *DecomposedfsTrashbin) RestoreRecycleItem(ctx context.Context, ref *pro
 
 // PurgeRecycleItem purges the specified item, all its children and all their revisions
 func (tb *DecomposedfsTrashbin) PurgeRecycleItem(ctx context.Context, ref *provider.Reference, key, relativePath string) error {
+	_, span := tracer.Start(ctx, "PurgeRecycleItem")
+	defer span.End()
 	if ref == nil {
 		return errtypes.BadRequest("missing reference, needs a space id")
 	}
@@ -429,6 +434,8 @@ func (tb *DecomposedfsTrashbin) PurgeRecycleItem(ctx context.Context, ref *provi
 
 // EmptyRecycle empties the trash
 func (tb *DecomposedfsTrashbin) EmptyRecycle(ctx context.Context, ref *provider.Reference) error {
+	_, span := tracer.Start(ctx, "EmptyRecycle")
+	defer span.End()
 	if ref == nil || ref.ResourceId == nil || ref.ResourceId.OpaqueId == "" {
 		return errtypes.BadRequest("spaceid must be set")
 	}

pkg/storage/utils/decomposedfs/revisions.go

@@ -48,6 +48,8 @@ import (
 
 // ListRevisions lists the revisions of the given resource
 func (fs *Decomposedfs) ListRevisions(ctx context.Context, ref *provider.Reference) (revisions []*provider.FileVersion, err error) {
+	_, span := tracer.Start(ctx, "ListRevisions")
+	defer span.End()
 	var n *node.Node
 	if n, err = fs.lu.NodeFromResource(ctx, ref); err != nil {
 		return
@@ -115,6 +117,8 @@ func (fs *Decomposedfs) ListRevisions(ctx context.Context, ref *provider.Referen
 // DownloadRevision returns a reader for the specified revision
 // FIXME the CS3 api should explicitly allow initiating revision and trash download, a related issue is https://github.com/cs3org/reva/issues/1813
 func (fs *Decomposedfs) DownloadRevision(ctx context.Context, ref *provider.Reference, revisionKey string, openReaderFunc func(md *provider.ResourceInfo) bool) (*provider.ResourceInfo, io.ReadCloser, error) {
+	_, span := tracer.Start(ctx, "DownloadRevision")
+	defer span.End()
 	log := appctx.GetLogger(ctx)
 
 	// verify revision key format
@@ -186,6 +190,8 @@ func (fs *Decomposedfs) DownloadRevision(ctx context.Context, ref *provider.Refe
 
 // RestoreRevision restores the specified revision of the resource
 func (fs *Decomposedfs) RestoreRevision(ctx context.Context, ref *provider.Reference, revisionKey string) (returnErr error) {
+	_, span := tracer.Start(ctx, "RestoreRevision")
+	defer span.End()
 	log := appctx.GetLogger(ctx)
 
 	// verify revision key format
@@ -330,6 +336,8 @@ func (fs *Decomposedfs) RestoreRevision(ctx context.Context, ref *provider.Refer
 
 // DeleteRevision deletes the specified revision of the resource
 func (fs *Decomposedfs) DeleteRevision(ctx context.Context, ref *provider.Reference, revisionKey string) error {
+	_, span := tracer.Start(ctx, "DeleteRevision")
+	defer span.End()
 	n, err := fs.getRevisionNode(ctx, ref, revisionKey, func(rp *provider.ResourcePermissions) bool {
 		return rp.RestoreFileVersion
 	})
@@ -345,6 +353,8 @@ func (fs *Decomposedfs) DeleteRevision(ctx context.Context, ref *provider.Refere
 }
 
 func (fs *Decomposedfs) getRevisionNode(ctx context.Context, ref *provider.Reference, revisionKey string, hasPermission func(*provider.ResourcePermissions) bool) (*node.Node, error) {
+	_, span := tracer.Start(ctx, "getRevisionNode")
+	defer span.End()
 	log := appctx.GetLogger(ctx)
 
 	// verify revision key format

pkg/storage/utils/decomposedfs/tree/tree.go

@@ -106,6 +106,8 @@ func (t *Tree) Setup() error {
 
 // GetMD returns the metadata of a node in the tree
 func (t *Tree) GetMD(ctx context.Context, n *node.Node) (os.FileInfo, error) {
+	_, span := tracer.Start(ctx, "GetMD")
+	defer span.End()
 	md, err := os.Stat(n.InternalPath())
 	if err != nil {
 		if errors.Is(err, fs.ErrNotExist) {
@@ -119,6 +121,8 @@ func (t *Tree) GetMD(ctx context.Context, n *node.Node) (os.FileInfo, error) {
 
 // TouchFile creates a new empty file
 func (t *Tree) TouchFile(ctx context.Context, n *node.Node, markprocessing bool, mtime string) error {
+	_, span := tracer.Start(ctx, "TouchFile")
+	defer span.End()
 	if n.Exists {
 		if markprocessing {
 			return n.SetXattr(ctx, prefixes.StatusPrefix, []byte(node.ProcessingStatus))
@@ -223,6 +227,8 @@ func (t *Tree) CreateDir(ctx context.Context, n *node.Node) (err error) {
 
 // Move replaces the target with the source
 func (t *Tree) Move(ctx context.Context, oldNode *node.Node, newNode *node.Node) (err error) {
+	_, span := tracer.Start(ctx, "Move")
+	defer span.End()
 	if oldNode.SpaceID != newNode.SpaceID {
 		// WebDAV RFC https://www.rfc-editor.org/rfc/rfc4918#section-9.9.4 says to use
 		// > 502 (Bad Gateway) - This may occur when the destination is on another
@@ -432,6 +438,8 @@ func (t *Tree) ListFolder(ctx context.Context, n *node.Node) ([]*node.Node, erro
 
 // Delete deletes a node in the tree by moving it to the trash
 func (t *Tree) Delete(ctx context.Context, n *node.Node) (err error) {
+	_, span := tracer.Start(ctx, "Delete")
+	defer span.End()
 	path := filepath.Join(n.ParentPath(), n.Name)
 	// remove entry from cache immediately to avoid inconsistencies
 	defer func() { _ = t.idCache.Delete(path) }()
@@ -524,6 +532,8 @@ func (t *Tree) Delete(ctx context.Context, n *node.Node) (err error) {
 
 // RestoreRecycleItemFunc returns a node and a function to restore it from the trash.
 func (t *Tree) RestoreRecycleItemFunc(ctx context.Context, spaceid, key, trashPath string, targetNode *node.Node) (*node.Node, *node.Node, func() error, error) {
+	_, span := tracer.Start(ctx, "RestoreRecycleItemFunc")
+	defer span.End()
 	logger := appctx.GetLogger(ctx)
 
 	recycleNode, trashItem, deletedNodePath, origin, err := t.readRecycleItem(ctx, spaceid, key, trashPath)
@@ -623,6 +633,8 @@ func (t *Tree) RestoreRecycleItemFunc(ctx context.Context, spaceid, key, trashPa
 
 // PurgeRecycleItemFunc returns a node and a function to purge it from the trash
 func (t *Tree) PurgeRecycleItemFunc(ctx context.Context, spaceid, key string, path string) (*node.Node, func() error, error) {
+	_, span := tracer.Start(ctx, "PurgeRecycleItemFunc")
+	defer span.End()
 	logger := appctx.GetLogger(ctx)
 
 	rn, trashItem, deletedNodePath, _, err := t.readRecycleItem(ctx, spaceid, key, path)
@@ -664,6 +676,8 @@ func (t *Tree) PurgeRecycleItemFunc(ctx context.Context, spaceid, key string, pa
 
 // InitNewNode initializes a new node
 func (t *Tree) InitNewNode(ctx context.Context, n *node.Node, fsize uint64) (metadata.UnlockFunc, error) {
+	_, span := tracer.Start(ctx, "InitNewNode")
+	defer span.End()
 	// create folder structure (if needed)
 	if err := os.MkdirAll(filepath.Dir(n.InternalPath()), 0700); err != nil {
 		return nil, err
@@ -854,6 +868,8 @@ var nodeIDRegep = regexp.MustCompile(`.*/nodes/([^.]*).*`)
 
 // TODO refactor the returned params into Node properties? would make all the path transformations go away...
 func (t *Tree) readRecycleItem(ctx context.Context, spaceID, key, path string) (recycleNode *node.Node, trashItem string, deletedNodePath string, origin string, err error) {
+	_, span := tracer.Start(ctx, "readRecycleItem")
+	defer span.End()
 	logger := appctx.GetLogger(ctx)
 
 	if key == "" {

pkg/storage/utils/decomposedfs/upload.go

@@ -47,6 +47,8 @@ import (
 // TODO Upload (and InitiateUpload) needs a way to receive the expected checksum.
 // Maybe in metadata as 'checksum' => 'sha1 aeosvp45w5xaeoe' = lowercase, space separated?
 func (fs *Decomposedfs) Upload(ctx context.Context, req storage.UploadRequest, uff storage.UploadFinishedFunc) (*provider.ResourceInfo, error) {
+	_, span := tracer.Start(ctx, "Upload")
+	defer span.End()
 	up, err := fs.GetUpload(ctx, req.Ref.GetPath())
 	if err != nil {
 		return &provider.ResourceInfo{}, errors.Wrap(err, "Decomposedfs: error retrieving upload")
@@ -130,6 +132,8 @@ func (fs *Decomposedfs) Upload(ctx context.Context, req storage.UploadRequest, u
 // TODO read optional content for small files in this request
 // TODO InitiateUpload (and Upload) needs a way to receive the expected checksum. Maybe in metadata as 'checksum' => 'sha1 aeosvp45w5xaeoe' = lowercase, space separated?
 func (fs *Decomposedfs) InitiateUpload(ctx context.Context, ref *provider.Reference, uploadLength int64, metadata map[string]string) (map[string]string, error) {
+	_, span := tracer.Start(ctx, "InitiateUpload")
+	defer span.End()
 	log := appctx.GetLogger(ctx)
 
 	// remember the path from the reference

pkg/storage/utils/decomposedfs/upload/session.go

@@ -81,6 +81,8 @@ func (s *OcisSession) executantUser() *userpb.User {
 
 // Purge deletes the upload session metadata and written binary data
 func (s *OcisSession) Purge(ctx context.Context) error {
+	_, span := tracer.Start(ctx, "Purge")
+	defer span.End()
 	sessionPath := sessionPath(s.store.root, s.info.ID)
 	f, err := lockedfile.OpenFile(sessionPath+".lock", os.O_RDWR|os.O_TRUNC|os.O_CREATE, 0600)
 	if err != nil {
@@ -112,6 +114,8 @@ func (s *OcisSession) TouchBin() error {
 // events can update the scan outcome and the finished event might read an empty file because of race conditions
 // so we need to lock the file while writing and use atomic writes
 func (s *OcisSession) Persist(ctx context.Context) error {
+	_, span := tracer.Start(ctx, "Persist")
+	defer span.End()
 	sessionPath := sessionPath(s.store.root, s.info.ID)
 	// create folder structure (if needed)
 	if err := os.MkdirAll(filepath.Dir(sessionPath), 0700); err != nil {

pkg/storage/utils/decomposedfs/upload/store.go

@@ -199,8 +199,8 @@ func (store OcisStore) Cleanup(ctx context.Context, session Session, revertNodeM
 // CreateNodeForUpload will create the target node for the Upload
 // TODO move this to the node package as NodeFromUpload?
 // should we in InitiateUpload create the node first? and then the upload?
-func (store OcisStore) CreateNodeForUpload(session *OcisSession, initAttrs node.Attributes) (*node.Node, error) {
-	ctx, span := tracer.Start(session.Context(context.Background()), "CreateNodeForUpload")
+func (store OcisStore) CreateNodeForUpload(ctx context.Context, session *OcisSession, initAttrs node.Attributes) (*node.Node, error) {
+	ctx, span := tracer.Start(session.Context(ctx), "CreateNodeForUpload")
 	defer span.End()
 	n := node.New(
 		session.SpaceID(),
@@ -303,6 +303,8 @@ func (store OcisStore) CreateNodeForUpload(session *OcisSession, initAttrs node.
 }
 
 func (store OcisStore) updateExistingNode(ctx context.Context, session *OcisSession, n *node.Node, spaceID string, fsize uint64) (metadata.UnlockFunc, error) {
+	_, span := tracer.Start(ctx, "updateExistingNode")
+	defer span.End()
 	targetPath := n.InternalPath()
 
 	// write lock existing node before reading any metadata
@@ -388,6 +390,7 @@ func (store OcisStore) updateExistingNode(ctx context.Context, session *OcisSess
 			}
 
 			// clean revision file
+			span.AddEvent("os.Create")
 			if _, err := os.Create(versionPath); err != nil {
 				return unlock, err
 			}
@@ -405,6 +408,7 @@ func (store OcisStore) updateExistingNode(ctx context.Context, session *OcisSess
 		}
 		session.info.MetaData["versionsPath"] = versionPath
 		// keep mtime from previous version
+		span.AddEvent("os.Chtimes")
 		if err := os.Chtimes(session.info.MetaData["versionsPath"], oldNodeMtime, oldNodeMtime); err != nil {
 			return unlock, errtypes.InternalError(fmt.Sprintf("failed to change mtime of version node: %s", err))
 		}