Skip to content

Commit

Permalink
refactor(pinmfs): log error if pre-existing pin failed (#8056)
Browse files Browse the repository at this point in the history 
* pinmfs: log error if pin failed
* refactor: log pre-existing remote mfs pins

This cleans up debug logging and ensures we use %q for data read from
remote services. We log pre-existing pins for MFS root and print ERROR
if pin for current root has status "failed", otherwise, we log to debug.

Co-authored-by: Marcin Rataj <lidel@lidel.org>
  • Loading branch information
@BogdanStirbat @lidel
BogdanStirbat and lidel authored May 17, 2021
1 parent b0fda5c commit 075cc8f
Show file tree
Hide file tree
Showing 2 changed files with 22 additions and 16 deletions.
34 changes: 20 additions & 14 deletions cmd/ipfs/pinmfs.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -138,9 +138,9 @@ func pinAllMFS(ctx context.Context, node pinMFSNode, cfg *config.Config, rootCid
for svcName_, svcConfig_ := range cfg.Pinning.RemoteServices {
// skip services where MFS is not enabled
svcName, svcConfig := svcName_, svcConfig_
mfslog.Debugf("pinning considering service %s for mfs pinning", svcName)
mfslog.Debugf("pinning MFS root considering service %q", svcName)
if !svcConfig.Policies.MFS.Enable {
mfslog.Debugf("pinning service %s is not enabled", svcName)
mfslog.Debugf("pinning service %q is not enabled", svcName)
ch <- lastPin{}
continue
}
Expand All @@ -153,7 +153,7 @@ func pinAllMFS(ctx context.Context, node pinMFSNode, cfg *config.Config, rootCid
repinInterval, err = time.ParseDuration(svcConfig.Policies.MFS.RepinInterval)
if err != nil {
select {
case errCh <- fmt.Errorf("remote pinning service %s has invalid MFS.RepinInterval (%v)", svcName, err):
case errCh <- fmt.Errorf("remote pinning service %q has invalid MFS.RepinInterval (%v)", svcName, err):
case <-ctx.Done():
}
ch <- lastPin{}
Expand All @@ -165,20 +165,20 @@ func pinAllMFS(ctx context.Context, node pinMFSNode, cfg *config.Config, rootCid
if last, ok := lastPins[svcName]; ok {
if last.ServiceConfig == svcConfig && (last.CID == rootCid || time.Since(last.Time) < repinInterval) {
if last.CID == rootCid {
mfslog.Debugf("pinning MFS root to %s: pin for %s exists since %s, skipping", svcName, rootCid, last.Time.String())
mfslog.Debugf("pinning MFS root to %q: pin for %q exists since %s, skipping", svcName, rootCid, last.Time.String())
} else {
mfslog.Debugf("pinning MFS root to %s: skipped due to MFS.RepinInterval=%s (remaining: %s)", svcName, repinInterval.String(), (repinInterval - time.Since(last.Time)).String())
mfslog.Debugf("pinning MFS root to %q: skipped due to MFS.RepinInterval=%s (remaining: %s)", svcName, repinInterval.String(), (repinInterval - time.Since(last.Time)).String())
}
ch <- lastPin{}
continue
}
}

mfslog.Debugf("pinning MFS root %s to %s", rootCid, svcName)
mfslog.Debugf("pinning MFS root %q to %q", rootCid, svcName)
go func() {
if r, err := pinMFS(ctx, node, rootCid, svcName, svcConfig); err != nil {
select {
case errCh <- fmt.Errorf("pinning MFS root %s to %s (%v)", rootCid, svcName, err):
case errCh <- fmt.Errorf("pinning MFS root %q to %q (%v)", rootCid, svcName, err):
case <-ctx.Done():
}
ch <- lastPin{}
Expand Down Expand Up @@ -212,12 +212,18 @@ func pinMFS(
pinStatuses := []pinclient.Status{pinclient.StatusQueued, pinclient.StatusPinning, pinclient.StatusPinned, pinclient.StatusFailed}
lsPinCh, lsErrCh := c.Ls(ctx, pinclient.PinOpts.FilterName(pinName), pinclient.PinOpts.FilterStatus(pinStatuses...))
existingRequestID := "" // is there any pre-existing MFS pin with pinName (for any CID)?
alreadyPinned := false // is CID for current MFS already pinned?
pinning := false // is CID for current MFS already being pinned?
pinTime := time.Now().UTC()
pinStatusMsg := "pinning to %q: received pre-existing %q status for %q (requestid=%q)"
for ps := range lsPinCh {
existingRequestID = ps.GetRequestId()
if ps.GetPin().GetCid() == cid && ps.GetStatus() == pinclient.StatusFailed {
mfslog.Errorf(pinStatusMsg, svcName, pinclient.StatusFailed, cid, existingRequestID)
} else {
mfslog.Debugf(pinStatusMsg, svcName, ps.GetStatus(), ps.GetPin().GetCid(), existingRequestID)
}
if ps.GetPin().GetCid() == cid && ps.GetStatus() != pinclient.StatusFailed {
alreadyPinned = true
pinning = true
pinTime = ps.GetCreated().UTC()
break
}
Expand All @@ -228,9 +234,9 @@ func pinMFS(
return lastPin{}, fmt.Errorf("error while listing remote pins: %v", err)
}

// CID of the current MFS root is already pinned, nothing to do
if alreadyPinned {
mfslog.Debugf("pinning MFS to %s: pin for %s exists since %s, skipping", svcName, cid, pinTime.String())
// CID of the current MFS root is already being pinned, nothing to do
if pinning {
mfslog.Debugf("pinning MFS to %q: pin for %q exists since %s, skipping", svcName, cid, pinTime.String())
return lastPin{Time: pinTime, ServiceName: svcName, ServiceConfig: svcConfig, CID: cid}, nil
}

Expand All @@ -250,13 +256,13 @@ func pinMFS(

// Create or replace pin for MFS root
if existingRequestID != "" {
mfslog.Debugf("pinning to %s: replacing existing MFS root pin with %s", svcName, cid)
mfslog.Debugf("pinning to %q: replacing existing MFS root pin with %q", svcName, cid)
_, err := c.Replace(ctx, existingRequestID, cid, addOpts...)
if err != nil {
return lastPin{}, err
}
} else {
mfslog.Debugf("pinning to %s: creating a new MFS root pin for %s", svcName, cid)
mfslog.Debugf("pinning to %q: creating a new MFS root pin for %q", svcName, cid)
_, err := c.Add(ctx, cid, addOpts...)
if err != nil {
return lastPin{}, err
Expand Down
4 changes: 2 additions & 2 deletions cmd/ipfs/pinmfs_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,7 @@ import (

config "github.com/ipfs/go-ipfs-config"
ipld "github.com/ipfs/go-ipld-format"
"github.com/ipfs/go-merkledag"
merkledag "github.com/ipfs/go-merkledag"
"github.com/libp2p/go-libp2p-core/host"
peer "github.com/libp2p/go-libp2p-core/peer"
)
Expand Down Expand Up @@ -149,7 +149,7 @@ func TestPinMFSService(t *testing.T) {
},
},
}
testPinMFSServiceWithError(t, cfg_invalid_interval, "remote pinning service invalid_interval has invalid MFS.RepinInterval")
testPinMFSServiceWithError(t, cfg_invalid_interval, "remote pinning service \"invalid_interval\" has invalid MFS.RepinInterval")
testPinMFSServiceWithError(t, cfg_valid_unnamed, "error while listing remote pins: empty response from remote pinning service")
testPinMFSServiceWithError(t, cfg_valid_named, "error while listing remote pins: empty response from remote pinning service")
}
Expand Down

0 comments on commit 075cc8f

Please sign in to comment.