Events are getting lost from query response

[ghost]

Summary of Bug

When querying for a tx with indexing turned on for all events, the grpc/cli query returns a subset of events that are actually on the tx. When querying from tendermint, all events are returned as should be the case.

For example:
From GRPC -> http://34.82.40.187:1317/cosmos/tx/v1beta1/txs/1CA6357119C42A9743C7BA0F6AE520F7E78D49E7950AA51239206A44522FEE6E
Response ->

...
"tx_response": {
    "height": "3678130",
    "txhash": "1CA6357119C42A9743C7BA0F6AE520F7E78D49E7950AA51239206A44522FEE6E",
    "codespace": "",
    "code": 0,
    "data": "0A2B0A292F70726F76656E616E63652E6D61726B65722E76312E4D736741646441636365737352657175657374",
    "raw_log": "[{\"events\":[{\"type\":\"message\",\"attributes\":[{\"key\":\"action\",\"value\":\"/provenance.marker.v1.MsgAddAccessRequest\"},{\"key\":\"module\",\"value\":\"marker\"}]},{\"type\":\"provenance.marker.v1.EventMarkerAddAccess\",\"attributes\":[{\"key\":\"access\",\"value\":\"{\\\"address\\\":\\\"tp1002q25jgdtlxh8vdhrlnavc8y7xcj9fygkw3e0\\\",\\\"permissions\\\":[\\\"ACCESS_MINT\\\",\\\"ACCESS_WITHDRAW\\\"]}\"},{\"key\":\"denom\",\"value\":\"\\\"fmtp13gm7m78ullfxxa6lsek2ltz9eljfax7950fhdu\\\"\"},{\"key\":\"administrator\",\"value\":\"\\\"tp13gm7m78ullfxxa6lsek2ltz9eljfax7950fhdu\\\"\"}]}]}]",
    "logs": [
      {
        "msg_index": 0,
        "log": "",
        "events": [
          {
            "type": "message",
            "attributes": [
              {
                "key": "action",
                "value": "/provenance.marker.v1.MsgAddAccessRequest"
              },
              {
                "key": "module",
                "value": "marker"
              }
            ]
          },
          {
            "type": "provenance.marker.v1.EventMarkerAddAccess",
            "attributes": [
              {
                "key": "access",
                "value": "{\"address\":\"tp1002q25jgdtlxh8vdhrlnavc8y7xcj9fygkw3e0\",\"permissions\":[\"ACCESS_MINT\",\"ACCESS_WITHDRAW\"]}"
              },
              {
                "key": "denom",
                "value": "\"fmtp13gm7m78ullfxxa6lsek2ltz9eljfax7950fhdu\""
              },
              {
                "key": "administrator",
                "value": "\"tp13gm7m78ullfxxa6lsek2ltz9eljfax7950fhdu\""
              }
            ]
          }
        ]
      }
    ],
...

From Tendermint -> http://34.82.40.187:26657/tx?hash=0x1CA6357119C42A9743C7BA0F6AE520F7E78D49E7950AA51239206A44522FEE6E
Response ->

...
"tx_result": {
      "code": 0,
      "data": "CisKKS9wcm92ZW5hbmNlLm1hcmtlci52MS5Nc2dBZGRBY2Nlc3NSZXF1ZXN0",
      "log": "[{\"events\":[{\"type\":\"message\",\"attributes\":[{\"key\":\"action\",\"value\":\"/provenance.marker.v1.MsgAddAccessRequest\"},{\"key\":\"module\",\"value\":\"marker\"}]},{\"type\":\"provenance.marker.v1.EventMarkerAddAccess\",\"attributes\":[{\"key\":\"access\",\"value\":\"{\\\"address\\\":\\\"tp1002q25jgdtlxh8vdhrlnavc8y7xcj9fygkw3e0\\\",\\\"permissions\\\":[\\\"ACCESS_MINT\\\",\\\"ACCESS_WITHDRAW\\\"]}\"},{\"key\":\"denom\",\"value\":\"\\\"fmtp13gm7m78ullfxxa6lsek2ltz9eljfax7950fhdu\\\"\"},{\"key\":\"administrator\",\"value\":\"\\\"tp13gm7m78ullfxxa6lsek2ltz9eljfax7950fhdu\\\"\"}]}]}]",
      "info": "",
      "gas_wanted": "333700",
      "gas_used": "217597",
      "events": [
        {
          "type": "coin_spent",
          "attributes": [
            {
              "key": "c3BlbmRlcg==",
              "value": "dHAxM2dtN203OHVsbGZ4eGE2bHNlazJsdHo5ZWxqZmF4Nzk1MGZoZHU=",
              "index": false
            },
            {
              "key": "YW1vdW50",
              "value": "NjM1Njk4NTAwbmhhc2g=",
              "index": false
            }
          ]
        },
        {
          "type": "coin_received",
          "attributes": [
            {
              "key": "cmVjZWl2ZXI=",
              "value": "dHAxN3hwZnZha20yYW1nOTYyeWxzNmY4NHoza2VsbDhjNWwydWRmeXQ=",
              "index": false
            },
            {
              "key": "YW1vdW50",
              "value": "NjM1Njk4NTAwbmhhc2g=",
              "index": false
            }
          ]
        },
        {
          "type": "transfer",
          "attributes": [
            {
              "key": "cmVjaXBpZW50",
              "value": "dHAxN3hwZnZha20yYW1nOTYyeWxzNmY4NHoza2VsbDhjNWwydWRmeXQ=",
              "index": false
            },
            {
              "key": "c2VuZGVy",
              "value": "dHAxM2dtN203OHVsbGZ4eGE2bHNlazJsdHo5ZWxqZmF4Nzk1MGZoZHU=",
              "index": false
            },
            {
              "key": "YW1vdW50",
              "value": "NjM1Njk4NTAwbmhhc2g=",
              "index": false
            }
          ]
        },
        {
          "type": "message",
          "attributes": [
            {
              "key": "c2VuZGVy",
              "value": "dHAxM2dtN203OHVsbGZ4eGE2bHNlazJsdHo5ZWxqZmF4Nzk1MGZoZHU=",
              "index": true
            }
          ]
        },
        {
          "type": "tx",
          "attributes": [
            {
              "key": "ZmVl",
              "value": "NjM1Njk4NTAwbmhhc2g=",
              "index": false
            }
          ]
        },
        {
          "type": "tx",
          "attributes": [
            {
              "key": "YWNjX3NlcQ==",
              "value": "dHAxM2dtN203OHVsbGZ4eGE2bHNlazJsdHo5ZWxqZmF4Nzk1MGZoZHUvMjI=",
              "index": false
            }
          ]
        },
        {
          "type": "tx",
          "attributes": [
            {
              "key": "c2lnbmF0dXJl",
              "value": "bnROc29nb2xidWNET3FYY2Y0YjJEWUlHZXczS2JPMFlJcGZwK3M1dzNHZ0RudFQyRVJWZExpcWlRbXBGUDF4NlYrdHRLS1BPVURGZmp5Ull3ZDdyVlE9PQ==",
              "index": false
            }
          ]
        },
        {
          "type": "message",
          "attributes": [
            {
              "key": "YWN0aW9u",
              "value": "L3Byb3ZlbmFuY2UubWFya2VyLnYxLk1zZ0FkZEFjY2Vzc1JlcXVlc3Q=",
              "index": false
            }
          ]
        },
        {
          "type": "provenance.marker.v1.EventMarkerAddAccess",
          "attributes": [
            {
              "key": "YWNjZXNz",
              "value": "eyJhZGRyZXNzIjoidHAxMDAycTI1amdkdGx4aDh2ZGhybG5hdmM4eTd4Y2o5Znlna3czZTAiLCJwZXJtaXNzaW9ucyI6WyJBQ0NFU1NfTUlOVCIsIkFDQ0VTU19XSVRIRFJBVyJdfQ==",
              "index": false
            },
            {
              "key": "ZGVub20=",
              "value": "ImZtdHAxM2dtN203OHVsbGZ4eGE2bHNlazJsdHo5ZWxqZmF4Nzk1MGZoZHUi",
              "index": false
            },
            {
              "key": "YWRtaW5pc3RyYXRvcg==",
              "value": "InRwMTNnbTdtNzh1bGxmeHhhNmxzZWsybHR6OWVsamZheDc5NTBmaGR1Ig==",
              "index": false
            }
          ]
        },
        {
          "type": "message",
          "attributes": [
            {
              "key": "bW9kdWxl",
              "value": "bWFya2Vy",
              "index": false
            }
          ]
        }
      ],
      "codespace": ""
    },
...

Tracking the code, it seems to stem from the conversion from tendermint to rosetta, but thats where my go-foo ends. Specifically here: https://github.com/cosmos/cosmos-sdk/blob/v0.44.0/x/auth/tx/query.go#L82

Version

0.44.0

Steps to Reproduce

Query a tx from cli/grpc vs tendermint api, and view the results.

---

For Admin Use

• Not duplicate issue
• Appropriate labels applied
• Appropriate contributors tagged
• Contributor assigned/self-assigned

[alexanderbez]

Hey @crussell-figure. Rosetta has nothing to do with Tendermint's tx indexing. The code you referenced is just a proxy to Tendermint's RPC to query a tx by hash.

Can you instead post a diff of the events that are in one response and not the other?

[ghost]

Hey @crussell-figure. Rosetta has nothing to do with Tendermint's tx indexing. The code you referenced is just a proxy to Tendermint's RPC to query a tx by hash.

Can you instead post a diff of the events that are in one response and not the other?

My issue includes the events from the query vs from tendermint. The code i linked to is where the tendermint response gets converted to rosetta, specifically this function https://github.com/cosmos/cosmos-sdk/blob/v0.44.0/server/rosetta/converter.go#L268

[alexanderbez]

Ahh I see, thank you. Yet, I don't see what Rosetta has to do with anything here. Are you querying for the tx via a Rosetta API or something?

[ghost]

No, Im querying through cli/grpc. But both of those point to the function that fetches from the tendermint api and then converts to rosetta. Again, I may be off base, but when tendermint gives me all the events and cosmos cli/grpc doesnt, thats an issue.

[alexanderbez]

Sorry, I'm just not getting where Rosetta comes into the picture here. Maybe that's where the issue lies. @fdymylja any thoughts or insight?

[ghost]

@alexanderbez

So after discussion with my team who knows this stuff a lot better than I do, it seems that tendermint is returning those events in an Events object in the tm response (see data in issue), which cosmos is completely ignoring. However, tendermint is also NOT including some events (I dont know which ones) in the Log object in the response (also see data in issue).

Either way, this needs to be resolved if the cosmos query response is going to have those new events in the response.

[alexanderbez]

which cosmos is completely ignoring.

Cosmos doesn't ignore anything. The SDK simply proxies that request to Tendermint and returns the response directly from Tendermint.

What does your application's configuration set for which events to index? Is it set to index all events?

[ghost]

This is the response from Tendermint:

cosmos-sdk/third_party/proto/tendermint/abci/types.proto

Line 217 in 9fd866e

message ResponseDeliverTx {

This is how cosmos returns the response from Tendermint:

cosmos-sdk/types/result.go

Line 66 in bf11b1b

func NewResponseResultTx(res *ctypes.ResultTx, anyTx *codectypes.Any, timestamp string) *TxResponse {

The ResponseDeliverTx.Events is never set anywhere on the Cosmos response. That field is where the "missing" events are held.

[ghost]

Renamed to remove Bug from title.

I figured out what is going on.

Msg events are indexed by msg index. If a tx has multiple msgs, events are grouped by the msg they belong to. So any pre- or post-msg processing events that happen, ie those that are about the tx itself (coin_*, tx), are not included in the logs. They are appended to the result events after the logs are written to string. Thus, you get msg-only events in the Log, and all events in the Events.

I would like to see the ResultTx.TxResult.Events passed through from Tendermint just so end users have access to all events. I know they are not broken down by Msg index, but thats why we have TxResponse.Log. By process of elimination, a user can determine the tx-based events vs the msg-based events.

[alexanderbez]

So any pre- or post-msg processing events that happen, ie those that are about the tx itself (coin_*, tx), are not included in the logs.

BeginBlock and EndBlock events are indexed by Tendermint in the respective responses (via the Events field). Also, Tendermint does not index Logs, it indexes Events. Those are two entirely separate fields in the ResponseDeliverTx. See here.

I'm not sure I understand what you're asking. Tendermint successfully indexes all ABCI Event objects provided to it in the relevant ABCI response data structures.

Are you asking to include events in the SDK's TxResponse. It doesn't seem like we consume and return the Events in that object, which does seem like a bug.

[ghost]

Are you asking to include events in the SDK's TxResponse. It doesn't seem like we consume and return the Events in that object, which does seem like a bug.

Yes, thats exactly what I would like to see. And when I was saying indexed, I meant the literal index of the list. Not the tendermint indexer.