Ethers.js: Unreliable event filtering

[andrewgordstewart]

The cookbook provides a strategy for testing events, using contract.on. However, this only seems to be reliable if run in a single test suite.

A separate part of the cookbook presents a strategy for returning a value from a state-changing function. This strategy can also be used to test events.

Going by the cookbook, we at Magmo used the first strategy. However, it forced us to run our jest test suites in serial with the --runInBand option. This is both time consuming, and worrying, since we cannot trust the behaviour of contract.on based on this issue.

Here is a repository reproducing the issue. On the first commit, yarn test will not work, but yarn testInBand will reliably work. On the second commit, yarn test will reliably work.

[ricmoo]

Do you mean the event is never happening? What backend are you using (Geth, Ganache, Parity, INFURA) and which network (homestead, dev)?

I'm not familiar with jest, what is the purpose of --runInBand?

[andrewgordstewart]

The --runInBand option tells jest to run the test suites serially. By default, test suites are run in parallel.

I have only tested the linked repository against ganache.

The event happens, and as the testInBand command shows, ethers notices the event in the absence of other callbacks looking for the same events. But when two callbacks are concurrently looking for some event, it seems like one of them might be clobbering the other.

[andrewgordstewart]

Is there any update on this? We're at the point in the state channels project where this becomes a real issue, not just in testing: if

• one part of my application wants to filter events based on some argument's value being 1
• another part of my application wants to filter events based on some argument's value being 2

then the first event filter might cause the second filter to not work properly.

What seems to be worse is, even in the case where there is just one filter, it doesn't always seem to catch the proper event emitted when there are multiple events of the same type emitted. Here's an example which fails for me, in the same repository linked above.

[ricmoo]

Looking more into this now. @yuetloo reproduced it on her machine, so I'll be creating a simple test on my machine to test this too...

[ricmoo]

We are still investigating, and plugging console.log statements all over the place, but it seems certain there is something wrong with how the initial getBlockNumber() is being used for the very first filter.

Thanks for your patience. :)

[snario]

Thanks @ricmoo!

[ricmoo]

Huge thanks to @yuetloo for all her efforts in debugging this.

A fix has been added, and the tests are running, after they pass (usually about an hour) I will publish to NPM and update this ticket.

This has identified a few other quirks with events, which I'm addressing right now with the re-write of the v5 events.

Thanks!

[ricmoo]

Please update to v4.0.39 and let me know if that works for you.

Thanks! :)

[andrewgordstewart]

After upgrading to v4.0.39, tests pass in the repro repository. Thanks for sorting this out!

[andrevmatos]

@ricmoo doesn't this break the usecase where a user wants to register several filters before doing the initial poll? In our case (at raiden light-client), to catch up after the user was offline for a while, we've been setting the block with resetEventsBlock to the block right after the last we polled/saw, then registering all needed filters before the first poll updated the block and fetched the missed events in the meantime. How should we proceed with this change? Is there a way to prevent polling from auto-starting completely, and starting it ourselves after we're sure filters were installed?

[ricmoo]

@andrevmatos I don't think it should. Does it for you? The call to _doPoll still has a getBlockNumber() call, which means all the contents won't be scheduled until at least the next event loop (in actually, it should be far later, since it has to hit the network), so as long as you configure all your events and reset the block number before then, I think things should work.

Let me know if not though.

One change I do notice I should add though, is to add a if (!this.polling) { return; } to the top of the filter processing; this would at least allow you to turn off polling (using providers.polling = false) to prevent any filter processing.

[andrevmatos]

@ricmoo It seems to be working fine here on the e2e tests, thank you. But finer control over when the polling happens, since there may be a lot in between, would be useful. Maybe prevent it from auto-starting if it was explicitly disabled by the user, or some special value to indicate that? Anyway, the getBlockNumber delay has been enough in our case to register everything for now.