Unable to catch events with provider when using Ganache-Core for test

[mayorcoded]

I am writing a test to listen to events on the blockchain, most especially the 'block' event. My tools are Ethers.js and Ganache-core. Using the provider.on(event, callback) function does not work. here is a copy of my code and what I was testing:

const ethers = require('ethers');
const getProvider = new ethers.providers.Web3Provider(ganache.provider({mnemonic: some random phrase}));

describe('listen to blockchain transactions', () => {
 beforeAll(async (done) => {
        provider = getProvider();
  });
 afterAll(async () => {
        provider.stop();
 });

it('should listen to transactions between user accounts', async () => {
        const accounts = await provider.listAccounts();
        const userAccount1 = accounts[1];
        const userAccount2 = accounts[2];
        const chainId = (await provider.ready).chainId;
        let transaction = {
            nonce: 0,
            gasLimit: 21000,
            gasPrice: ethers.utils.bigNumberify("20000000000"),
            to: userAccount2,
            value: ethers.utils.parseEther("10.0"),
            data: "0x",
            chainId: chainId
        };
        const privateKey = await accountService.getAccountSigningKey(userAccount1);
        const wallet = new ethers.Wallet(privateKey);
        const signedTransaction = await wallet.sign(transaction);
        const transactionResponse = await provider.sendTransaction(signedTransaction);
        provider.on('block', async (blockHeight) => {
            console.log('blockHeight: ', blockHeight) //Nothing logs, this callback is not executed    
        });
    });
})

Could there be a better way to do this? Kindly recommend.

[ricmoo]

What if you configure the block event before the transaction?

Ganache does blockchain things very synchronously, so the block number may already be up to date when the provider fetched the block number to compare against?

[ricmoo]

Also, ready is meant to be fairly internal. You can use provider.getNetwork() to get the same thing. :)

[mayorcoded]

Also, ready is meant to be fairly internal. You can use provider.getNetwork() to get the same thing. :)

I have done this. Thank you!

[mayorcoded]

What if you configure the block event before the transaction?

Ganache does blockchain things very synchronously, so the block number may already be up to date when the provider fetched the block number to compare against?

I did this, I also made the provider listen to the block event in the beforeAll hook, but nothing logs still. Is there a way to force the provider to emit an event? I have practically been on this for days

[ricmoo]

You could call provider.emit("block", 1234), but that seems to defeat the purposes of testing...

Oh!! I think I see a problem, maybe. You aren't waiting for the transaction to be mined... I'm not sure about Ganache, but this would be a problem in non-Ganache test cases. The events are only emitted once mined.

Can you add await transactionResponse.wait() after registering for the event?

[mayorcoded]

Sure, I did that already as well, I have also done it again, still nothing. Although when I debug the test, I see that the 'block' event is registered in the _event property, but the listener is not just catching it.

[ricmoo]

Oh! I think this may be an issue with how polling is done, which is only on block change.

As an experiment, can you add the following (in addition to the above async):

setInterval(function() {
    provider._doPoll();
}, 500);

Does the test case exit? Because it should hang, as long as there are non-daemon intervals running...

[mayorcoded]

I literarily have some tears in my eyes now... adding the last function worked! However, I added it to the top of the test case before it did.

• Does the test case exit?
  yes, the test case exits. Cuz I have some other test cases after it that runs.

[ricmoo]

Ok... I will address this somehow.... I need to think of a better way to do this.

The problem is that in a PoA network, which is what Ganache basically is, there are no blocks mined if there is nothing happening. And since ethers only triggers an event processing loop when a block happens, this never happens in a non-chatty PoA network.

Is there a way to make ganache mine empty blocks periodically? This should also "help" the situation, but isn't a real fix. I'll think about this for a bit too...

[mayorcoded]

Yeah, it requires some thinking to figure out. I appreciate your help thus far Richard. Thank you! I will also look into this issue and come up with suggestions as they come to mind.

[mayorcoded]

In the polling section of the documentation, it says this This may make sense to lower for PoA networks or when polling a local node. ref (https://docs.ethers.io/ethers.js/html/api-providers.html?highlight=polling#properties) do you think it might just be normal to have a smaller polling time since it a local node recommendation?

[andrewgordstewart]

Ok... I will address this somehow.... I need to think of a better way to do this.

The problem is that in a PoA network, which is what Ganache basically is, there are no blocks mined if there is nothing happening. And since ethers only triggers an event processing loop when a block happens, this never happens in a non-chatty PoA network.

Is there a way to make ganache mine empty blocks periodically? This should also "help" the situation, but isn't a real fix. I'll think about this for a bit too...

Ganache does offer this feature with the --blockTime flag: npx ganache-cli --blockTime n will mine a block every n seconds.

If you don't want to do this, you can also manually mine a block by sending evm_mine. Here's a blog post that uses this technique.

[niksauer]

I have the same problem. Neither evm_mine, nor a default blocktime triggered the subscription callback..

Setup

export async function setupTestEnvironment(): Promise<TestEnvironment> {
  const blockchain = Ganache.provider({
    total_accounts: 3,
    default_balance_ether: 100,
    // blockTime: 5, // mine a block every two seconds in order to flush event listeners
  });

  const provider = new providers.Web3Provider(blockchain as any);

  const accounts = await provider.listAccounts();

  const deployerAddress = accounts[0];
  const deployerSigner = provider.getSigner(deployerAddress);

  const contractAddress = await deployContract(provider, deployerSigner);

  return {
    provider,
    accounts,
    deployerAddress,
    deployerSigner,
    contractAddress,
  };
}

Test

test.serial('subscribe() notifies on LicensePurchased event', async (t) => {
  const {
    deployerAddress,
    contractAddress,
    deployerSigner,
  } = t.context as TestEnvironment;

  t.plan(1);

  const registry = new LicenseRegistry(contractAddress, deployerSigner);

  registry.subscribe(LicenseTokenEvent.LicensePurchased, (address, event) => {
    t.true(typeof address == 'string');
  });

  await registry.purchaseLicense(deployerAddress);
});

It works fine when run against a Docker Ganache CLI instance.

[ricmoo]

Is this still an issue? Or should I close it?

[tina1998612]

I have the same problem

[trojanMcAfee]

Same over here. Callback doesn't run with on subscription while using hardhat's local node:

const signer2 = await hre.ethers.provider.getSigner(2);
  const receiver = signer2.getAddress();
  const amount = hre.ethers.utils.parseEther('1120');

  const Contract = await hre.ethers.getContractFactory("Token");
  const contract = await Contract.deploy();
  await contract.deployed();

  function cb(from, to, amount) {
    console.log(from, to, amount);
  };

  

  await contract.transfer(receiver, { value: amount });
  console.log(hre.ethers.utils.formatEther(await signer2.getBalance()));

  
  contract.on("Transfer", cb);

[zemse]

The way contract.on("Transfer", cb); works is it polls the chain in intervals (default 4 secs).

it('test case', async () => {
  const contract = ...; // declare

  contract.on("Transfer", cb); // 0ms

  await contract.transfer(...args); // 100ms
}) // contract variable scope is finished, it is cleared

As you can see your test case runs for such a small time, then moves to another test case. If you want to make that work, you might try waiting until the polling interval (also shortening the polling interval).

await new Promise(res => setTimeout(res, 4000)); // waits for 4 secs

However, to test events, I'd suggest to instead use an alternate method that doesn't need you to wait.

it('testcase', async() => {
  const tx = await contract.transfer(...args); // 100ms
  const rc = await tx.wait(); // 0ms, as tx is already confirmed
  const event = rc.events.find(event => event.event === 'Transfer');
  const [from, to, value] = event.args;
  console.log(from, to, value);
})

[trojanMcAfee]

Perfect explanation and workaround! Thanks @zemse

[kallolborah]

I am facing a problem with listening to events on a contract when using ganache-cli locally. Can anyone help ?

I have the listener code running on a local node

const ganache = require("ganache-cli");
const Oracle = require('./Oracle.json');
adminMnemonics = 'plate fame coffee life door noble panther virus grief real inherit episode';
const OracleAddress = '0x7532BdE4F81307e47daC1c054FF4f589ff4a8BEb';
const provider = new ethers.providers.Web3Provider(ganache.provider());

const aw = ethers.Wallet.fromMnemonic(adminMnemonics);
const admin = new ethers.Wallet(aw, provider);
const oracle = new ethers.Contract(OracleAddress, JSON.stringify(Oracle.abi), admin);

var app = express();

async function startListen() {
    console.log("Listening for events .....");
    oracle.on("NewRequest", (id, urlToQuery, attributeToFetch) => {
        console.log("Received oracle request " + id + " for " + urlToQuery + " with attribute " + attributeToFetch);        
        //callOracle(urlToQuery, id, attributeToFetch);
    });
}

And the event is generated from a truffle test. truffle test --show-events shows the event being generated, but the oracle.on in node app does not catch it. I also run ganache-cli blocktime 1, to ensure ganache mines blocks. But still nothing.

I am running
Ganache CLI v6.12.2 (ganache-core: 2.13.2)
Truffle v5.4.9 (core: 5.4.9)
Ethers v5.4.6
Node v14.15.3