Contract events not being emitted reliably

[firatkaratas]

Ethers Version

5.6.7

Search Terms

alchemy, event, eventfilter, optimism

Describe the Problem

Hey all,

I'm having a problem with contract events being not reliable as in they are mostly not emitted but sometimes are emitted.

Events from a smart contract (Gnosis Safe contract, SignMsg but true for other events as well) events usually are not being emitted through **ethers** on **optimism** even though I can see they are actually emitted from the contract on etherscan. I'm using Alchemy as the RPC provider and it seems there are no outages or rate limiting on there as well.

In the below code, you can see how i wait for the events.

This only happens on Optimism. Goerli works perfectly fine.

I'm curious why this piece of code fails to receive the events sometimes. Any clue or suggestion is appreciated 🙏🙏🙏

Thanks in advance.

Code Snippet

const waitSmartContractSignature = async (signer: Signer, hash: string) => {
    const walletContract = new Contract(await signer.getAddress(), EIP1271.abi, signer)
    const internalHash = await walletContract.getMessageHash(hash)
    const eventFilter = walletContract.filters.SignMsg(internalHash)
    return await resolveOnContractEvent(walletContract, eventFilter)
}

const resolveOnContractEvent = (contract: Contract, eventFilter: EventFilter) =>
    new Promise<void>((resolve, reject) => contract.once(eventFilter, resolve).once('error', reject))

### Contract ABI

```shell
{
    "abi": [
        {
            "anonymous": false,
            "inputs": [
                {
                    "indexed": true,
                    "internalType": "bytes32",
                    "name": "msgHash",
                    "type": "bytes32"
                }
            ],
            "name": "SignMsg",
            "type": "event"
        },
        {
            "inputs": [
                {
                    "internalType": "bytes",
                    "name": "message",
                    "type": "bytes"
                }
            ],
            "name": "getMessageHash",
            "outputs": [
                {
                    "internalType": "bytes32",
                    "name": "",
                    "type": "bytes32"
                }
            ],
            "stateMutability": "view",
            "type": "function"
        },
        {
            "inputs": [
                {
                    "internalType": "bytes",
                    "name": "_data",
                    "type": "bytes"
                }
            ],
            "name": "signMessage",
            "outputs": [],
            "stateMutability": "nonpayable",
            "type": "function"
        },
        {
            "constant": true,
            "inputs": [
                {
                    "internalType": "bytes32",
                    "name": "_hash",
                    "type": "bytes32"
                },
                {
                    "internalType": "bytes",
                    "name": "_signature",
                    "type": "bytes"
                }
            ],
            "name": "isValidSignature",
            "outputs": [
                {
                    "internalType": "bytes4",
                    "name": "",
                    "type": "bytes4"
                }
            ],
            "payable": false,
            "stateMutability": "view",
            "type": "function"
        }
    ]
}

Errors

No response

Environment

Browser (Chrome, Safari, etc)

Environment (Other)

optimism, alchemy

[nobrayner]

Just noting that I have been experiencing similar issues - events being created on chain, but not triggering my event listeners - also with Alchemy, but on the Arbitrum Testnet.

My situation also differs in that I am calling contract.on, and not contract.once.

Further findings:

• Sometimes restarting the process fixes it, and it starts receiving new events
• After periods of not working, it starts working again

---

My conclusion is that it is something to do with Alchemy more than ethers, but I am not sure how to proceed with testing/verification.

[goerris]

Hey!
I'm also experiencing the same issue on Polygon Mainnet.
"ethers": "^5.7.1",
I am using Alchemy as a provider and pretty often the events won't trigger.
Calling contract.on.

Saw that a very similar issue was addressed on 2652
And supposedly fixed on v5.6.0 ...

[panukettu]

Since most rollups consider every transaction as a "block" it might be that the default value for provider.pollingInterval is missing transactions as a single poll round seems to do a eth_getLogs for the newest 10 blocks.

Related #3599

[unek]

having the same issue. running off my own Optimism node.

[ricmoo]

Can you please update to the latest version? Similar problems were addressed since the version your OP indicated you were on. :)

[unek]

I am on 5.7.2.

[unek]

my issue might not be ethers-related, I see that I'm stuck on block number 67766754, whatever the fuck that number is

[Siegrift]

Since most rollups consider every transaction as a "block" it might be that the default value for provider.pollingInterval is missing transactions as a single poll round seems to do a eth_getLogs for the newest 10 blocks.

Is this correct? I wasn't able to find this logic in ethers implementation, but I can confirm this for Hardhat. I created an event listener and made 20 transactions. But I only received 10 events via the listener.

[unek]

@Siegrift have you tried using the websocket provider?

[ricmoo]

A polling provider searches ranges, not individual blocks (so if during the last poll it ended on block 1000 and the current poll it is block 1016, it will search blocks 1001 through 1016, inclusive).

[ricmoo]

(It also maintains a sliding window, with capped end-points, to account for networks with fast block times that do not index events before emitting block numbers)

[Siegrift]

Mhh, maybe there is something I am missing... I've created a small repro in https://github.com/Siegrift/ethers-events-skip-demo

There is a simple contract which just emits an event. The test file contains three tests, but the first two fail...

(The output of the first test - notice that I only received the last 11 logs)

The second test only gives me the last event, I guess the provider only looks for the last block for some reason?

[panukettu]

Since most rollups consider every transaction as a "block" it might be that the default value for provider.pollingInterval is missing transactions as a single poll round seems to do a eth_getLogs for the newest 10 blocks.

Is this correct? I wasn't able to find this logic in ethers implementation, but I can confirm this for Hardhat. I created an event listener and made 20 transactions. But I only received 10 events via the listener.

When I had to get rid of this issue I concluded this v5 base provider snippet was my problem:

ethers.js/packages/providers/src.ts/base-provider.ts

Lines 1082 to 1089 in 0bfa7f4

	const filter = event.filter;
	filter.fromBlock = event._lastBlockNumber + 1;
	filter.toBlock = blockNumber;
	// Prevent fitler ranges from growing too wild, since it is quite
	// likely there just haven't been any events to move the lastBlockNumber.
	const minFromBlock = filter.toBlock - this._maxFilterBlockRange;
	if (minFromBlock > filter.fromBlock) { filter.fromBlock = minFromBlock; }

Range being constructed here:

ethers.js/packages/providers/src.ts/base-provider.ts

Line 792 in 0bfa7f4

this._maxFilterBlockRange = 10;

[ricmoo]

@panukettu What did you change the range to?

[panukettu]

@panukettu What did you change the range to?

I lowered the pollingInterval instead , it has a setter so it felt less risky.

But in Optimism to catch 99%, would need to assume bursts around ~15blocks/s. So would set the range to ~60 myself with the default 4s interval.

[ricmoo]

Thanks! I will probably add this to the Network config as a plug-in then. It was originally added for Polygon which was the first network to have inconsistent log reads. I will talk to the optimism team too to figure out if there is an upper bound, or if it is a function of polling interval.

[panukettu]

Thanks! I will probably add this to the Network config as a plug-in then. It was originally added for Polygon which was the first network to have inconsistent log reads. I will talk to the optimism team too to figure out if there is an upper bound, or if it is a function of polling interval.

Makes sense for Polygon.

Not stepped to v6 yet but given the v5 API, overloading .on and .once to include filter setup for granular control would make sense.

[Siegrift]

I lowered the pollingInterval instead , it has a setter so it felt less risky.

Btw. I am using this as well, but I don't like this solution.

Shouldn't the expected behaviour though, be to chunk the range and get logs for each chunk? I don't think we should ever skip a block - or am I missing something?

[ricmoo]

The window isn't about skipping blocks. It expands the search window.

The problem is that that a node might respond to getBlockNumber of 1000, but a getLogs(1000, latest) might return an empty list (even though there are events), because the node hasn't indexed the events yet (but has updated its internal block height seen). So, the internal maxFilterBlockRange is used so, when polling, it will continue asking for logs in block 1000 up until 1010 (i.e. 1000 + maxFilterBlockRange).

It internally updates the base block when an event is returned for that block, so if no events have been seen for block 1000 yet, but getLogs(1000, 1005) has an event for block 1000, the next update will only then use getLogs(1001, 1005).

If that makes sense. So, nothing is skipped. It is just used to determine how long to allow a node to return inconsistent results (in this case, inconsistent means returning a block height X for which it hasn't added the events from block X to its db yet).

[ricmoo]

@Siegrift One thing I noticed with one of your above examples, is that you are not waiting for the event to start before triggering the events. The .on requires some time to start up (you can await on it, but that won't include the subscriber starting, although I've been considering adding that). So it isn't skipping events, you are simply not yet subscribed, since there are many steps involved in subscribing that are async, which is why you only get the last 11.

[Siegrift]

One thing I noticed with one of your above examples, is that you are not waiting for the event to start before triggering the events. The .on requires some time to start up (you can await on it, but that won't include the subscriber starting, although I've been considering adding that)

Right, that's a good point. However, I found this issue during an e2e test - and I started my BE system in advance, so the event listener has time to initialise. I tried adding a 15s wait period after initialising the listener in the example above and still got the same result (only last 11 events).

(you can await on it, but that won't include the subscriber starting, although I've been considering adding that)

Yeah, I think that would be very useful.

[ricmoo]

@Siegrift That's weird. I will add a test to the integration tests which runs against a Geth dev node deployed during the CI.

[Siegrift]

Hi, just checking in again. Did you try reproducing this? In our project we are happy with lowering the polling interval workaround - but I am still bugged how/why this happens.

I've edited the https://github.com/Siegrift/ethers-events-skip-demo to also wait until the event is registered, but it has the same problem as I mentioned above.