Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add a bit of logging #301

Merged
merged 2 commits into from
Dec 7, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions responsemanager/client.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ package responsemanager
import (
"context"
"errors"
"time"

logging "github.com/ipfs/go-log/v2"
"github.com/ipfs/go-peertaskqueue/peertask"
Expand Down Expand Up @@ -36,6 +37,7 @@ type inProgressResponseStatus struct {
updates []gsmsg.GraphSyncRequest
state graphsync.RequestState
subscriber *notifications.TopicDataSubscriber
startTime time.Time
}

type responseKey struct {
Expand Down
14 changes: 13 additions & 1 deletion responsemanager/server.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ import (
"context"
"errors"
"math"
"time"

"github.com/ipfs/go-peertaskqueue/peertask"
"github.com/libp2p/go-libp2p-core/peer"
Expand Down Expand Up @@ -155,6 +156,11 @@ func (rm *ResponseManager) processRequests(p peer.ID, requests []gsmsg.GraphSync
networkErrorListeners: rm.networkErrorListeners,
connManager: rm.connManager,
})
log.Infow("graphsync request initiated", "request id", request.ID(), "peer", p, "root", request.Root())
ipr, ok := rm.inProgressResponses[key]
if ok && ipr.state == graphsync.Running {
log.Warnf("there is an identical request already in progress", "request id", request.ID(), "peer", p)
}

rm.inProgressResponses[key] =
&inProgressResponseStatus{
Expand All @@ -167,7 +173,8 @@ func (rm *ResponseManager) processRequests(p peer.ID, requests []gsmsg.GraphSync
UpdateSignal: make(chan struct{}, 1),
ErrSignal: make(chan error, 1),
},
state: graphsync.Queued,
state: graphsync.Queued,
startTime: time.Now(),
}
// TODO: Use a better work estimation metric.

Expand All @@ -180,6 +187,8 @@ func (rm *ResponseManager) taskDataForKey(key responseKey) queryexecutor.Respons
if !hasResponse {
return queryexecutor.ResponseTask{Empty: true}
}
log.Infow("graphsync response processing begins", "request id", key.requestID, "peer", key.p, "total time", time.Since(response.startTime))

if response.loader == nil || response.traverser == nil {
loader, traverser, isPaused, err := (&queryPreparer{rm.requestHooks, rm.responseAssembler, rm.linkSystem, rm.maxLinksPerRequest}).prepareQuery(response.ctx, key.p, response.request, response.signals, response.subscriber)
if err != nil {
Expand Down Expand Up @@ -212,6 +221,7 @@ func (rm *ResponseManager) startTask(task *peertask.Task) queryexecutor.Response
if taskData.Empty {
rm.responseQueue.TaskDone(key.p, task)
}

return taskData
}

Expand All @@ -226,6 +236,8 @@ func (rm *ResponseManager) finishTask(task *peertask.Task, err error) {
response.state = graphsync.Paused
return
}
log.Infow("graphsync response processing complete (messages stil sending)", "request id", key.requestID, "peer", key.p, "total time", time.Since(response.startTime))

if err != nil {
log.Infof("response failed: %w", err)
}
Expand Down