get_ops_in_block inconsistencies

roadscape commented 5 years ago

To reliably index account history (and re/create other functionality) outside of steemd, clients need assurance that their copy of events are complete and accurate. Here I outline discrepancies and general concerns.

Ideally:

all ops are unique on (block, trx_in_block, op_in_trx, virtual_op)
all indices are sequential (gaps suggest missing data)
ability to verify, even if rudimentary, that an external indexer is not missing ops
any non-op balance change is associated with a vop
ops_in_block are accessible up to head_block

Data inconsistency

virtual_op can be non-unique in get_ops_in_block n, True (Appendix A)
op_in_trx can be non-unique in get_ops_in_block n, False (Appendix B)
virtual_op is occasionally non-sequential (Appendix C)
many virtual ops have a trx_in_block of 4294967295 (Appendix C)
- (unclear) are these meant to be -1, or does it signify these are processed after all others?

General concerns

get_ops_in_block is occasionally buggy (e.g. #2413, #2936), difficult to detect issues
- unlike get_block, some issues are undetectable
- possible to expose something like total_vop_count @ block_height for verification?
- one sanity check: all blocks >= 864000 must have at least 1 vop
- Some ops seem to get doubled-up from get_ops_in_block (related to #2496?)
  - not easily reproducible, but running an indexer which calls get_ops_in_block once per block revealed 1000's of duplicate entries
some virtual ops which change balance are missing (#2191 #2173)
inaccessible state, e.g. steem_per_vest (#2174 #2867)
get_ops_in_block only available at irreversible block
- some applications need instant feedback
vops sometimes have unexpected/invalid trx hashes (#853)
(possibly related) last entries on account_history are inconsistent #3052

Appendix A: non-unique `(block,trx_in_block,op_in_trx,virtual_op)`

The last 2 items (virtual_op=3) in this snippet have an identical 'location'.

$ http -j post https://api.steemit.com jsonrpc=2.0 id=1 method=account_history_api.get_ops_in_block params:='{"block_num": 2889020, "only_virtual": true}' > vops.tmp
$ cat vops.tmp | jq . | head -n 95
{
  "jsonrpc": "2.0",
  "result": {
    "ops": [
      {
        "trx_id": "0000000000000000000000000000000000000000",
        "block": 2889020,
        "trx_in_block": 4294967295,
        "op_in_trx": 0,
        "virtual_op": 1,
        "timestamp": "2016-07-04T00:00:06",
        "op": {
          "type": "producer_reward_operation",
          "value": {
            "producer": "witness.svk",
            "vesting_shares": {
              "amount": "5234743387",
              "precision": 6,
              "nai": "@@000000037"
            }
          }
        }
      },
      {
        "trx_id": "0000000000000000000000000000000000000000",
        "block": 2889020,
        "trx_in_block": 4294967295,
        "op_in_trx": 0,
        "virtual_op": 2,
        "timestamp": "2016-07-04T00:00:06",
        "op": {
          "type": "curation_reward_operation",
          "value": {
            "curator": "anonymous",
            "reward": {
              "amount": "3952229956",
              "precision": 6,
              "nai": "@@000000037"
            },
            "comment_author": "abit",
            "comment_permlink": "spam"
          }
        }
      },
      {
        "trx_id": "0000000000000000000000000000000000000000",
        "block": 2889020,
        "trx_in_block": 4294967295,
        "op_in_trx": 0,
        "virtual_op": 3,
        "timestamp": "2016-07-04T00:00:06",
        "op": {
          "type": "author_reward_operation",
          "value": {
            "author": "abit",
            "permlink": "spam",
            "sbd_payout": {
              "amount": "82",
              "precision": 3,
              "nai": "@@000000013"
            },
            "steem_payout": {
              "amount": "0",
              "precision": 3,
              "nai": "@@000000021"
            },
            "vesting_payout": {
              "amount": "1978732349",
              "precision": 6,
              "nai": "@@000000037"
            }
          }
        }
      },
      {
        "trx_id": "0000000000000000000000000000000000000000",
        "block": 2889020,
        "trx_in_block": 4294967295,
        "op_in_trx": 0,
        "virtual_op": 3,
        "timestamp": "2016-07-04T00:00:06",
        "op": {
          "type": "curation_reward_operation",
          "value": {
            "curator": "tuck-fheman",
            "reward": {
              "amount": "492065716",
              "precision": 6,
              "nai": "@@000000037"
            },
            "comment_author": "joshua",
            "comment_permlink": "a-story-about-a-lack-of-symmetry"
          }
        }
      },

Appendix B: ops are non-unique on (`block,trx_in_block,op_in_trx`)

The last 2 items of the following snippet both specify "block": 4273531, "trx_in_block": 1, "op_in_trx": 0, "virtual_op": 0

http -j post <ahnode> jsonrpc=2.0 id=1 method=account_history_api.get_ops_in_block params:='{"block_num": 4273531, "only_virtual": false}' | jq . | head -n 75
{
  "jsonrpc": "2.0",
  "result": {
    "ops": [
      {
        "trx_id": "13a82b79890a7f77461bb383284b51b230de2669",
        "block": 4273531,
        "trx_in_block": 0,
        "op_in_trx": 0,
        "virtual_op": 0,
        "timestamp": "2016-08-21T11:18:33",
        "op": {
          "type": "vote_operation",
          "value": {
            "voter": "teatree",
            "author": "candy49",
            "permlink": "re-fyrstikken-throw-away-accounts-is-a-problem-i-suggest-that-in-order-to-be-allowed-to-flag-a-post-the-account-flagging-needs-to-have-a-20160820t210706679z",
            "weight": 10000
          }
        }
      },
      {
        "trx_id": "417e14bb5565aa8bb9c0c74bfbcf59d75298f7e0",
        "block": 4273531,
        "trx_in_block": 1,
        "op_in_trx": 0,
        "virtual_op": 0,
        "timestamp": "2016-08-21T11:18:33",
        "op": {
          "type": "limit_order_create_operation",
          "value": {
            "owner": "btcmsia",
            "orderid": 78309885,
            "amount_to_sell": {
              "amount": "100000",
              "precision": 3,
              "nai": "@@000000021"
            },
            "min_to_receive": {
              "amount": "160000",
              "precision": 3,
              "nai": "@@000000013"
            },
            "fill_or_kill": false,
            "expiration": "2016-08-22T11:18:30"
          }
        }
      },
      {
        "trx_id": "417e14bb5565aa8bb9c0c74bfbcf59d75298f7e0",
        "block": 4273531,
        "trx_in_block": 1,
        "op_in_trx": 0,
        "virtual_op": 0,
        "timestamp": "2016-08-21T11:18:33",
        "op": {
          "type": "limit_order_create_operation",
          "value": {
            "owner": "btcmsia",
            "orderid": 78309887,
            "amount_to_sell": {
              "amount": "120000",
              "precision": 3,
              "nai": "@@000000021"
            },
            "min_to_receive": {
              "amount": "192360",
              "precision": 3,
              "nai": "@@000000013"
            },
            "fill_or_kill": false,
            "expiration": "2016-08-22T11:18:30"
          }
        }
      },

Appendix C: `virtual_op` can be non-sequential

Block 2998688 contains only virtual ops, and there are 2 unexpected gaps in virtual_op:

$ http -j post <ahnode> jsonrpc=2.0 id=1 method=account_history_api.get_ops_in_block params:='{"block_num": 2998688, "only_virtual": false}' | jq '.result.ops[].virtual_op'
1
5
6
7
11
12

sneak commented 5 years ago

 sneak  nostromo-2  ~  http -j post https://api.steemit.com jsonrpc=2.0 id=1 method=account_history_api.get_ops_in_block params:='{"block_num": 2889020, "only_virtual": false}'
HTTP/1.1 200 OK
Access-Control-Allow-Headers: DNT,Keep-Alive,User-Agent,X-Requested-With,If-Modified-Since,Cache-Control,Content-Type,Content-Range,Range
Access-Control-Allow-Methods: GET, POST, OPTIONS
Access-Control-Allow-Origin: *
Connection: keep-alive
Content-Length: 491
Content-Security-Policy: upgrade-insecure-requests
Content-Type: application/json
Date: Mon, 05 Nov 2018 17:05:48 GMT
Server: nginx
Strict-Transport-Security: max-age=31557600; includeSubDomains; preload
x-amzn-trace-id: Root=1-5be0786c-ee82ac2acbc2507bbce65e26
x-jussi-request-id: 000286667438859137

{
    "error": {
        "code": -32002,
        "data": {
            "code": 10,
            "message": "Assert Exception",
            "name": "assert_exception",
            "stack": [
                {
                    "context": {
                        "file": "json_rpc_plugin.cpp",
                        "hostname": "",
                        "level": "error",
                        "line": 206,
                        "method": "find_api_method",
                        "timestamp": "2018-11-05T17:05:48"
                    },
                    "data": {
                        "api": "account_history_api"
                    },
                    "format": "api_itr != _registered_apis.end(): Could not find API ${api}"
                }
            ]
        },
        "message": "Assert Exception:api_itr != _registered_apis.end(): Could not find API account_history_api"
    },
    "id": "1",
    "jsonrpc": "2.0"
}

 sneak  nostromo-2  ~ 

Is account_history_api.get_ops_in_block supposed to be available on api.steemit.com?

mvandeberg commented 5 years ago

Jussi is not routing account_history_api properly. This is a known bug. steemit/jussi#212

roadscape commented 5 years ago

An exchange also reported an account history op_in_trx inconsistency.

condenser_api.get_account_history returned an operation with "op_in_trx": 0, while get_transaction reveals op_in_trx should be 90.

condenser_api.get_account_history response:

    "jsonrpc": "2.0",
    "result": [
        [
            2228,
            {
                "trx_id": "551c1bc0e04671ceaf6740f13e623663e417533d",
                "block": 22967441,
                "trx_in_block": 8,
                "op_in_trx": 0,
                "virtual_op": 0,
                "timestamp": "2018-06-02T10:40:30",
                "op": [
                    "transfer",
                    {
                        "from": "id1",
                        "to": "huobi-withdrawal",
                        "amount": "0.001 SBD",
                        "memo": "☆ Hi! We are creating one of the first Multichain tokens ever working on ETH, EOS and NEO: 3 in 1. Please check out our project  🔥Ducatur.net🔥 •MVP is ready  •3 Hackathons won  •Softcap Reached 📬 Any questions please feel free to contact me  steemit@ducatur.net ☆"
                    }
                ]
            }
        ]
    ],
    "id": 1
}

get_transaction response: https://steemd.com/tx/551c1bc0e04671ceaf6740f13e623663e417533d

mvandeberg commented 5 years ago

Are they the running normal account_history or the rocksdb backed account history?

All previous bug reports I thought we from the rocksdb backed account history which indicates there is probably an inconsistency in how that implementation tracks this data vs how is used to be tracked. Because we are actively working on a rocksdb adapter for all indices that will replace the rocksdb backed account history altogether, I am inclined not to investigate this further.

roadscape commented 5 years ago

Ok it sounds like they are using the non-rocksdb account history.

steemchiller commented 5 years ago

The op_in_trx inconsistency still occurs sometimes. I got the same value of 0 for two operations within one transaction, which makes it hard to uniquely identify each of them:

I tested it with different nodes (also api.steemit.com) a few days ago and the result was always the same.

steemit / steem