Skip to content
This repository was archived by the owner on Feb 14, 2025. It is now read-only.

Commit a048086

Browse files
authored
Merge pull request #36 from iotaledger/fix/improve-logging
Improve logging
2 parents bed65f6 + 1c74f0d commit a048086

File tree

5 files changed

+160
-150
lines changed

5 files changed

+160
-150
lines changed

components/validator/issuer.go

+40-30
Original file line numberDiff line numberDiff line change
@@ -23,12 +23,22 @@ const (
2323

2424
func candidateAction(ctx context.Context) {
2525
now := time.Now()
26+
2627
currentAPI := deps.NodeBridge.APIProvider().APIForTime(now)
2728
currentSlot := currentAPI.TimeProvider().SlotFromTime(now)
2829

30+
if !deps.NodeBridge.NodeStatus().GetIsBootstrapped() {
31+
Component.LogDebugf("not issuing candidacy announcement for account %s in slot %d because node is not bootstrapped yet.", validatorAccount.ID(), currentSlot)
32+
33+
// If a node is not bootstrapped, then retry until it is bootstrapped.
34+
executor.ExecuteAt(CandidateTask, func() { candidateAction(ctx) }, now.Add(ParamsValidator.CandidacyRetryInterval))
35+
36+
return
37+
}
38+
2939
isCandidate, err := readIsCandidate(ctx, validatorAccount.ID(), currentSlot)
3040
if err != nil {
31-
Component.LogWarnf("error while checking if account is already a candidate: %s", err.Error())
41+
Component.LogWarnf("error while checking if account %s is already a candidate: %s", validatorAccount.ID(), err.Error())
3242

3343
// If there is an error, then retry registering as a candidate, except if the context was canceled.
3444
if !ierrors.Is(err, context.Canceled) {
@@ -39,7 +49,8 @@ func candidateAction(ctx context.Context) {
3949
}
4050

4151
if isCandidate {
42-
Component.LogDebugf("not issuing candidacy announcement block as account %s is already registered as candidate in epoch %d", validatorAccount.ID(), currentAPI.TimeProvider().EpochFromSlot(currentSlot))
52+
Component.LogDebugf("not issuing candidacy announcement for account %s in slot %d as it is already registered as candidate in epoch %d", validatorAccount.ID(), currentSlot, currentAPI.TimeProvider().EpochFromSlot(currentSlot))
53+
4354
// If an account is a registered candidate, then try to register as a candidate in the next epoch.
4455
executor.ExecuteAt(CandidateTask, func() { candidateAction(ctx) }, currentAPI.TimeProvider().SlotStartTime(currentAPI.TimeProvider().EpochStart(currentAPI.TimeProvider().EpochFromSlot(currentSlot)+1)))
4556

@@ -49,41 +60,47 @@ func candidateAction(ctx context.Context) {
4960
epochEndSlot := currentAPI.TimeProvider().EpochEnd(currentAPI.TimeProvider().EpochFromSlot(currentSlot))
5061
if currentSlot+currentAPI.ProtocolParameters().EpochNearingThreshold() > epochEndSlot {
5162
Component.LogDebugf("not issuing candidacy announcement for account %s as block's slot would be issued in (%d) is past the Epoch Nearing Threshold (%d) of epoch %d", validatorAccount.ID(), currentSlot, epochEndSlot-currentAPI.ProtocolParameters().EpochNearingThreshold(), currentAPI.TimeProvider().EpochFromSlot(currentSlot))
63+
5264
// If it's too late to register as a candidate, then try to register in the next epoch.
5365
executor.ExecuteAt(CandidateTask, func() { candidateAction(ctx) }, currentAPI.TimeProvider().SlotStartTime(currentAPI.TimeProvider().EpochStart(currentAPI.TimeProvider().EpochFromSlot(currentSlot)+1)))
5466

5567
return
5668
}
5769

5870
// Schedule next committeeMemberAction regardless of the result below.
59-
// If a node is not bootstrapped, then retry until it is bootstrapped.
6071
// The candidacy block might be issued and fail to be accepted in the node for various reasons,
6172
// so we should stop issuing candidacy blocks only when the account is successfully registered as a candidate.
6273
// For this reason,
6374
// retry interval parameter should be bigger than the fishing threshold to avoid issuing redundant candidacy blocks.
6475
executor.ExecuteAt(CandidateTask, func() { candidateAction(ctx) }, now.Add(ParamsValidator.CandidacyRetryInterval))
6576

66-
if !deps.NodeBridge.NodeStatus().GetIsBootstrapped() {
67-
Component.LogDebug("not issuing candidate block because node is not bootstrapped yet.")
68-
69-
return
70-
}
71-
7277
if err = issueCandidateBlock(ctx, now, currentAPI); err != nil {
73-
Component.LogWarnf("error while trying to issue candidacy announcement: %s", err.Error())
78+
Component.LogWarnf("error while trying to issue candidacy announcement for account %s in slot %d: %s", validatorAccount.ID(), currentSlot, err.Error())
7479
}
7580
}
7681

7782
func committeeMemberAction(ctx context.Context) {
7883
now := time.Now()
84+
7985
currentAPI := deps.NodeBridge.APIProvider().APIForTime(now)
8086
currentSlot := currentAPI.TimeProvider().SlotFromTime(now)
8187
currentEpoch := currentAPI.TimeProvider().EpochFromSlot(currentSlot)
82-
slotDurationMillis := int64(currentAPI.ProtocolParameters().SlotDurationInSeconds()) * 1000
88+
8389
// Calculate the broadcast interval in milliseconds.
90+
slotDurationMillis := int64(currentAPI.ProtocolParameters().SlotDurationInSeconds()) * 1000
8491
broadcastIntervalMillis := slotDurationMillis / int64(currentAPI.ProtocolParameters().ValidationBlocksPerSlot())
8592
committeeBroadcastInterval := time.Duration(broadcastIntervalMillis * int64(time.Millisecond))
8693

94+
// If we are not bootstrapped and we are _not_ ignoring such condition, we return.
95+
if !deps.NodeBridge.NodeStatus().GetIsBootstrapped() && !ParamsValidator.IgnoreBootstrapped {
96+
Component.LogDebugf("not issuing validation block for account %s because node is not bootstrapped yet.", validatorAccount.ID())
97+
98+
// If a node is not bootstrapped, then retry until it is bootstrapped.
99+
executor.ExecuteAt(CommitteeTask, func() { committeeMemberAction(ctx) }, now.Add(committeeBroadcastInterval))
100+
101+
return
102+
}
103+
87104
// If we are bootstrapped let's check if we are part of the committee.
88105
if deps.NodeBridge.NodeStatus().GetIsBootstrapped() {
89106
isCommitteeMember, err := readIsCommitteeMember(ctx, validatorAccount.ID(), currentSlot)
@@ -99,44 +116,37 @@ func committeeMemberAction(ctx context.Context) {
99116
}
100117

101118
if !isCommitteeMember {
102-
Component.LogDebug("account %s is not a committee member in epoch %d", currentEpoch)
119+
Component.LogDebugf("account %s is not a committee member in epoch %d", validatorAccount.ID(), currentEpoch)
103120
executor.ExecuteAt(CommitteeTask, func() { committeeMemberAction(ctx) }, currentAPI.TimeProvider().SlotStartTime(currentAPI.TimeProvider().EpochStart(currentEpoch+1)))
104121

105122
return
106123
}
107124
}
108125

109-
// Schedule next committeeMemberAction regardless of whether the node is bootstrapped or validation block is issued
126+
// Schedule next committeeMemberAction regardless of whether the validation block is issued or not
110127
// as it must be issued as part of validator's responsibility.
111128
executor.ExecuteAt(CommitteeTask, func() { committeeMemberAction(ctx) }, now.Add(committeeBroadcastInterval))
112129

113-
// If we are not bootstrapped and we are _not_ ignoring such condition, we return.
114-
if !deps.NodeBridge.NodeStatus().GetIsBootstrapped() && !ParamsValidator.IgnoreBootstrapped {
115-
Component.LogDebug("not issuing validation block because node is not bootstrapped yet.")
116-
117-
return
118-
}
119-
120130
// If we are either bootstrapped (and we are part of the committee) or we are ignoring being bootstrapped we issue
121131
// a validation block, reviving the chain if necessary.
122132
if err := issueValidationBlock(ctx, now, currentAPI, committeeBroadcastInterval); err != nil {
123-
Component.LogWarnf("error while trying to issue validation block: %s", err.Error())
133+
Component.LogWarnf("error while trying to issue validation block for account %s: %s", validatorAccount.ID(), err.Error())
124134
}
125135
}
126136

127137
func issueCandidateBlock(ctx context.Context, blockIssuingTime time.Time, currentAPI iotago.API) error {
128-
blockSlot := currentAPI.TimeProvider().SlotFromTime(blockIssuingTime)
129-
130138
issuanceBlockHeaderResponse, err := blockIssuance(ctx, iotago.BasicBlockMaxParents)
131139
if err != nil {
132-
return ierrors.Wrapf(err, "failed to get blockIssuance")
140+
return ierrors.Wrap(err, "failed to get blockIssuance")
133141
}
134142

135143
latestParentBlockIssuingTime := issuanceBlockHeaderResponse.LatestParentBlockIssuingTime.Add(time.Nanosecond)
136144
if blockIssuingTime.Before(latestParentBlockIssuingTime) {
137145
blockIssuingTime = latestParentBlockIssuingTime
138146
}
139147

148+
blockSlot := currentAPI.TimeProvider().SlotFromTime(blockIssuingTime)
149+
140150
addressableCommitment, err := getAddressableCommitment(ctx, blockSlot)
141151
if err != nil {
142152
return ierrors.Wrap(err, "error getting commitment")
@@ -185,12 +195,12 @@ func issueCandidateBlock(ctx context.Context, blockIssuingTime time.Time, curren
185195
func issueValidationBlock(ctx context.Context, blockIssuingTime time.Time, currentAPI iotago.API, committeeBroadcastInterval time.Duration) error {
186196
protocolParametersHash, err := currentAPI.ProtocolParameters().Hash()
187197
if err != nil {
188-
return ierrors.Wrapf(err, "failed to get protocol parameters hash")
198+
return ierrors.Wrap(err, "failed to get protocol parameters hash")
189199
}
190200

191201
issuanceBlockHeaderResponse, err := blockIssuance(ctx, iotago.ValidationBlockMaxParents)
192202
if err != nil {
193-
return ierrors.Wrapf(err, "failed to get blockIssuance")
203+
return ierrors.Wrap(err, "failed to get blockIssuance")
194204
}
195205

196206
latestParentBlockIssuingTime := issuanceBlockHeaderResponse.LatestParentBlockIssuingTime.Add(time.Nanosecond)
@@ -208,15 +218,15 @@ func issueValidationBlock(ctx context.Context, blockIssuingTime time.Time, curre
208218
// to allow the validator to issue validation blocks.
209219
commitment, parentID, reviveChainErr := reviveChain(ctx, blockIssuingTime)
210220
if reviveChainErr != nil {
211-
return ierrors.Wrapf(err, "error reviving chain")
221+
return ierrors.Wrap(err, "error reviving chain")
212222
}
213223

214224
addressableCommitment = commitment
215225
issuanceBlockHeaderResponse.StrongParents = []iotago.BlockID{parentID}
216226
issuanceBlockHeaderResponse.WeakParents = []iotago.BlockID{}
217227
issuanceBlockHeaderResponse.ShallowLikeParents = []iotago.BlockID{}
218228
} else if err != nil {
219-
return ierrors.Wrapf(err, "error getting commitment")
229+
return ierrors.Wrap(err, "error getting commitment")
220230
}
221231

222232
// create the validation block here using the validation block builder from iota.go
@@ -232,12 +242,12 @@ func issueValidationBlock(ctx context.Context, blockIssuingTime time.Time, curre
232242
Sign(validatorAccount.ID(), validatorAccount.PrivateKey()).
233243
Build()
234244
if err != nil {
235-
return ierrors.Wrapf(err, "error creating validation block")
245+
return ierrors.Wrap(err, "error creating validation block")
236246
}
237247

238248
blockID, err := submitBlock(ctx, validationBlock)
239249
if err != nil {
240-
return ierrors.Wrapf(err, "error issuing validation block")
250+
return ierrors.Wrap(err, "error issuing validation block")
241251
}
242252

243253
Component.LogDebugf("issued validation block: %s - commitment %s %d - latest finalized slot %d - broadcast interval %v", blockID, validationBlock.Header.SlotCommitmentID, validationBlock.Header.SlotCommitmentID.Slot(), validationBlock.Header.LatestFinalizedSlot, committeeBroadcastInterval.Truncate(time.Millisecond))

go.mod

+20-20
Original file line numberDiff line numberDiff line change
@@ -3,10 +3,10 @@ module github.com/iotaledger/inx-validator
33
go 1.22
44

55
require (
6-
github.com/iotaledger/hive.go/app v0.0.0-20240425095808-113b21573349
7-
github.com/iotaledger/hive.go/crypto v0.0.0-20240425095808-113b21573349
8-
github.com/iotaledger/hive.go/ierrors v0.0.0-20240425095808-113b21573349
9-
github.com/iotaledger/hive.go/runtime v0.0.0-20240425095808-113b21573349
6+
github.com/iotaledger/hive.go/app v0.0.0-20240517132220-ecd835d54221
7+
github.com/iotaledger/hive.go/crypto v0.0.0-20240517132220-ecd835d54221
8+
github.com/iotaledger/hive.go/ierrors v0.0.0-20240517132220-ecd835d54221
9+
github.com/iotaledger/hive.go/runtime v0.0.0-20240517132220-ecd835d54221
1010
github.com/iotaledger/inx-app v1.0.0-rc.3.0.20240425100742-5c85b6d16701
1111
github.com/iotaledger/iota.go/v4 v4.0.0-20240425100055-540c74851d65
1212
go.uber.org/dig v1.17.1
@@ -20,26 +20,26 @@ require (
2020
github.com/cespare/xxhash/v2 v2.3.0 // indirect
2121
github.com/decred/dcrd/dcrec/secp256k1/v4 v4.3.0 // indirect
2222
github.com/eclipse/paho.mqtt.golang v1.4.3 // indirect
23-
github.com/ethereum/go-ethereum v1.14.0 // indirect
23+
github.com/ethereum/go-ethereum v1.14.3 // indirect
2424
github.com/fatih/structs v1.1.0 // indirect
2525
github.com/felixge/fgprof v0.9.4 // indirect
2626
github.com/fsnotify/fsnotify v1.7.0 // indirect
2727
github.com/google/go-github v17.0.0+incompatible // indirect
2828
github.com/google/go-querystring v1.1.0 // indirect
29-
github.com/google/pprof v0.0.0-20240424215950-a892ee059fd6 // indirect
29+
github.com/google/pprof v0.0.0-20240509144519-723abb6459b7 // indirect
3030
github.com/gorilla/websocket v1.5.1 // indirect
3131
github.com/grpc-ecosystem/go-grpc-middleware v1.4.0 // indirect
3232
github.com/grpc-ecosystem/go-grpc-prometheus v1.2.0 // indirect
3333
github.com/hashicorp/go-version v1.6.0 // indirect
3434
github.com/holiman/uint256 v1.2.4 // indirect
3535
github.com/iancoleman/orderedmap v0.3.0 // indirect
36-
github.com/iotaledger/hive.go/constraints v0.0.0-20240425095808-113b21573349 // indirect
37-
github.com/iotaledger/hive.go/core v1.0.0-rc.3.0.20240425095808-113b21573349 // indirect
38-
github.com/iotaledger/hive.go/ds v0.0.0-20240425095808-113b21573349 // indirect
39-
github.com/iotaledger/hive.go/lo v0.0.0-20240425095808-113b21573349 // indirect
40-
github.com/iotaledger/hive.go/log v0.0.0-20240425095808-113b21573349 // indirect
41-
github.com/iotaledger/hive.go/serializer/v2 v2.0.0-rc.1.0.20240425095808-113b21573349 // indirect
42-
github.com/iotaledger/hive.go/stringify v0.0.0-20240425095808-113b21573349 // indirect
36+
github.com/iotaledger/hive.go/constraints v0.0.0-20240517132220-ecd835d54221 // indirect
37+
github.com/iotaledger/hive.go/core v1.0.0-rc.3.0.20240517132220-ecd835d54221 // indirect
38+
github.com/iotaledger/hive.go/ds v0.0.0-20240517132220-ecd835d54221 // indirect
39+
github.com/iotaledger/hive.go/lo v0.0.0-20240517132220-ecd835d54221 // indirect
40+
github.com/iotaledger/hive.go/log v0.0.0-20240517132220-ecd835d54221 // indirect
41+
github.com/iotaledger/hive.go/serializer/v2 v2.0.0-rc.1.0.20240517132220-ecd835d54221 // indirect
42+
github.com/iotaledger/hive.go/stringify v0.0.0-20240517132220-ecd835d54221 // indirect
4343
github.com/iotaledger/inx/go v1.0.0-rc.2.0.20240425100432-05e1bf8fc089 // indirect
4444
github.com/knadh/koanf v1.5.0 // indirect
4545
github.com/kr/text v0.2.0 // indirect
@@ -48,8 +48,8 @@ require (
4848
github.com/mitchellh/reflectwalk v1.0.2 // indirect
4949
github.com/mr-tron/base58 v1.2.0 // indirect
5050
github.com/pasztorpisti/qs v0.0.0-20171216220353-8d6c33ee906c // indirect
51-
github.com/pelletier/go-toml/v2 v2.2.1 // indirect
52-
github.com/petermattis/goid v0.0.0-20240327183114-c42a807a84ba // indirect
51+
github.com/pelletier/go-toml/v2 v2.2.2 // indirect
52+
github.com/petermattis/goid v0.0.0-20240503122002-4b96552b8156 // indirect
5353
github.com/prometheus/client_golang v1.19.0 // indirect
5454
github.com/prometheus/client_model v0.6.1 // indirect
5555
github.com/prometheus/common v0.53.0 // indirect
@@ -58,14 +58,14 @@ require (
5858
github.com/spf13/cast v1.6.0 // indirect
5959
github.com/spf13/pflag v1.0.5 // indirect
6060
github.com/tcnksm/go-latest v0.0.0-20170313132115-e3007ae9052e // indirect
61-
golang.org/x/crypto v0.22.0 // indirect
62-
golang.org/x/net v0.24.0 // indirect
61+
golang.org/x/crypto v0.23.0 // indirect
62+
golang.org/x/net v0.25.0 // indirect
6363
golang.org/x/sync v0.7.0 // indirect
64-
golang.org/x/sys v0.19.0 // indirect
65-
golang.org/x/text v0.14.0 // indirect
64+
golang.org/x/sys v0.20.0 // indirect
65+
golang.org/x/text v0.15.0 // indirect
6666
google.golang.org/genproto/googleapis/rpc v0.0.0-20240415180920-8c6c420018be // indirect
6767
google.golang.org/grpc v1.63.2 // indirect
68-
google.golang.org/protobuf v1.33.0 // indirect
68+
google.golang.org/protobuf v1.34.1 // indirect
6969
gopkg.in/yaml.v2 v2.4.0 // indirect
7070
gopkg.in/yaml.v3 v3.0.1 // indirect
7171
)

0 commit comments

Comments
 (0)