Mismatched Operation IDs in Governance Flow: TimelockUnexpectedOperationState Error

Support Contracts
1

I am relatively new to smart contract development and am currently working on implementing a governance system using OpenZeppelin's contracts. (I test on a local HardHat node).

My contracts, MyToken and MyGovernor are from https://docs.openzeppelin.com/contracts/5.x/governance#governor

Objective:
I'm implementing a smart contract governance system using OpenZeppelin's contracts. The workflow includes creating proposals with MyGovernor contract, scheduling operations in TimelockController , and then executing these operations post-voting.

Problem:
The main issue arises during the execution stage. I'm facing a TimelockUnexpectedOperationState error. This error seems to be triggered by an inconsistency in the operation IDs between the scheduling and execution phases.

Detailed Steps and Observations:

  1. Proposal Creation: Successfully created a proposal with the MyGovernor contract.
  2. Operation Scheduling: Scheduled the operation in TimelockController using scheduleBatch. The operation successfully entered the pending state.
  3. Voting and Queuing: Completed the voting process and queued the proposal in MyGovernor.
  4. Execution Attempt: Encountered the TimelockUnexpectedOperationState error when trying to execute the operation with execute . The error references an operation ID different from the one I've been tracking.

The error itself:
Error: VM Exception while processing transaction: reverted with custom error 'TimelockUnexpectedOperationState("0x0f074607eabfa02e41554a483f284c975246cd60414b6be3ed139fe2df1fcfd6", "0x0000000000000000000000000000000000000000000000000000000000000004")' at TimelockController.updateDelay (@openzeppelin/contracts/governance/TimelockController.sol:452) at TimelockController.executeBatch (@openzeppelin/contracts/governance/TimelockController.sol:398) at MyGovernor._executeOperations (@openzeppelin/contracts/governance/extensions/GovernorTimelockControl.sol:111) at MyGovernor._executeOperations (contracts/MyGovernor.sol:83) at MyGovernor.execute (@openzeppelin/contracts/governance/Governor.sol:418) at processTicksAndRejections (node:internal/process/task_queues:95:5) at runNextTicks (node:internal/process/task_queues:64:3) at listOnTimeout (node:internal/timers:533:9) at processTimers (node:internal/timers:507:7) at async HardhatNode._mineBlockWithPendingTxs1

The logs:
Operation ID: Promise {
'0xe9a0b217bae1e6321753629f67a3d5d370e40f7f153de2642c50d0899a607829'
}
Current state of proposal before voting: 1
Votes have been cast
Current state of proposal: 4
Operation ready: true
Operation status: Pending - true, Ready - true
timestamp : 1706882895
State of the proposal: 5

Upon examining the logs and error messages closely, I've noticed a discrepancy between the operation IDs. The operation ID logged during my process is 0xe9a0b217bae1e6321753629f67a3d5d370e40f7f153de2642c50d0899a607829, yet the error message references a completely different operation ID: 0x0f074607eabfa02e41554a483f284c975246cd60414b6be3ed139fe2df1fcfd6. This mismatch seems to be at the crux of the TimelockUnexpectedOperationState error I'm encountering.

It appears that this discrepancy in operation IDs between the scheduled task and the executed task in the TimelockController is causing the workflow to fail. Any insights into why these IDs are different, would be greatly appreciated.

The error occurs at
const executeTx = await myGovernor .connect(deployer) .execute(targets, values, calldatas, descriptionHash); await executeTx.wait();

I am using the same values to get the operation ID and to schedule the operation:
const operationId = await timelock.hashOperationBatch( targets, values, calldatas, ethers.constants.HashZero, salt );

await timelock.scheduleBatch( targets, values, calldatas, ethers.constants.HashZero, salt, minDelay );

I hope this information clearly outlines the issues I'm encountering. Thank you in advance for your time and assistance. If you need any further information, please leave a comment.

2

The TimelockUnexpectedOperationState error indicates in its natspec that the other value indicates the expected status of the operation. In this case, the operation 0x0f074607eabfa02e41554a483f284c975246cd60414b6be3ed139fe2df1fcfd6 needs to be in Ready state (0b0100 == 0x...04).

Any insights into why these IDs are different, would be greatly appreciated.

Unfortunately, it's unclear what ids are comparing. I'd advise to note that the operationId is never the same for the timelock and the governor. The governor queues a proposal into the timelock, and each id is calculated on its own instance (i.e. in Timelock and in GovernorTimelockControl).

Will be helpful if you share your code and summarize your explanation in a single question.

My suspicious is that you're running a script and you're executing the proposal before the Timelock delay has passed, thus its state may be just OperationState.Waiting.

3

It's not really a question; I'm somewhat confused and unsure about what mistake I might be making that causes me this error. I don't really understand why my logs say it's ready, but the error seems to say otherwise. I'm not sure if it's possible to create a script with a minimum delay of 10 seconds, but my main goal is to understand how the Governor and Timelock work.

Apologies if the code is not very clean; I am experimenting, which is why it may appear as such.

Here is my script

async function main() {
  const [deployer, proposer, voter1, voter2, voter3] =
    await ethers.getSigners();

  console.log("Deployer address:", deployer.address);

  // Deploy MyToken
  const MyToken = await ethers.getContractFactory("MyToken");
  const myToken = await MyToken.deploy();
  await myToken.deployed();
  console.log("MyToken deployed to:", myToken.address);

  // Mint tokens to deployer
  const initialMintAmount = ethers.utils.parseEther("10000");
  await myToken.mint(deployer.address, initialMintAmount);

  // Deploy TimelockController
  const Timelock = await ethers.getContractFactory("TimelockController");
  const minDelay = 10;
  const proposers = [proposer.address];
  const executors = [deployer.address];
  const admin = deployer.address;
  const timelock = await Timelock.deploy(minDelay, proposers, executors, admin);
  await timelock.deployed();
  await myToken.mint(timelock.address, initialMintAmount);
  console.log(`TimelockController deployed to: ${timelock.address}`);

  // Deploy MyGovernor
  const MyGovernor = await ethers.getContractFactory("MyGovernor");
  const myGovernor = await MyGovernor.deploy(myToken.address, timelock.address);
  await myGovernor.deployed();
  console.log("MyGovernor deployed to:", myGovernor.address);
  await myToken.mint(myGovernor.address, initialMintAmount);

  const PROPOSER_ROLE = await timelock.PROPOSER_ROLE();
  await timelock.grantRole(PROPOSER_ROLE, myGovernor.address);
  await timelock.grantRole(PROPOSER_ROLE, deployer.address);

  const EXECUTOR_ROLE = await timelock.EXECUTOR_ROLE();
  await timelock.grantRole(EXECUTOR_ROLE, myGovernor.address);

  // Distribute tokens and delegate
  const distributeAndDelegate = async (voter) => {
    await myToken.transfer(voter.address, ethers.utils.parseEther("1000"));
    await myToken.connect(voter).delegate(voter.address);
  };

  await distributeAndDelegate(proposer);
  await distributeAndDelegate(voter1);
  await distributeAndDelegate(voter2);
  await distributeAndDelegate(voter3);

  const teamAddress = "0xbDA5747bFD65F08deb54cb465eB87D40e51B197E";
  const targets = [myToken.address];
  const values = [0]; // No ether is being sent for this call
  const calldatas = [
    myToken.interface.encodeFunctionData("transfer", [teamAddress, 0]),
  ];

  const description = "Simple Proposal: Set new state value";
  const descriptionHash = ethers.utils.id(description);

  const salt =
    "0x025e7b0be353a74631ad648c667493c0e1cd31caa4cc2d3520fdc171ea0cc726"; // a random value

  const createTx = await myGovernor
    .connect(proposer)
    .propose(targets, values, calldatas, description);
  const createReceipt = await createTx.wait();

  const proposalId = createReceipt.events?.find(
    (e: Event) => e.event === "ProposalCreated"
  )?.args?.proposalId;

  console.log(`Proposal created with ID: ${proposalId}`);
  console.log("\n");

  const operationId = await timelock.hashOperationBatch(
    targets,
    values,
    calldatas,
    ethers.constants.HashZero,
    salt
  );

  await timelock.scheduleBatch(
    targets,
    values,
    calldatas,
    ethers.constants.HashZero,
    salt,
    minDelay
  );
  console.log("Operation scheduled in TimelockController");
  console.log(
    "timestamp : " +
      convertTimestampToReadableDate(await timelock.getTimestamp(operationId))
  );
  console.log(
    `Is Operation Waiting: ${await timelock.isOperationPending(operationId)}`
  );
  console.log(
    `Is Operation Ready: ${await timelock.isOperationReady(operationId)}`
  );
  let state = await myGovernor.state(proposalId);
  console.log(`Current state of proposal before voting: ${state}`);
  console.log("\n");

  // Wait for the voting delay
  const votingDelayBlocks = 10000;
  for (let i = 0; i < votingDelayBlocks; i++) {
    await ethers.provider.send("evm_mine", []);
  }

  // Check proposal state before voting
  state = await myGovernor.state(proposalId);
  console.log(`Current state of proposal before voting: ${state}`);

  if (state === 1 /* 1 = Active */) {
    await myGovernor.connect(voter1).castVote(proposalId, 1); // 1 for 'For'
    await myGovernor.connect(voter2).castVote(proposalId, 0); // 0 for 'Against'
    await myGovernor.connect(voter3).castVote(proposalId, 1); // 1 for 'For'
    console.log("Votes have been cast");
  } else {
    console.log("Proposal not in active state, cannot vote");
  }

  // Wait for the voting delay
  const votingDelayBlockss = 70000;
  for (let i = 0; i < votingDelayBlockss; i++) {
    await ethers.provider.send("evm_mine", []);
  }

  // Check proposal state after voting and time delay
  const stateAfterVoting = await myGovernor.state(proposalId);
  console.log(`Current state of proposal: ${stateAfterVoting}`);
  console.log("\n")


  if (stateAfterVoting === 4 /* 4 = Succeeded */) {
    const isPending = await timelock.isOperationPending(operationId);
    const isReady = await timelock.isOperationReady(operationId);

    console.log(`Operation status: Waiting - ${isPending}, Ready - ${isReady}`);
    console.log(
      "timestamp : " +
        convertTimestampToReadableDate(await timelock.getTimestamp(operationId))
    );
    console.log("Current time:", new Date().toISOString());
    const queueTx = await myGovernor.queue(
      targets,
      values,
      calldatas,
      descriptionHash
    );
    await queueTx.wait();
    const States = await myGovernor.state(proposalId);

    console.log("Queued the proposal")
    console.log(`State of the proposal: ${States}`);
    console.log("\n");

    const executeTx = await myGovernor
      .connect(deployer)
      .execute(targets, values, calldatas, descriptionHash);

    await executeTx.wait();

    const finalState = await myGovernor.state(proposalId);
    console.log(`Final state of the proposal: ${finalState}`);
  } else {
    console.log(
      `Proposal not in executable state. Current state: ${stateAfterVoting}`
    );
  }
}

Here are the logs:

Proposal created with ID: 101446016097254637703468876547213566555737649677309002580315613022853321153606


Operation scheduled in TimelockController
timestamp : 2024-02-02T12:52:33.000Z
Is Operation Waiting: true
Is Operation Ready: false
Current state of proposal before voting: 0


Current state of proposal before voting: 1
Votes have been cast
Current state of proposal: 4


Operation status: Waiting - true, Ready - true
timestamp : 2024-02-02T12:52:33.000Z
Current time: 2024-02-02T12:52:40.992Z
Queued the proposal
State of the proposal: 5

Error: VM Exception while processing transaction: reverted with custom error 'TimelockUnexpectedOperationState("0x5764d749d9a1f4cb81a063fc40258662329ee7c2edadba4b3763e7b8815197cd", "0x0000000000000000000000000000000000000000000000000000000000000004")'
4

This suggests that your transaction reverts here:

_executeOperations(proposalId, targets, values, calldatas, descriptionHash);

Looking into this function, we can see that it may revert in either one of these two lines:

(bool success, bytes memory returndata) = targets[i].call{value: values[i]}(calldatas[i]);
Address.verifyCallResult(success, returndata);

The first line attempts to execute the input byte-code, which in your script above is given by:

const teamAddress = "0xbDA5747bFD65F08deb54cb465eB87D40e51B197E";
const targets = [myToken.address];
const values = [0]; // No ether is being sent for this call
const calldatas = [
  myToken.interface.encodeFunctionData("transfer", [teamAddress, 0]),
];

My suggestion here is to first check whether or not you can execute that directly with your externally-owned account.
If you cannot do this, then there's obviously an issue there.
If you can do this, then either there's an issue with it being executed via the Governor smart-contract account, or there's no problem in this line, in which case, the problem is in the next line.
However, the next line merely asserts the success of the previous line, so in short - the first place I'd start my investigation at (if I were you), is the ability to execute that transfer.
For example - perhaps you need to first make sure that the contract's balance in your token is sufficiently high for that specific transfer to complete successfully.

5

The operation shows in Waiting status as expected. You need to either wait for the proposal delay or use a helper to advance time.

Since you're using Hardhat, I recommend you using @nomicfoundation/hardhat-network-helpers to manipulate the block time:

For a reference usage, check out the openzeppelin-contracts tests. You should do something like:

await time.latest().then(timestamp => time.increaseTo(timestamp + delay));

Note delay is defined by your application.

6

So, should I remove this code and use something like this instead?: await time.latest().then(timestamp => time.increaseTo(timestamp + delay));
Because when I remove it and add that line, the logs show:

Operation scheduled in TimelockController
timestamp : 2024-02-03T10:40:43.000Z
Is Operation Waiting: true
Is Operation Ready: false
Current state of proposal before voting: 0


Initial block number: 20
2024-02-03T10:40:33.000Z
Final block number: 21
timestamp : 2024-02-04T16:40:33.000Z
Current state of proposal before voting: 0
Is Operation Ready: true

I've even set the delay higher const delay = 7200 * 15; while the voting delay is only 1 day.
It appears the voting delay is not met, yet when I utilize the for loop, it is met.
I also created a script without the Timelock, and it works perfectly

7 
// Wait for the voting delay
  const votingDelayBlocks = 10000;
  for (let i = 0; i < votingDelayBlocks; i++) {
    await ethers.provider.send("evm_mine", []);
  }

Well, you can force the timestamp by mining N blocks until it's met. But I think it's better if you use the official helpers for that.

So, should I remove this code and use something like this instead?: await time.latest().then(timestamp => time.increaseTo(timestamp + delay));

I think using a "native" tested implementation is recommended. Seems like it doesn't work because is setting the next block to proposal.timestamp == block.timestamp while the Timelock expect's proposal.timestamp > block.timestamp..

Just add 1.