feat: events: Index events by emitter actor ID

[masih]

Related Issues

Fixes #11594

Proposed Changes

Changes the chain event indexing mechanism to index events
solely by their emitter actor ID, instead of their address. This change
means: 1) index can accommodate non-EVM actors, and 2) improved
performance and efficiency due to reduced number of resolutions and
storage footprint.

Additional Info

The work introduces a caching mechanism to momentarily cache the
resolutions to/fro actor ID and address. Further experimentation is
needed to tune the cache for optimal performance. For now, the
introduction of a unified cache reduces lookup time and memory
allocation foot print compared to the previous implementation where
ephemeral caches were being instantiated per event filter.

Checklist

Before you mark the PR ready for review, please make sure that:

• Commits have a clear commit message.
• PR title is in the form of of <PR type>: <area>: <change being made>
  • example: fix: mempool: Introduce a cache for valid signatures
  • PR type: fix, feat, build, chore, ci, docs, perf, refactor, revert, style, test
  • area, e.g. api, chain, state, market, mempool, multisig, networking, paych, proving, sealing, wallet, deps
• If the PR affects users (e.g., new feature, bug fix, system requirements change), update the CHANGELOG.md and add details to the UNRELEASED section.
• New features have usage guidelines and / or documentation updates in
  • Lotus Documentation
  • Discussion Tutorials
• Tests exist for new functionality or change in behavior
• CI is green

[aarshkshah1992]

Will do one more pass once the tests are up.

[aarshkshah1992]

What does this mean ? Why does having atleast one matching emitter with the filter lead us to exclude reverted events ?

[masih]

Because we cannot confidently resolve the address for reverted events.

[Stebalien]

We should just always exclude reverted events when prefilling (for now). The option to not exclude them only exists for testing.

I've filed an issue. #11770

[rvagg]

I think until we've done proper work to resolve #11770 (see thread there) you'd have to include reverted even in the case of having emitters to consider. I think you need to give maximal information to someone seeking to do a look-back because they're likely trying to catch up unless they exclude reverted themselves in which case they are not doing a "tell me what happened since I last looked" catch-up but a "tell me how it is now".

[masih]

The issue with that is address resolution; events database may contain reverted events without emitter actor ID. Therefore, we cannot confidently infer whether those events should be included in pre-filling or not. Does that make sense?

[Stebalien]

Well, after the migration, they'll have IDs, they just won't have addresses. But you're right that we won't be able to confidently pre-fill (quickly, at least).

I'm going to have to disagree with @rvagg here. Our handling of reverted events in the current APIs is not very useful, as discussed in the linked issue.

[masih]

Progressed with always excluding reverted events during backfill. Please mark as unresolved if there is anything that I have missed here. thanks

[masih]

ah never mind.

[arajasek]

I left a ramble below on the different possible address resolutions mostly for informative purposes, but I'm a little confused about why we need an AddressResolver at all. I fee like if we're doing this correctly, we should only ever be going in one direction (to ID addresses).

[Stebalien]

Any reason for this to be public?

[Stebalien]

Also, why add this field on the event filter itself?

[masih]

Unexported ActorResolver.

why add this field on the event filter itself?

I think either event filter keeps a reference to manager to access the resolver or takes the resolver reference directly. The latter seems like a more concise reference for what it is used today.

[Stebalien]

We should just always exclude reverted events when prefilling (for now). The option to not exclude them only exists for testing.

I've filed an issue. #11770

[rvagg]

I disagree with this as an outcome to 11770, see #11770 (comment)

I think we have to leave this out for now and resolve it separately. I like the idea of an API where you can say "this is where I was last, catch me up". But we don't have that yet so the best we can do is get everything from the API and build a state representation locally by consuming reverted events to undo existing state we have already collected.

Suggested change

	// Always exclude reverted events when prefilling. See:
	// - https://github.com/filecoin-project/lotus/issues/11770
	clauses = append(clauses, "event.reverted=?")

[rvagg]

This seems pretty close, albeit a scary migration and big change.

With a few of my diff suggestions applied and rebased to current master I've run it on my calibnet node which has a complete events db (the 3->4 upgrade timing is not quite right cause I already manually added the indexes from that migration in this db):

{"level":"info","ts":"2024-04-30T14:59:54.325+1000","logger":"filter","caller":"filter/index.go:588","msg":"Upgrading event index from version 3 to version 4"}
{"level":"info","ts":"2024-04-30T14:59:54.325+1000","logger":"filter","caller":"filter/index.go:370","msg":"Successfully migrated event index from version 3 to version 4 in 31.81µs"}
{"level":"info","ts":"2024-04-30T14:59:54.325+1000","logger":"filter","caller":"filter/index.go:598","msg":"Upgrading event index from version 4 to version 5"}
{"level":"info","ts":"2024-04-30T14:59:59.709+1000","logger":"filter","caller":"filter/index.go:520","msg":"Performing DB vacuum and wal checkpointing to free up space after the migration"}
{"level":"info","ts":"2024-04-30T15:00:07.075+1000","logger":"filter","caller":"filter/index.go:512","msg":"Successfully migrated event index from version 4 to version 5 in 12.749369829s"}

So 👍 that the migration was successful at least.

I then ran a couple of queries before and after to see what the difference is:

Just built-in actor events:

curl -s -X POST -H "Content-Type: application/json" --data '{"method":"Filecoin.GetActorEventsRaw","params":[{"fromHeight":1441214,"toHeight":1444094,"fields":{"$type":[{"Codec":81,"Value":"cHZlcmlmaWVyLWJhbGFuY2U="},{"Codec":81,"Value":"amFsbG9jYXRpb24="},{"Codec":81,"Value":"cmFsbG9jYXRpb24tcmVtb3ZlZA=="},{"Codec":81,"Value":"ZWNsYWlt"},{"Codec":81,"Value":"bWNsYWltLXVwZGF0ZWQ="},{"Codec":81,"Value":"bWNsYWltLXJlbW92ZWQ="},{"Codec":81,"Value":"bmRlYWwtcHVibGlzaGVk"},{"Codec":81,"Value":"bmRlYWwtYWN0aXZhdGVk"},{"Codec":81,"Value":"b2RlYWwtdGVybWluYXRlZA=="},{"Codec":81,"Value":"bmRlYWwtY29tcGxldGVk"},{"Codec":81,"Value":"c3NlY3Rvci1wcmVjb21taXR0ZWQ="},{"Codec":81,"Value":"cHNlY3Rvci1hY3RpdmF0ZWQ="},{"Codec":81,"Value":"bnNlY3Rvci11cGRhdGVk"},{"Codec":81,"Value":"cXNlY3Rvci10ZXJtaW5hdGVk"}]}}],"id":1,"jsonrpc":"2.0"}' http://localhost:1235/rpc/v1

This one produced no difference, so that's good! They're already actor IDs anyway.

Same epoch span, but all events:

curl -s -X POST -H "Content-Type: application/json" --data '{"method":"Filecoin.GetActorEventsRaw","params":[{"fromHeight":1441214,"toHeight":1444094}],"id":1,"jsonrpc":"2.0"}' http://localhost:1235/rpc/v1

This one has differences, but formatting JSON and diffing just shows the addresses changed.

...
---
>   "emitter": "t067651",
455026c455026
<   "emitter": "t410f43gi2ue3ffyued2tnzggj4bp46sbm4oqefvwm7i",
---
>   "emitter": "t067646",
455065c455065
<   "emitter": "t410fazjdjy3l32rrlnavap6uljckuvjl7f4ziticsca",
---
>   "emitter": "t067651",

However, using the more common eth_getLogs for the same range, fails:

curl -s -X POST -H "Content-Type: application/json" --data '{"method":"Filecoin.EthGetLogs","params":[{"fromBlock":"0x15fdbe","toBlock":"0x1608fe"}],"id":1,"jsonrpc":"2.0"}' http://localhost:1235/rpc/v1

{"jsonrpc":"2.0","id":1,"error":{"code":1,"message":"state get actor: actor not found"}}

Logs have:

{"level":"warn","ts":"2024-04-30T15:21:51.735+1000","logger":"rpc","caller":"go-jsonrpc@v0.3.1/handler.go:444","msg":"error in RPC call to 'Filecoin.EthGetLogs': state get actor:\n    github.com/filecoin-project/lotus/node/impl/full.ethFilterResultFromEvents\n        /home/rvagg/go/src/github.com/filecoin-project/lotus/node/impl/full/eth_events.go:123\n  - actor not found"}

Extra debugging shows it tripping up on this event:

{"level":"warn","ts":"2024-04-30T15:34:02.894+1000","logger":"fullnode","caller":"full/eth_events.go:124","msg":"failed to get actor","actor":"t084452","event":{"Entries":[{"Flags":3,"Key":"t1","Codec":85,"Value":"j6pwh4ZxzNIS0gdxt5XFCvj9P/bPJ/S95X5dTeCutnM="},{"Flags":3,"Key":"d","Codec":85,"Value":"<snipped>"}],"Emitter":84452,"EventIdx":1,"Reverted":false,"Height":1441489,"TipSetKey":[{"/":"bafy2bzacedlxximvilreromjdsbqdd5irj7j6plhu57rm64xexkhusptdorj2"},{"/":"bafy2bzacedi3vqjodd63k7cycvvnnjvmcdkkcfvmhn67bus7szwc4a4x42uda"}],"MsgIdx":1,"MsgCid":{"/":"bafy2bzacebl5mfp7ekw56xdetv7vscukqnbhos5t7jbg3wmtb3z4nmvstnkfw"}},"error":"actor not found"}

Which isn't a reverted event, but apparently not found in state. I'll investigate further after I fix an error I found with my v4 migration!

[rvagg]

OK, here's the problem:

The actor exists at the current head:

curl -s -X POST -H "Content-Type: application/json" --data '{"method":"Filecoin.StateGetActor","params":["t084452",[]],"id":1,"jsonrpc":"2.0"}' http://localhost:1235/rpc/v1

{"jsonrpc":"2.0","result":{"Code":{"/":"bafk2bzacec5ibmbtzuzjgwjmksm2n6zfq3gkicxqywwu7tsscqgdzajpfctxk"},"Head":{"/":"bafy2bzacebezeusg7k3z4g2j2cl3uvx5wvydgvbn7f2p5hzgu3mmvfmn4ldqw"},"Nonce":0,"Balance":"0","Address":"t410fczebosgrdb3oapy37zzmwpli7o5tjdvi7yfv2dy"},"id":1}

But it doesn't exist at the tipset of the event:

curl -s -X POST -H "Content-Type: application/json" --data '{"method":"Filecoin.StateGetActor","params":["t084452",[{"/":"bafy2bzacedlxximvilreromjdsbqdd5irj7j6plhu57rm64xexkhusptdorj2"},{"/":"bafy2bzacedi3vqjodd63k7cycvvnnjvmcdkkcfvmhn67bus7szwc4a4x42uda"}]],"id":1,"jsonrpc":"2.0"}' http://localhost:1235/rpc/v1

{"jsonrpc":"2.0","id":1,"error":{"code":1,"message":"actor not found"}}

But if we fast-forward by one epoch, it does exist:

curl -s -X POST -H "Content-Type: application/json" --data '{"method":"Filecoin.StateGetActor","params":["t084452",[{"/":"bafy2bzaceckcfvpj5uxarwoky37uinq2kcbxuijliisloxvopf2xc75mqvvfc"},{"/":"bafy2bzacebjhy3nw3abeasz2symc4y4ze4w76tdgpl6b4e23j6unhr2qmqwym"},{"/":"bafy2bzaceavtrohq4y7pprr3m4ecjxauo66j3xxfcq6harwpg3qxus2qbxepg"},{"/":"bafy2bzacec27r2slvaysjzqac4k6oy5yesqogpqgoncvl3phrfkdkcl6uqu5g"}]],"id":1,"jsonrpc":"2.0"}' http://localhost:1235/rpc/v1

{"jsonrpc":"2.0","result":{"Code":{"/":"bafk2bzacec5ibmbtzuzjgwjmksm2n6zfq3gkicxqywwu7tsscqgdzajpfctxk"},"Head":{"/":"bafy2bzacedyonsvsf6f3ufayfdaaiepvl23dt2c5btfbmhlqlcpepetqavirk"},"Nonce":0,"Balance":"0","Address":"t410fczebosgrdb3oapy37zzmwpli7o5tjdvi7yfv2dy"},"id":1}

Deferred execution yay.

I'm not sure the best way to deal with this. Perhaps we could:

1. Call StateGetActor without a tipset and cross our fingers? That probably won't work for reverted events though.
2. Use a combination of GetTipSetFromKey and GetTipSetFromHeight to get the tipset+1 and use that when we call StateGetActor?
3. ... something else I'm not aware of that we can do?

[rvagg]

I just found this, which will need to be included in this PR:

lotus/cmd/lotus-shed/indexes.go

Line 110 in 6bbe090

// TODO: We don't need this address resolution anymore once https://github.com/filecoin-project/lotus/issues/11594 lands

[rvagg]

OK, with #11953 applied, the Filecoin.EthGetLogs (eth_getLogs) call above works now, which is good.

However, it takes 1.16 seconds to get 10198 events.

Without this PR and needing to do the address translation on request, the same call for 10198 events takes 0.56s seconds to fetch. So we've doubled the time due to the need to load state and map addresses on output.

[masih]

That's the time measurement on a warm instance with caches populated?

[Stebalien]

However, it takes 1.16 seconds to get 10198 events.

The issue is likely that we're constantly re-loading the init actor and address map. If we could cache that (even within a single trace), we'd get much better performance (#11723 (comment)).

Although this is something we should be able to look at with a pprof profile.