PoST: pass logger through to post-rs (#4394)

## Motivation
This integrates the new logging in `post` (spacemeshos/post#137) into `go-spacemesh`.

## Changes
The logger needs to be passed thorough to some components of `post`.

Do not merge before
- [x] spacemeshos/post-rs#47
- [x] spacemeshos/post#137
- [x] #4390

are merged and released

## Test Plan
Existing tests pass.

## TODO
<!-- This section should be removed when all items are complete -->
- [x] Explain motivation or link existing issue(s)
- [x] Test changes and document test plan
- [x] Update documentation as needed

## DevOps Notes
<!-- Please uncheck these items as applicable to make DevOps aware of changes that may affect releases -->
- [x] This PR does not require configuration changes (e.g., environment variables, GitHub secrets, VM resources)
- [x] This PR does not affect public APIs
- [x] This PR does not rely on a new version of external services (PoET, elasticsearch, etc.)
- [x] This PR does not make changes to log messages (which monitoring infrastructure may rely on)


Co-authored-by: Bartosz Różański <[email protected]>

Makefile-libs.Inc

@@ -49,7 +49,7 @@ else
 	endif
 endif
 
-POSTRS_SETUP_REV = 0.1.11
+POSTRS_SETUP_REV = 0.1.12
 POSTRS_SETUP_ZIP = libpost-$(platform)-v$(POSTRS_SETUP_REV).zip
 POSTRS_SETUP_URL_ZIP ?= https://github.com/spacemeshos/post-rs/releases/download/v$(POSTRS_SETUP_REV)/$(POSTRS_SETUP_ZIP)
 ifeq ($(platform), windows)

activation/nipost_test.go

@@ -121,13 +121,12 @@ func TestNIPostBuilderWithClients(t *testing.T) {
 
 	postCfg := DefaultPostConfig()
 	nipost := buildNIPost(t, postProvider, postCfg, challenge, poetDb)
-	err := validateNIPost(
+	v := NewValidator(poetDb, postCfg, logtest.New(t).WithName("validator"))
+	_, err := v.NIPost(
 		postProvider.id,
 		postProvider.commitmentAtxId,
 		nipost,
 		challengeHash,
-		poetDb,
-		postCfg,
 		postProvider.opts.NumUnits,
 		verifying.WithLabelScryptParams(postProvider.opts.Scrypt),
 	)
@@ -215,16 +214,16 @@ func TestNewNIPostBuilderNotInitialized(t *testing.T) {
 	r.NoError(err)
 	r.NotNil(nipost)
 
-	r.NoError(validateNIPost(
+	v := NewValidator(poetDb, postProvider.cfg, logtest.New(t).WithName("validator"))
+	_, err = v.NIPost(
 		postProvider.id,
 		postProvider.goldenATXID,
 		nipost,
 		challenge.Hash(),
-		poetDb,
-		postProvider.cfg,
 		postProvider.opts.NumUnits,
 		verifying.WithLabelScryptParams(postProvider.opts.Scrypt),
-	))
+	)
+	r.NoError(err)
 }
 
 func TestNIPostBuilder_BuildNIPost(t *testing.T) {

activation/post.go

@@ -284,7 +284,7 @@ func (mgr *PostSetupManager) PrepareInitializer(ctx context.Context, opts PostSe
 		initialization.WithCommitmentAtxId(mgr.commitmentAtxId.Bytes()),
 		initialization.WithConfig(config.Config(mgr.cfg)),
 		initialization.WithInitOpts(config.InitOpts(opts)),
-		initialization.WithLogger(mgr.logger),
+		initialization.WithLogger(mgr.logger.Zap()),
 	)
 	if err != nil {
 		mgr.state = PostSetupStateError
@@ -370,7 +370,7 @@ func (mgr *PostSetupManager) GenerateProof(ctx context.Context, challenge []byte
 	}
 	mgr.mu.Unlock()
 
-	proof, proofMetadata, err := proving.Generate(ctx, challenge, config.Config(mgr.cfg), mgr.logger,
+	proof, proofMetadata, err := proving.Generate(ctx, challenge, config.Config(mgr.cfg), mgr.logger.Zap(),
 		proving.WithDataSource(config.Config(mgr.cfg), mgr.id.Bytes(), mgr.commitmentAtxId.Bytes(), mgr.lastOpts.DataDir),
 		proving.WithNonces(mgr.provingOpts.Nonces),
 		proving.WithThreads(mgr.provingOpts.Threads),

activation/post_test.go

@@ -208,6 +208,7 @@ func TestPostSetupManager_GenerateProof(t *testing.T) {
 		LabelsPerUnit:   m.LabelsPerUnit,
 	},
 		config.DefaultConfig(),
+		logtest.New(t).WithName("verifying").Zap(),
 		verifying.WithLabelScryptParams(mgr.opts.Scrypt),
 	)
 	req.NoError(err)

activation/validation.go

@@ -15,6 +15,7 @@ import (
 	"github.com/spacemeshos/go-spacemesh/activation/metrics"
 	"github.com/spacemeshos/go-spacemesh/common/types"
 	"github.com/spacemeshos/go-spacemesh/common/util"
+	"github.com/spacemeshos/go-spacemesh/log"
 )
 
 type ErrAtxNotFound struct {
@@ -40,11 +41,12 @@ func (e *ErrAtxNotFound) Is(target error) bool {
 type Validator struct {
 	poetDb poetDbAPI
 	cfg    PostConfig
+	log    log.Log
 }
 
 // NewValidator returns a new NIPost validator.
-func NewValidator(poetDb poetDbAPI, cfg PostConfig) *Validator {
-	return &Validator{poetDb, cfg}
+func NewValidator(poetDb poetDbAPI, cfg PostConfig, log log.Log) *Validator {
+	return &Validator{poetDb, cfg, log}
 }
 
 // NIPost validates a NIPost, given a node id and expected challenge. It returns an error if the NIPost is invalid.
@@ -123,7 +125,7 @@ func (v *Validator) Post(nodeId types.NodeID, commitmentAtxId types.ATXID, PoST
 	}
 
 	start := time.Now()
-	if err := verifying.Verify(p, m, (config.Config)(v.cfg), opts...); err != nil {
+	if err := verifying.Verify(p, m, (config.Config)(v.cfg), v.log.Zap(), opts...); err != nil {
 		return fmt.Errorf("verify PoST: %w", err)
 	}
 	metrics.PostVerificationLatency.Observe(time.Since(start).Seconds())

activation/validation_test.go

@@ -13,6 +13,7 @@ import (
 	"github.com/stretchr/testify/require"
 
 	"github.com/spacemeshos/go-spacemesh/common/types"
+	"github.com/spacemeshos/go-spacemesh/log/logtest"
 )
 
 func Test_Validation_VRFNonce(t *testing.T) {
@@ -46,7 +47,7 @@ func Test_Validation_VRFNonce(t *testing.T) {
 
 	nonce := (*types.VRFPostIndex)(init.Nonce())
 
-	v := NewValidator(poetDbAPI, postCfg)
+	v := NewValidator(poetDbAPI, postCfg, logtest.New(t).WithName("validator"))
 
 	// Act & Assert
 	t.Run("valid vrf nonce", func(t *testing.T) {
@@ -87,7 +88,7 @@ func Test_Validation_InitialNIPostChallenge(t *testing.T) {
 	postCfg := DefaultPostConfig()
 	goldenATXID := types.ATXID{2, 3, 4}
 
-	v := NewValidator(poetDbAPI, postCfg)
+	v := NewValidator(poetDbAPI, postCfg, logtest.New(t).WithName("validator"))
 
 	// Act & Assert
 	t.Run("valid initial nipost challenge passes", func(t *testing.T) {
@@ -220,7 +221,7 @@ func Test_Validation_NIPostChallenge(t *testing.T) {
 	poetDbAPI := NewMockpoetDbAPI(ctrl)
 	postCfg := DefaultPostConfig()
 
-	v := NewValidator(poetDbAPI, postCfg)
+	v := NewValidator(poetDbAPI, postCfg, logtest.New(t).WithName("validator"))
 
 	// Act & Assert
 	t.Run("valid nipost challenge passes", func(t *testing.T) {
@@ -393,7 +394,7 @@ func Test_Validation_PositioningAtx(t *testing.T) {
 	poetDbAPI := NewMockpoetDbAPI(ctrl)
 	postCfg := DefaultPostConfig()
 
-	v := NewValidator(poetDbAPI, postCfg)
+	v := NewValidator(poetDbAPI, postCfg, logtest.New(t).WithName("validator"))
 
 	// Act & Assert
 	t.Run("valid nipost challenge passes", func(t *testing.T) {
@@ -508,7 +509,7 @@ func Test_Validate_NumUnits(t *testing.T) {
 	poetDbAPI := NewMockpoetDbAPI(ctrl)
 	postCfg := DefaultPostConfig()
 
-	v := NewValidator(poetDbAPI, postCfg)
+	v := NewValidator(poetDbAPI, postCfg, logtest.New(t).WithName("validator"))
 
 	// Act & Assert
 	t.Run("valid number of num units passes", func(t *testing.T) {
@@ -542,7 +543,7 @@ func Test_Validate_PostMetadata(t *testing.T) {
 	poetDbAPI := NewMockpoetDbAPI(ctrl)
 	postCfg := DefaultPostConfig()
 
-	v := NewValidator(poetDbAPI, postCfg)
+	v := NewValidator(poetDbAPI, postCfg, logtest.New(t).WithName("validator"))
 
 	// Act & Assert
 	t.Run("valid post metadata", func(t *testing.T) {
@@ -584,39 +585,37 @@ func TestValidator_Validate(t *testing.T) {
 	nipost := buildNIPost(t, postProvider, postProvider.cfg, challenge, poetDb)
 
 	opts := []verifying.OptionFunc{verifying.WithLabelScryptParams(postProvider.opts.Scrypt)}
-	err := validateNIPost(postProvider.id, postProvider.commitmentAtxId, nipost, challengeHash, poetDb, postProvider.cfg, postProvider.opts.NumUnits, opts...)
+	v := NewValidator(poetDb, postProvider.cfg, logtest.New(t).WithName("validator"))
+	_, err := v.NIPost(postProvider.id, postProvider.commitmentAtxId, nipost, challengeHash, postProvider.opts.NumUnits, opts...)
 	r.NoError(err)
 
-	err = validateNIPost(postProvider.id, postProvider.commitmentAtxId, nipost, types.BytesToHash([]byte("lerner")), poetDb, postProvider.cfg, postProvider.opts.NumUnits, opts...)
+	_, err = v.NIPost(postProvider.id, postProvider.commitmentAtxId, nipost, types.BytesToHash([]byte("lerner")), postProvider.opts.NumUnits, opts...)
 	r.Contains(err.Error(), "invalid membership proof")
 
 	newNIPost := *nipost
 	newNIPost.Post = &types.Post{}
-	err = validateNIPost(postProvider.id, postProvider.commitmentAtxId, &newNIPost, challengeHash, poetDb, postProvider.cfg, postProvider.opts.NumUnits, opts...)
+	_, err = v.NIPost(postProvider.id, postProvider.commitmentAtxId, &newNIPost, challengeHash, postProvider.opts.NumUnits, opts...)
 	r.Contains(err.Error(), "invalid Post")
 
 	newPostCfg := postProvider.cfg
 	newPostCfg.MinNumUnits = postProvider.opts.NumUnits + 1
-	err = validateNIPost(postProvider.id, postProvider.commitmentAtxId, nipost, challengeHash, poetDb, newPostCfg, postProvider.opts.NumUnits, opts...)
+	v = NewValidator(poetDb, newPostCfg, logtest.New(t).WithName("validator"))
+	_, err = v.NIPost(postProvider.id, postProvider.commitmentAtxId, nipost, challengeHash, postProvider.opts.NumUnits, opts...)
 	r.EqualError(err, fmt.Sprintf("invalid `numUnits`; expected: >=%d, given: %d", newPostCfg.MinNumUnits, postProvider.opts.NumUnits))
 
 	newPostCfg = postProvider.cfg
 	newPostCfg.MaxNumUnits = postProvider.opts.NumUnits - 1
-	err = validateNIPost(postProvider.id, postProvider.commitmentAtxId, nipost, challengeHash, poetDb, newPostCfg, postProvider.opts.NumUnits, opts...)
+	v = NewValidator(poetDb, newPostCfg, logtest.New(t).WithName("validator"))
+	_, err = v.NIPost(postProvider.id, postProvider.commitmentAtxId, nipost, challengeHash, postProvider.opts.NumUnits, opts...)
 	r.EqualError(err, fmt.Sprintf("invalid `numUnits`; expected: <=%d, given: %d", newPostCfg.MaxNumUnits, postProvider.opts.NumUnits))
 
 	newPostCfg = postProvider.cfg
 	newPostCfg.LabelsPerUnit = nipost.PostMetadata.LabelsPerUnit + 1
-	err = validateNIPost(postProvider.id, postProvider.commitmentAtxId, nipost, challengeHash, poetDb, newPostCfg, postProvider.opts.NumUnits, opts...)
+	v = NewValidator(poetDb, newPostCfg, logtest.New(t).WithName("validator"))
+	_, err = v.NIPost(postProvider.id, postProvider.commitmentAtxId, nipost, challengeHash, postProvider.opts.NumUnits, opts...)
 	r.EqualError(err, fmt.Sprintf("invalid `LabelsPerUnit`; expected: >=%d, given: %d", newPostCfg.LabelsPerUnit, nipost.PostMetadata.LabelsPerUnit))
 }
 
-func validateNIPost(minerID types.NodeID, commitmentAtx types.ATXID, nipost *types.NIPost, challenge types.Hash32, poetDb poetDbAPI, postCfg PostConfig, numUnits uint32, opts ...verifying.OptionFunc) error {
-	v := &Validator{poetDb, postCfg}
-	_, err := v.NIPost(minerID, commitmentAtx, nipost, challenge, numUnits, opts...)
-	return err
-}
-
 func TestValidateMerkleProof(t *testing.T) {
 	challenge := types.CalcHash32([]byte("challenge"))
 

cmd/node/node.go

@@ -93,6 +93,7 @@ const (
 	ProposalBuilderLogger  = "proposalBuilder"
 	ProposalListenerLogger = "proposalListener"
 	NipostBuilderLogger    = "nipostBuilder"
+	NipostValidatorLogger  = "nipostValidator"
 	Fetcher                = "fetcher"
 	TimeSyncLogger         = "timesync"
 	VMLogger               = "vm"
@@ -470,7 +471,7 @@ func (app *App) initServices(
 	lg := app.log.Named(nodeID.ShortString()).WithFields(nodeID)
 
 	poetDb := activation.NewPoetDb(app.db, app.addLogger(PoetDbLogger, lg))
-	validator := activation.NewValidator(poetDb, app.Config.POST)
+	validator := activation.NewValidator(poetDb, app.Config.POST, app.addLogger(NipostValidatorLogger, lg))
 	app.validator = validator
 
 	cfg := vm.DefaultConfig()

go.mod

@@ -39,7 +39,7 @@ require (
 	github.com/spacemeshos/go-scale v1.1.9
 	github.com/spacemeshos/merkle-tree v0.2.1
 	github.com/spacemeshos/poet v0.8.4
-	github.com/spacemeshos/post v0.6.2
+	github.com/spacemeshos/post v0.6.3
 	github.com/spf13/afero v1.9.5
 	github.com/spf13/cobra v1.7.0
 	github.com/spf13/pflag v1.0.5

go.sum

@@ -603,8 +603,8 @@ github.com/spacemeshos/merkle-tree v0.2.1 h1:BSs/zt1n3ceZcpWdcqNFRvTeAWDlc0W+bql
 github.com/spacemeshos/merkle-tree v0.2.1/go.mod h1:IsrdlW6AHZ4HSi89H7G94ravFCMFZLGnm6To0tQ0SPY=
 github.com/spacemeshos/poet v0.8.4 h1:SH4s0tUacSRE0Pfo/MrF6ds4i3a40Y69Lcm6Ar++YlE=
 github.com/spacemeshos/poet v0.8.4/go.mod h1:tw/WGXBejkTJ1DljanwkzrR0h+dgUlrzasm650LEd0Q=
-github.com/spacemeshos/post v0.6.2 h1:NpdjiBFPtlj1AZPAI3TLr+TLj5fElDlq9GfJE18FAY0=
-github.com/spacemeshos/post v0.6.2/go.mod h1:kFkOxkJP2kgGY19MEaejvpHFMn8XnDsfDe9L7/awoXw=
+github.com/spacemeshos/post v0.6.3 h1:fpb7GzEU2O1K9VBmZYHfbJI/5L9+V9BOqGzlO95UP7U=
+github.com/spacemeshos/post v0.6.3/go.mod h1:MxEMzoCuKfAByJcFlYhgLuGgbGrnEwI0V4jkGZj5C8g=
 github.com/spacemeshos/sha256-simd v0.1.0 h1:G7Mfu5RYdQiuE+wu4ZyJ7I0TI74uqLhFnKblEnSpjYI=
 github.com/spacemeshos/sha256-simd v0.1.0/go.mod h1:O8CClVIilId7RtuCMV2+YzMj6qjVn75JsxOxaE8vcfM=
 github.com/spaolacci/murmur3 v1.1.0 h1:7c1g84S4BPRrfL5Xrdp6fOJ206sU9y293DDHaoy0bLI=