Add more logging for input/output bug

Makefile

@@ -61,6 +61,9 @@ soci: proto
 soci-store: proto
 	cd cmd/ ; GO111MODULE=$(GO111MODULE_VALUE) go build -o $(OUTDIR)/$@ $(GO_BUILD_FLAGS) $(GO_LD_FLAGS) ./soci-store
 
+soci-store-race: proto
+	cd cmd/ ; GO111MODULE=$(GO111MODULE_VALUE) go build -race -o $(OUTDIR)/$@ $(GO_BUILD_FLAGS) $(GO_LD_FLAGS) ./soci-store
+
 proto:
 	protoc --go_out=. --go_opt=paths=source_relative --go-grpc_out=. --go-grpc_opt=paths=source_relative proto/local_keychain.proto
 

store/fs.go

@@ -41,6 +41,7 @@ import (
 	"fmt"
 	"io"
 	"os/exec"
+	"reflect"
 	"sync"
 	"syscall"
 	"time"
@@ -194,7 +195,7 @@ func (n *rootnode) Lookup(ctx context.Context, name string, out *fuse.EntryOut)
 		case *refnode:
 			copyAttr(&out.Attr, &tn.attr)
 		default:
-			log.G(ctx).Warn("rootnode.Lookup: uknown node type detected")
+			log.G(ctx).Warnf("rootnode.Lookup: unknown node type detected: %s", reflect.TypeOf(tn))
 			return nil, syscall.EIO
 		}
 		out.Attr.Ino = cn.StableAttr().Ino
@@ -233,6 +234,7 @@ func (n *rootnode) Lookup(ctx context.Context, name string, out *fuse.EntryOut)
 		out.Attr.Ino = uint64(ino)
 		cn.attr.Ino = uint64(ino)
 		sAttr.Ino = uint64(ino)
+		log.G(ctx).Debugf("refnode %s has ino %d", name, ino)
 		return n.NewInode(ctx, cn, sAttr)
 	})
 }
@@ -258,7 +260,7 @@ func (n *refnode) Lookup(ctx context.Context, name string, out *fuse.EntryOut) (
 		case *layernode:
 			copyAttr(&out.Attr, &tn.attr)
 		default:
-			log.G(ctx).Warn("rootnode.Lookup: uknown node type detected")
+			log.G(ctx).Warnf("refnode.Lookup: unknown node type detected: %s", reflect.TypeOf(tn))
 			return nil, syscall.EIO
 		}
 		out.Attr.Ino = cn.StableAttr().Ino
@@ -280,6 +282,7 @@ func (n *refnode) Lookup(ctx context.Context, name string, out *fuse.EntryOut) (
 		out.Attr.Ino = uint64(ino)
 		cn.attr.Ino = uint64(ino)
 		sAttr.Ino = uint64(ino)
+		log.G(ctx).Debugf("layernode %s (reference %s) has ino %d", name, n.ref.String(), ino)
 		return n.NewInode(ctx, cn, sAttr)
 	})
 }
@@ -402,6 +405,9 @@ func (n *layernode) Lookup(ctx context.Context, name string, out *fuse.EntryOut)
 			}
 			log.G(ctx).WithField(remoteSnapshotLogKey, prepareFailed).
 				WithField("layerdigest", n.digest).
+				WithField("ref", n.refnode.ref.String()).
+				WithField("refnode-ino", n.refnode.attr.Ino).
+				WithField("layer-ino", n.attr.Ino).
 				WithError(err).
 				Debugf("error resolving layer (context error: %v)", cErr)
 			log.G(ctx).WithError(err).Warnf("failed to mount layer %q: %q", name, n.digest)

store/manager.go

@@ -179,6 +179,7 @@ func (r *LayerManager) getLayer(ctx context.Context, refspec reference.Spec, dgs
 		errChan    = make(chan error)
 	)
 	manifest, _, err := r.refPool.loadRef(ctx, refspec)
+	log.G(ctx).Debugf("fetched manifest with config digest %s for %s", manifest.Config.Digest.String(), refspec.String())
 	if err != nil {
 		return nil, fmt.Errorf("failed to get manifest and config: %w", err)
 	}
@@ -202,7 +203,7 @@ func (r *LayerManager) getLayer(ctx context.Context, refspec reference.Spec, dgs
 		for _, l := range manifest.Layers {
 			layers = append(layers, l.Digest.String())
 		}
-		return nil, fmt.Errorf("unknown digest %v for ref %q (known digests: [%s])", target, refspec.String(), strings.Join(layers, ","))
+		return nil, fmt.Errorf("unknown digest %s for ref %q (known digests: [%s])", dgst.String(), refspec.String(), strings.Join(layers, ","))
 	}
 	for _, l := range append([]ocispec.Descriptor{target}, preResolve...) {
 		l := l