Bug: Call handler improperly invoked when call was reverted on-chain

[ryley-o]

Do you want to request a feature or report a bug?
bug

What is the current behavior?
Currently, we expect call handlers to be invoked only when they are not reverted and associated state changes are applied to the blockchain. However, we observe a case where our subgraph call handler was invoked, but the execution of the call was reverted on-chain, and no associated state changes were not applied to the blockchain.

If the current behavior is a bug, please provide the steps to reproduce and if possible a minimal demo of the problem.
We believe that this transaction would currently always show an example of the bug:
https://bloxy.info/tx/0xc1f4610a49f7b6e5672a31fd4df6c0fa8bf63b54ade7a2cb6d7424df1822ceb5

For context, the transaction is intended to be a Gnosis Safe multiSend transaction where two projects are added to Art Blocks. The first addProject succeeded, but the second addProject reverted (out of gas). The result of the transaction is that both addProject calls were reverted (blockchain state does not see either project added), but the transaction as a whole succeeded. Thus, we would expect no addProject call handler to be invoked in our subgraph. However, we see that the first addProject was invoked in our subgraph, leading to a mismatch of blockchain state vs. subgraph state.

We can prove that our call handler was triggered via the following query. Comparing blocks 14676509 vs. 14676510 shows that project 308 was added in our subgraph.
reference subgraph: https://thegraph.com/explorer/subgraph?id=5So3nipgHT3ks7pEPDQ6YgSFhfEmADrh481P9z1ZtcMA&view=Playground

{
  projects(
    block: {
      number: 14676510
    }
    where: {
    id: "0xa7d8d9ef8d8ce8992df33d8b8cf4aebabd5bd270-308"
  }) {
    id
    createdAt
  }
}

What is the expected behavior?
The expected behavior is as described above - we would not expect a call handler to be invoked when it was actually reverted during execution.

Other
The following issue may be related to the best solution for this bug. The bug described in this issue is slightly different because in this case, we think the call was improperly interpreted to not have been reverted (whereas the linked issue below would just give visibility to all calls that were properly interpreted to have reverted).
#1055

[ryley-o]

Cc @jakerockland

[jakerockland]

Thank you very much for filing this @ryley-o 🙏 🤝

[schmidsi]

Great write up. We'll dig into this.

[ryley-o]

(updated description with a link I accidentally left out to our decentralized subgraph!)

[azf20]

Hi! Thanks for the detailed description. I discussed with @leoyvens. We had previously fixed a similar issue #2409 where callHandlers were triggered for failing transactions. This is a more nuanced case in that the transaction succeeded, it's just that one of the underlying calls failed, which reverted the execution. Fixing this definitively under the current architecture would require fetching all the call traces for every transaction which triggers a callHandler, which would have a non-trivial performance impact. We are currently testing the Firehose as an alternative data source for Ethereum indexing (vs. RPC), which would allow us to fix this bug in a performant fashion (as the firehose provides all the traces). That work is ongoing and will hopefully be available soon, so that is probably the happiest path from where we are. Again apologies for this, as this is certainly a tricky bug.

[sduchesneau]

I dug into this particular transaction from how we see them in the firehose block (see json format below)

Indeed, the DELEGATE call at index 5 calls method "multiSend()", which makes two children calls (index 6 and 7), both to AddProject().

The CALL 7 fails and reverts ("statusFailed": true) and the CALL 6 is reverted (no statusFailed, but does show "stateReverted": true.

This is probably why the RPC implementation cannot catch this particular case, there is no error on this call.

By using the "stateReverted" from the firehose, we can easily fix the behavior and ignore the "successful but reverted" calls the same way that we do with "failed and reverted" calls.

(I'm dumping more data mostly for documentation purpose, but also for all the curious minds...)

Simplified map of the calls

           CALL(1) execTransaction()
                    SUCCESS
          /                          \ 
   DELEGATE(1) execTransaction()      DELEGATE(5) -> multiSend()
           SUCCESS                         FAILED, REVERTED
                                        /                \
                             CALL(6) AddProject()         CALL(7) -> AddProject()
                             REVERTED  (not failed)       FAILED, REVERTED

Content of firehose transaction (some fields have been removed for readability)

        "to": "cf00ec2b327bcfa2bee2d8a5aee0a7671d08a283",
        "nonce": "75",
        "gasPrice": "1702680fe4",
        "gasLimit": "240000",
        "input":  
        (...)
        "hash": "c1f4610a49f7b6e5672a31fd4df6c0fa8bf63b54ade7a2cb6d7424df1822ceb5",
        "from": "8a271f4f7c883e947b90f1098ea40696e8e779f3",
        "status": "SUCCEEDED",
        "receipt": {
          "cumulativeGasUsed": "4282329",
          "logs": [ ... ],
        "calls": [
          {
            "index": 1,
            "callType": "CALL",
            "caller": "8a271f4f7c883e947b90f1098ea40696e8e779f3",
            "address": "cf00ec2b327bcfa2bee2d8a5aee0a7671d08a283",
            "gasLimit": "210604",
            "gasConsumed": "206383",
            "returnData": "0000000000000000000000000000000000000000000000000000000000000000",
            "input": "6a76120200000000000000000000000040a2accbd92bca938b02010e17a5b8929b49130d00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000140000000000000000000000000000000000000000000000000000000000000000100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000040000000000000000000000000000000000000000000000000000000000000002848d80ff0a0000000000000000000000000000000000000000000000000000000000000020000000000000000000000000000000000000000000000000000000000000023200a7d8d9ef8d8ce8992df33d8b8cf4aebabd5bd270000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000c4e3f59c44000000000000000000000000000000000000000000000000000000000000008000000000000000000000000077bc098edff7faac3c31a60969978c4e0b5e867c000000000000000000000000000000000000000000000000016345785d8a000000000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000000000008436174746c65796100000000000000000000000000000000000000000000000000a7d8d9ef8d8ce8992df33d8b8cf4aebabd5bd270000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000c4e3f59c4400000000000000000000000000000000000000000000000000000000000000800000000000000000000000004056d8246deff465667addc33bd97b350578ed0200000000000000000000000000000000000000000000003635c9adc5dea0000000000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000000000009313030205052494e54000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000826e2ba18d94a4d68e7265bbe303a9726d9ed5032aeb9b5a6d45b210bdb3d1681530cda303691baba45d5ae49f195ce4684f447e3e4a38b01453554530735967281cbd0e70b15b2a8b2c2959ec03d0cdc369c800540e3461b5109a23f68fd9959e48339ca2563cc1940e9fe8b29e08e6fd3f53b82950f88fd2d22e755f88602d93fc1b000000000000000000000000000000000000000000000000000000000000",
            "executedCode": true,
            "endOrdinal": "2076"
          },
          {
            "index": 2,
            "parentIndex": 1,
            "depth": 1,
            "callType": "DELEGATE",
            "caller": "8a271f4f7c883e947b90f1098ea40696e8e779f3",
            "address": "34cfac646f301356faa8b21e94227e3583fe3f5f",
            "gasLimit": "202382",
            "gasConsumed": "201328",
            "returnData": "0000000000000000000000000000000000000000000000000000000000000000",
            "input": "6a76120200000000000000000000000040a2accbd92bca938b02010e17a5b8929b49130d00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000140000000000000000000000000000000000000000000000000000000000000000100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000040000000000000000000000000000000000000000000000000000000000000002848d80ff0a0000000000000000000000000000000000000000000000000000000000000020000000000000000000000000000000000000000000000000000000000000023200a7d8d9ef8d8ce8992df33d8b8cf4aebabd5bd270000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000c4e3f59c44000000000000000000000000000000000000000000000000000000000000008000000000000000000000000077bc098edff7faac3c31a60969978c4e0b5e867c000000000000000000000000000000000000000000000000016345785d8a000000000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000000000008436174746c65796100000000000000000000000000000000000000000000000000a7d8d9ef8d8ce8992df33d8b8cf4aebabd5bd270000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000c4e3f59c4400000000000000000000000000000000000000000000000000000000000000800000000000000000000000004056d8246deff465667addc33bd97b350578ed0200000000000000000000000000000000000000000000003635c9adc5dea0000000000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000000000009313030205052494e54000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000826e2ba18d94a4d68e7265bbe303a9726d9ed5032aeb9b5a6d45b210bdb3d1681530cda303691baba45d5ae49f195ce4684f447e3e4a38b01453554530735967281cbd0e70b15b2a8b2c2959ec03d0cdc369c800540e3461b5109a23f68fd9959e48339ca2563cc1940e9fe8b29e08e6fd3f53b82950f88fd2d22e755f88602d93fc1b000000000000000000000000000000000000000000000000000000000000",
            "executedCode": true,
            "storageChanges": [...],
            "logs": [
              {
                "address": "cf00ec2b327bcfa2bee2d8a5aee0a7671d08a283",
                "topics": [
                  "23428b18acfb3ea64b08dc0c1d296ea9c09702c09083ca5272e64d115b687d23"
                ],
                "data": "a736b6a4ceffdc9531a79629e0cecfac1d7af78df9143ecebe48eea31dcf89440000000000000000000000000000000000000000000000000000000000000000",
                "blockIndex": 88,
                "ordinal": "2072"
              }
            ],
            "gasChanges": [...],
            "beginOrdinal": "2030",
            "endOrdinal": "2073"
          },
          {
            "index": 3,
            "parentIndex": 2,
            "depth": 2,
            "callType": "STATIC",
            "caller": "cf00ec2b327bcfa2bee2d8a5aee0a7671d08a283",
            "address": "0000000000000000000000000000000000000001",
            "gasLimit": "186782",
            "gasConsumed": "3000",
            "returnData": "00000000000000000000000089e0cce4bc79d9cb0cefa4785783ad6e66978527",
            "input": "a736b6a4ceffdc9531a79629e0cecfac1d7af78df9143ecebe48eea31dcf8944000000000000000000000000000000000000000000000000000000000000001c6e2ba18d94a4d68e7265bbe303a9726d9ed5032aeb9b5a6d45b210bdb3d1681530cda303691baba45d5ae49f195ce4684f447e3e4a38b0145355453073596728",
            "executedCode": true,
            "gasChanges": [...],
            "beginOrdinal": "2035",
            "endOrdinal": "2037"
          },
          {
            "index": 4,
            "parentIndex": 2,
            "depth": 2,
            "callType": "STATIC",
            "caller": "cf00ec2b327bcfa2bee2d8a5aee0a7671d08a283",
            "address": "0000000000000000000000000000000000000001",
            "gasLimit": "180864",
            "gasConsumed": "3000",
            "returnData": "0000000000000000000000008a271f4f7c883e947b90f1098ea40696e8e779f3",
            "input": "a736b6a4ceffdc9531a79629e0cecfac1d7af78df9143ecebe48eea31dcf8944000000000000000000000000000000000000000000000000000000000000001bbd0e70b15b2a8b2c2959ec03d0cdc369c800540e3461b5109a23f68fd9959e48339ca2563cc1940e9fe8b29e08e6fd3f53b82950f88fd2d22e755f88602d93fc",
            "executedCode": true,
            "gasChanges": [...],
            "beginOrdinal": "2040",
            "endOrdinal": "2042"
          },
          {
            "index": 5,
            "parentIndex": 2,
            "depth": 2,
            "callType": "DELEGATE",
            "caller": "8a271f4f7c883e947b90f1098ea40696e8e779f3",
            "address": "40a2accbd92bca938b02010e17a5b8929b49130d",
            "gasLimit": "172271",
            "gasConsumed": "172255",
            "input": "8d80ff0a0000000000000000000000000000000000000000000000000000000000000020000000000000000000000000000000000000000000000000000000000000023200a7d8d9ef8d8ce8992df33d8b8cf4aebabd5bd270000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000c4e3f59c44000000000000000000000000000000000000000000000000000000000000008000000000000000000000000077bc098edff7faac3c31a60969978c4e0b5e867c000000000000000000000000000000000000000000000000016345785d8a000000000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000000000008436174746c65796100000000000000000000000000000000000000000000000000a7d8d9ef8d8ce8992df33d8b8cf4aebabd5bd270000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000c4e3f59c4400000000000000000000000000000000000000000000000000000000000000800000000000000000000000004056d8246deff465667addc33bd97b350578ed0200000000000000000000000000000000000000000000003635c9adc5dea0000000000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000000000009313030205052494e5400000000000000000000000000000000000000000000000000000000000000000000000000",
            "executedCode": true,
            "gasChanges": [...],
            "statusFailed": true,
            "statusReverted": true,
            "failureReason": "execution reverted",
            "stateReverted": true,
            "beginOrdinal": "2047",
            "endOrdinal": "2069"
          },
          {
            "index": 6,
            "parentIndex": 5,
            "depth": 3,
            "callType": "CALL",
            "caller": "cf00ec2b327bcfa2bee2d8a5aee0a7671d08a283",
            "address": "a7d8d9ef8d8ce8992df33d8b8cf4aebabd5bd270",
            "gasLimit": "166251",
            "gasConsumed": "164302",
            "input": "e3f59c44000000000000000000000000000000000000000000000000000000000000008000000000000000000000000077bc098edff7faac3c31a60969978c4e0b5e867c000000000000000000000000000000000000000000000000016345785d8a000000000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000000000008436174746c657961000000000000000000000000000000000000000000000000",
            "executedCode": true,
            "storageChanges": [...],

            "gasChanges": [...],
            "stateReverted": true,
            "beginOrdinal": "2051",
            "endOrdinal": "2062"
          },
          {
            "index": 7,
            "parentIndex": 5,
            "depth": 3,
            "callType": "CALL",
            "caller": "cf00ec2b327bcfa2bee2d8a5aee0a7671d08a283",
            "address": "a7d8d9ef8d8ce8992df33d8b8cf4aebabd5bd270",
            "gasLimit": "4165",
            "gasConsumed": "4165",
            "input": "e3f59c4400000000000000000000000000000000000000000000000000000000000000800000000000000000000000004056d8246deff465667addc33bd97b350578ed0200000000000000000000000000000000000000000000003635c9adc5dea0000000000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000000000009313030205052494e540000000000000000000000000000000000000000000000",
            "executedCode": true,
            "keccakPreimages": {
              "7be6e7f68c9506c4cd47cdeb3cf7ebb370c8694e3a306884fa9409ec9af46bb5": "000000000000000000000000cf00ec2b327bcfa2bee2d8a5aee0a7671d08a283000000000000000000000000000000000000000000000000000000000000001c",
              "b6c0fe7b21af9f3e6513005b15f2febeb580c646ec1994803997683eb05c34c4": "0000000000000000000000000000000000000000000000000000000000000135000000000000000000000000000000000000000000000000000000000000000d"
            },
            "gasChanges": [...],
            "statusFailed": true,
            "failureReason": "out of gas",
            "stateReverted": true,
            "beginOrdinal": "2065",
            "endOrdinal": "2068"
          }
        ]
      }```