palomachain / paloma

The fast blockchain messenger protocol
Apache License 2.0
289 stars 133 forks source link

bug: Added logs in x/consensus attest.go and module.go causing panics. #611

Closed taariq closed 1 year ago

taariq commented 1 year ago

What is happening?

Section description Provide as much context as you can. Give as much context as you can to make it easier for the developers to figure what is happening.

Added logs from https://github.com/palomachain/paloma/pull/610 to track attestation failures. Now getting consensus panic.


runtime/debug.Stack()
    /usr/local/go/src/runtime/debug/stack.go:24 +0x65
github.com/tendermint/tendermint/consensus.(*State).receiveRoutine.func2()
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/consensus/state.go:724 +0x4c
panic({0x1b0f160, 0x27605a0})
    /usr/local/go/src/runtime/panic.go:884 +0x212
reflect.valueInterface({0x1b65e80?, 0xc00127d608?, 0x1ae7?}, 0xd8?)
    /usr/local/go/src/reflect/value.go:1489 +0xd8
reflect.Value.Interface(...)
    /usr/local/go/src/reflect/value.go:1478
github.com/gogo/protobuf/proto.(*TextMarshaler).writeAny(0x0?, 0xc000fe87e0, {0x1b65e80?, 0xc00127d608?, 0x279a2b0?}, 0xc0003a2b00)
    /root/go/pkg/mod/github.com/regen-network/protobuf@v1.3.3-alpha.regen.1/proto/text.go:615 +0xa9d
github.com/gogo/protobuf/proto.(*TextMarshaler).writeStruct(0x3603fea, 0xc000fe87e0, {0x1d2b400?, 0xc00127d5c0?, 0x1?})
    /root/go/pkg/mod/github.com/regen-network/protobuf@v1.3.3-alpha.regen.1/proto/text.go:453 +0x8df
github.com/gogo/protobuf/proto.(*TextMarshaler).writeAny(0x1b105a3?, 0xc000fe87e0, {0x1dcc940?, 0xc0014d0028?, 0x279a2b0?}, 0xc0014bba00)
    /root/go/pkg/mod/github.com/regen-network/protobuf@v1.3.3-alpha.regen.1/proto/text.go:606 +0x935
github.com/gogo/protobuf/proto.(*TextMarshaler).writeStruct(0x3603fea, 0xc000fe87e0, {0x1d5a360?, 0xc0014d0000?, 0x20?})
    /root/go/pkg/mod/github.com/regen-network/protobuf@v1.3.3-alpha.regen.1/proto/text.go:453 +0x8df
github.com/gogo/protobuf/proto.(*TextMarshaler).Marshal(0x3603fea, {0x27618e0?, 0xc00386d200?}, {0x2778170?, 0xc0014d0000?})
    /root/go/pkg/mod/github.com/regen-network/protobuf@v1.3.3-alpha.regen.1/proto/text.go:896 +0x367
github.com/gogo/protobuf/proto.(*TextMarshaler).Text(0x0?, {0x2778170, 0xc0014d0000})
    /root/go/pkg/mod/github.com/regen-network/protobuf@v1.3.3-alpha.regen.1/proto/text.go:908 +0x56
github.com/gogo/protobuf/proto.CompactTextString(...)
    /root/go/pkg/mod/github.com/regen-network/protobuf@v1.3.3-alpha.regen.1/proto/text.go:930
github.com/palomachain/paloma/x/consensus/types.(*QueuedSignedMessage).String(0x278d0c0?)
    /root/paloma/x/consensus/types/consensus_queue.pb.go:46 +0x2a
github.com/palomachain/paloma/x/consensus/keeper.Keeper.CheckAndProcessAttestedMessages({{0x278d0c0, 0xc0010fcea0}, {0x2768a80, 0xc000e2ca70}, {0x2768a80, 0x0}, {{0x278d0c0, 0xc0010fcea0}, 0xc000125570, {0x2768a80, ...}, ...}, ...}, ...)
    /root/paloma/x/consensus/keeper/attest.go:23 +0x34e
github.com/palomachain/paloma/x/consensus.AppModule.EndBlock({{{0x278d0c0, 0xc0010fcea0}}, {{0x278d0c0, 0xc0010fcea0}, {0x2768a80, 0xc000e2ca70}, {0x2768a80, 0x0}, {{0x278d0c0, 0xc0010fcea0}, ...}, ...}, ...}, ...)
    /root/paloma/x/consensus/module.go:175 +0x198
github.com/cosmos/cosmos-sdk/types/module.(*Manager).EndBlock(_, {{0x277e2c8, 0xc000056030}, {0x278ee00, 0xc004ca3080}, {{0xb, 0x0}, {0xc0049dd370, 0xf}, 0x12d, ...}, ...}, ...)
    /root/go/pkg/mod/github.com/cosmos/cosmos-sdk@v0.45.11/types/module/module.go:512 +0x4c2
github.com/palomachain/paloma/app.(*App).EndBlocker(_, {{0x277e2c8, 0xc000056030}, {0x278ee00, 0xc004ca3080}, {{0xb, 0x0}, {0xc0049dd370, 0xf}, 0x12d, ...}, ...}, ...)
    /root/paloma/app/app.go:744 +0x98
github.com/cosmos/cosmos-sdk/baseapp.(*BaseApp).EndBlock(0xc000c8fa40, {0x20?})
    /root/go/pkg/mod/github.com/cosmos/cosmos-sdk@v0.45.11/baseapp/abci.go:202 +0x1fe
github.com/tendermint/tendermint/abci/client.(*localClient).EndBlockSync(0xc000e6a060, {0xc000e6a060?})
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/abci/client/local_client.go:288 +0xdf
github.com/tendermint/tendermint/proxy.(*appConnConsensus).EndBlockSync(0xc0031eb040?, {0x20?})
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/proxy/app_conn.go:89 +0x24
github.com/tendermint/tendermint/state.execBlockOnProxyApp({0x277f2f8?, 0xc000e6a2a0}, {0x2786dd0, 0xc0011b40b0}, 0xc00149a1e0, {0x278e2f0, 0xc00112ca08}, 0x12c?)
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/state/execution.go:327 +0x55f
github.com/tendermint/tendermint/state.(*BlockExecutor).ApplyBlock(_, {{{0xb, 0x0}, {0xc0004c4bb0, 0x8}}, {0xc0004c4be0, 0xf}, 0x1, 0x12c, {{0xc00496d8c0, ...}, ...}, ...}, ...)
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/state/execution.go:140 +0x171
github.com/tendermint/tendermint/consensus.(*State).finalizeCommit(0xc001256700, 0x12d)
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/consensus/state.go:1654 +0xafd
github.com/tendermint/tendermint/consensus.(*State).tryFinalizeCommit(0xc001256700, 0x12d)
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/consensus/state.go:1563 +0x2ff
github.com/tendermint/tendermint/consensus.(*State).enterCommit.func1()
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/consensus/state.go:1498 +0x94
github.com/tendermint/tendermint/consensus.(*State).enterCommit(0xc001256700, 0x12d, 0x0)
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/consensus/state.go:1536 +0xccf
github.com/tendermint/tendermint/consensus.(*State).addVote(0xc001256700, 0xc00528eb40, {0x0, 0x0})
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/consensus/state.go:2150 +0x18dc
github.com/tendermint/tendermint/consensus.(*State).tryAddVote(0xc001256700, 0xc00528eb40, {0x0?, 0x4c1166?})
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/consensus/state.go:1948 +0x2c
github.com/tendermint/tendermint/consensus.(*State).handleMsg(0xc001256700, {{0x27630e0?, 0xc004269c00?}, {0x0?, 0x0?}})
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/consensus/state.go:853 +0x170
github.com/tendermint/tendermint/consensus.(*State).receiveRoutine(0xc001256700, 0x0)
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/consensus/state.go:780 +0x505
created by github.com/tendermint/tendermint/consensus.(*State).OnStart
    /root/go/pkg/mod/github.com/tendermint/tendermint@v0.34.23/consensus/state.go:379 +0x12d```

# Paloma and pigeon versions and logs
<details>
  <summary>Section description</summary>
<i>Write down paloma version.</i>
<i>Write down pigeon version.</i>
<i>Copy and paste pigeon config file as well as relevant ENV variables.</i>
</details>

Master on all versions

# How to reproduce?
<details>
  <summary>Section description</summary>
  <i>Please write detailed steps of what you were doing for this bug to appear.</i>
</details>

# What is the expected behaviour?
<details>
  <summary>Section description</summary>
<i>If you know, please write down what is the expected behaviour. If you don't know, that's ok. We can have a discussion in comments.</i>
</details>

Consenus not impacted by adding new logs.
taariq commented 1 year ago

@webelf101 please revert the added logs so we can explore a new approach next week.

taariq commented 1 year ago

@alexanderbez re-opening for your reiew.

alexanderbez commented 1 year ago

Ok, seems like the panic is triggered from the log line added in x/consensus/keeper/attest.go.

@taariq do you have the entire stacktrace? Is it a nil deference error? I can't tell what's going on from the given stacktrace. However, I'm pretty confident it's due to msg.String() -- something funky is going on with that.

Instead, consider the following git diff change:

diff --git a/x/consensus/keeper/attest.go b/x/consensus/keeper/attest.go
index 7d27ad0..c386b03 100644
--- a/x/consensus/keeper/attest.go
+++ b/x/consensus/keeper/attest.go
@@ -1,6 +1,8 @@
 package keeper

 import (
+       "fmt"
+
        sdk "github.com/cosmos/cosmos-sdk/types"
 )

@@ -20,11 +22,18 @@ func (k Keeper) CheckAndProcessAttestedMessages(ctx sdk.Context) error {
                        }

                        for _, msg := range msgs {
-                               k.Logger(ctx).Info("check-and-process-attested-messages-queue", "id", msg.GetId(), "nonce", msg.Nonce(), "string", msg.String())
+                               k.Logger(ctx).Info(
+                                       "check-and-process-attested-messages-queue",
+                                       "id", msg.GetId(),
+                                       "nonce", msg.Nonce(),
+                                       "string", fmt.Sprintf("+%v", msg),
+                               )
+
                                cq, err := k.getConsensusQueue(ctx, opt.QueueTypeName)
                                if err != nil {
                                        return err
                                }
+
                                if err := opt.ProcessMessageForAttestation(ctx, cq, msg); err != nil {
                                        return err
                                }
taariq commented 1 year ago

Fixed with #613