Structure logs

License: MIT
Signed-off-by: Jakub Sztandera <kubuxu@protocol.ai>
This commit is contained in:
Jakub Sztandera 2019-10-11 01:41:48 +02:00
parent 530dc64e82
commit 49e3fe39f8
No known key found for this signature in database
GPG Key ID: 9A9AF56F8B3879BA
5 changed files with 34 additions and 10 deletions

View File

@ -44,7 +44,7 @@ func HandleIncomingBlocks(ctx context.Context, bsub *pubsub.Subscription, s *cha
return
}
log.Infof("inform new block over pubsub: %s from %s", blk.Header.Cid(), msg.GetFrom())
log.Infow("new block over pubsub", "cid", blk.Header.Cid(), "source", msg.GetFrom())
s.InformNewBlock(msg.GetFrom(), &types.FullBlock{
Header: blk.Header,
BlsMessages: bmsgs,

View File

@ -852,6 +852,7 @@ func (syncer *Syncer) collectChain(ctx context.Context, ts *types.TipSet) error
}
syncer.syncState.SetStage(api.StageSyncComplete)
log.Infow("new tipset", "height", ts.Height(), "tipset", types.LogCids(ts.Cids()))
return nil
}

17
chain/types/logs.go Normal file
View File

@ -0,0 +1,17 @@
package types
import (
"github.com/ipfs/go-cid"
"go.uber.org/zap/zapcore"
)
type LogCids []cid.Cid
var _ zapcore.ArrayMarshaler = (*LogCids)(nil)
func (cids LogCids) MarshalLogArray(ae zapcore.ArrayEncoder) error {
for _, c := range cids {
ae.AppendString(c.String())
}
return nil
}

View File

@ -219,7 +219,7 @@ func (m *Miner) GetBestMiningCandidate() (*MiningBase, error) {
}
func (m *Miner) mineOne(ctx context.Context, base *MiningBase) (*types.BlockMsg, error) {
log.Info("attempting to mine a block on:", base.ts.Cids())
log.Infow("attempting to mine a block", "tipset", types.LogCids(base.ts.Cids()))
ticket, err := m.scratchTicket(ctx, base)
if err != nil {
return nil, errors.Wrap(err, "scratching ticket failed")
@ -239,7 +239,7 @@ func (m *Miner) mineOne(ctx context.Context, base *MiningBase) (*types.BlockMsg,
if err != nil {
return nil, errors.Wrap(err, "failed to create block")
}
log.Infof("mined new block: %s", b.Cid())
log.Infow("mined new block", "cid", b.Cid())
return b, nil
}

View File

@ -2,7 +2,7 @@ package storage
import (
"context"
"encoding/base64"
"time"
"golang.org/x/xerrors"
@ -67,14 +67,14 @@ func (m *Miner) scheduleNextPost(ppe uint64) {
headPPE, provingPeriod := actors.ProvingPeriodEnd(ppe, ts.Height())
if headPPE > ppe {
log.Warn("PoSt computation running behind chain")
log.Warnw("PoSt computation running behind chain", "headPPE", headPPE, "ppe", ppe)
ppe = headPPE
}
m.schedLk.Lock()
if m.schedPost >= ppe {
// this probably can't happen
log.Error("PoSt already scheduled: %d >= %d", m.schedPost, ppe)
log.Errorw("PoSt already scheduled", "schedPost", m.schedPost, "ppe", ppe)
m.schedLk.Unlock()
return
}
@ -82,7 +82,8 @@ func (m *Miner) scheduleNextPost(ppe uint64) {
m.schedPost = ppe
m.schedLk.Unlock()
log.Infof("Scheduling post at height %d (head=%d; ppe=%d, period=%d)", ppe-build.PoSTChallangeTime, ts.Height(), ppe, provingPeriod)
log.Infow("scheduling PoSt", "post-height", ppe-build.PoSTChallangeTime,
"height", ts.Height(), "ppe", ppe, "proving-period", provingPeriod)
err = m.events.ChainAt(m.computePost(ppe), func(ts *types.TipSet) error { // Revert
// TODO: Cancel post
log.Errorf("TODO: Cancel PoSt, re-run")
@ -90,7 +91,7 @@ func (m *Miner) scheduleNextPost(ppe uint64) {
}, PoStConfidence, ppe-build.PoSTChallangeTime)
if err != nil {
// TODO: This is BAD, figure something out
log.Errorf("scheduling PoSt failed: %s", err)
log.Errorf("scheduling PoSt failed: %+v", err)
return
}
}
@ -110,14 +111,19 @@ func (m *Miner) computePost(ppe uint64) func(ts *types.TipSet, curH uint64) erro
return xerrors.Errorf("failed to get chain randomness for post (ts=%d; ppe=%d): %w", ts.Height(), ppe, err)
}
log.Infof("running PoSt computation, rh=%d r=%s, ppe=%d, h=%d", int64(ts.Height())-int64(ppe)+int64(build.PoSTChallangeTime), base64.StdEncoding.EncodeToString(r), ppe, ts.Height())
log.Infow("running PoSt", "delayed-by",
int64(ts.Height())-(int64(ppe)-int64(build.PoSTChallangeTime)),
"chain-random", r, "ppe", ppe, "height", ts.Height())
tsStart := time.Now()
var faults []uint64
proof, err := m.secst.RunPoSt(ctx, sset, r, faults)
if err != nil {
return xerrors.Errorf("running post failed: %w", err)
}
elapsed := time.Since(tsStart)
log.Infof("submitting PoSt pLen=%d", len(proof))
log.Infow("submitting PoSt", "pLen", len(proof), "elapsed", elapsed)
params := &actors.SubmitPoStParams{
Proof: proof,