Timeouts can be reported as deterministic errors

[leoyvens]

There is some situation where a timeout can happen and be reported as a deterministic error, as these logs indicate:

2022-05-20 01:08:59 
May 20 01:08:59.492 DEBG Subgraph stopped, WASM runtime thread terminated, sgd: 300247, subgraph_id: QmTpWTHihFbE9tgz1BE6QaJEQk9GXkzGENeF7AEheriu8J, component: SubgraphInstanceManager
    
2022-05-20 01:08:59 
May 20 01:08:59.490 ERRO Subgraph instance failed to run: Failed to call 'asc_type_id' with 'String'    wasm backtrace:     0: 0x2622 - <unknown>!generated/schema/Epoch#get:id       1: 0x3662 - <unknown>!generated/schema/GlobalState#get:networkArrayHead       2: 0x45bf - <unknown>!node_modules/@graphprotocol/graph-ts/global/global/id_of_type   : wasm trap: interrupt  wasm backtrace:     0: 0xffffffff - <unknown>!node_modules/@graphprotocol/graph-ts/global/global/allocate     1: 0x2622 - <unknown>!generated/schema/Epoch#get:id       2: 0x3662 - <unknown>!generated/schema/GlobalState#get:networkArrayHead       3: 0x45bf - <unknown>!node_modules/@graphprotocol/graph-ts/global/global/id_of_type    in handler `handleCrossChainEpochOracle` at block #12069788 (5a725bbd871dc2a2174d7da4e777fa2efb17f4725a51f51dbc15e5fc6b6fe836), code: SubgraphSyncingFailure, sgd: 300247, subgraph_id: QmTpWTHihFbE9tgz1BE6QaJEQk9GXkzGENeF7AEheriu8J, component: SubgraphInstanceManager
    
2022-05-20 01:08:59 
May 20 01:08:59.073 ERRO Subgraph error 1/1, code: SubgraphSyncingFailure, error: Failed to call 'asc_type_id' with 'String'    wasm backtrace:     0: 0x2622 - <unknown>!generated/schema/Epoch#get:id       1: 0x3662 - <unknown>!generated/schema/GlobalState#get:networkArrayHead       2: 0x45bf - <unknown>!node_modules/@graphprotocol/graph-ts/global/global/id_of_type   : wasm trap: interrupt  wasm backtrace:     0: 0xffffffff - <unknown>!node_modules/@graphprotocol/graph-ts/global/global/allocate     1: 0x2622 - <unknown>!generated/schema/Epoch#get:id       2: 0x3662 - <unknown>!generated/schema/GlobalState#get:networkArrayHead       3: 0x45bf - <unknown>!node_modules/@graphprotocol/graph-ts/global/global/id_of_type    in handler `handleCrossChainEpochOracle` at block #12069788 (5a725bbd871dc2a2174d7da4e777fa2efb17f4725a51f51dbc15e5fc6b6fe836), block_hash: 0x5a725bbd871dc2a2174d7da4e777fa2efb17f4725a51f51dbc15e5fc6b6fe836, block_number: 12069788, sgd: 300247, subgraph_id: QmTpWTHihFbE9tgz1BE6QaJEQk9GXkzGENeF7AEheriu8J, component: SubgraphInstanceManager
    
2022-05-20 01:08:59 
May 20 01:08:59.073 INFO Applying 1 entity operation(s), block_hash: 0x5a725bbd871dc2a2174d7da4e777fa2efb17f4725a51f51dbc15e5fc6b6fe836, block_number: 12069788, sgd: 300247, subgraph_id: QmTpWTHihFbE9tgz1BE6QaJEQk9GXkzGENeF7AEheriu8J, component: SubgraphInstanceManager
    
2022-05-20 01:08:58 
May 20 01:08:58.769 INFO Done processing trigger, gas_used: 26562157793948, data_source: DataEdge, handler: handleCrossChainEpochOracle, total_ms: 1202248, transaction: 0xc391…35d7, to: 0xae6a…6836, function: crossChainEpochOracle(bytes), sgd: 300247, subgraph_id: QmTpWTHihFbE9tgz1BE6QaJEQk9GXkzGENeF7AEheriu8J, component: SubgraphInstanceManager
    
2022-05-20 01:08:56 
May 20 01:08:56.579 ERRO Handler skipped due to execution failure, error: Failed to call 'asc_type_id' with 'String'    wasm backtrace:     0: 0x2622 - <unknown>!generated/schema/Epoch#get:id       1: 0x3662 - <unknown>!generated/schema/GlobalState#get:networkArrayHead       2: 0x45bf - <unknown>!node_modules/@graphprotocol/graph-ts/global/global/id_of_type   : wasm trap: interrupt  wasm backtrace:     0: 0xffffffff - <unknown>!node_modules/@graphprotocol/graph-ts/global/global/allocate     1: 0x2622 - <unknown>!generated/schema/Epoch#get:id       2: 0x3662 - <unknown>!generated/schema/GlobalState#get:networkArrayHead       3: 0x45bf - <unknown>!node_modules/@graphprotocol/graph-ts/global/global/id_of_type   , handler: handleCrossChainEpochOracle, sgd: 300247, subgraph_id: QmTpWTHihFbE9tgz1BE6QaJEQk9GXkzGENeF7AEheriu8J, component: SubgraphInstanceManager

The latest version of wasmtime no longer supports these interrupts but has other ways to support timeouts. So upgrading wasmtime would likely make timeout handling more robust and possibly avoid this issue.

[github-actions]

Looks like this issue has been open for 6 months with no activity. Is it still relevant? If not, please remember to close it.

[leoyvens]

Still relevant as we haven't updated wasmtime.

[leoyvens]

Looking at another occurence of this, it actually looks like an issue specific to the runtime assuming that traps from asc_type_id are always deterministic, which is incorrect since some traps are non-deterministic.

[rahul7668gupta]

I have also been facing the same issue with my subgraph for rarible exchange v2.
Subgraph instance failed to run: Failed to call 'asc_type_id' with 'String' wasm backtrace: 0: 0x331a - <unknown>!src/utils/matchAssetOneSide 1
I would request someone to please look into this issue.

[julien51]

Same on our end:

Handler skipped due to execution failure, error: Failed to call 'asc_type_id' with 'String' wasm backtrace: 0: 0x3146 - <unknown>!~lib/@graphprotocol/graph-ts/chain/ethereum/ethereum.SmartContract#tryCall 1: 0x3247 - <unknown>!generated/templates/PublicLock/PublicLockV11/PublicLockV11#try_tokenURI 2: 0x6584 - <unknown>!src/public-lock/handleLockMetadata : wasm trap: interrupt wasm backtrace: 0: 0xffffffff - <unknown>!node_modules/@graphprotocol/graph-ts/global/global/id_of_type 1: 0x3146 - <unknown>!~lib/@graphprotocol/graph-ts/chain/ethereum/ethereum.SmartContract#tryCall 2: 0x3247 - <unknown>!generated/templates/PublicLock/PublicLockV11/PublicLockV11#try_tokenURI 3: 0x6584 - <unknown>!src/public-lock/handleLockMetadata , handler: handleLockMetadata

Our subgraph code has a loop which is extra long for this token...

    if (
      !baseTokenURI.reverted &&
      baseTokenURI.value !== event.params.baseTokenURI
    ) {
      for (let i = 0; i < totalKeys.toI32(); i++) {
        const keyID = genKeyID(event.address, `${i + 1}`)
        const key = Key.load(keyID)
        if (key) {
          const tokenURI = lockContract.try_tokenURI(key.tokenId)
          if (!tokenURI.reverted) {
            key.tokenURI = tokenURI.value
            key.save()
          }
        }
      }
    }

Happening on QmZVK5VQ6LMm95nySe6opamptTCVVAG2yB3mFyCC1U2PrL

Posted on The Graph's discord server to get some good practices/guidance https://discord.com/channels/438038660412342282/438070183794573313/1082786404691628112

[julien51]

Thank you!!