Feature Activation Phased Testing on Testnet

[glevco]

This is a tracking issue to follow the Feature Activation Phase Testing. For more information, read the RFC.

[glevco]

After completing all required PRs to make the Phased Testing work, the process was correctly started. However, it was noticed that new blocks mined in the testnet were not signaling support for NOP_FEATURE_1, which was the intended behavior. We found out that the tx-mining-service, that is responsible for block mining in the testnet, also had to be updated to support signal bits, and it was not. Therefore, the initial trial of the whole process is considered failed, and it will have to be restarted.

[glevco]

To fix the issue found above, we had to make updates on hathor-core, python-hathorlib, and tx-mining-service:

• fix(feature-activation): add signal bits to minimally valid block #774
• fix(feature-activation): add missing signal bits on get_block_template python-hathorlib#32
• chore: update hathor-lib tx-mining-service#101

All those fixes have been merged and released.

[glevco]

New blocks mined for testnet are being correctly configured. Even though the process will be restarted for a full check of every evaluation interval, we can already see that it's working as expected.

Logs indicate that the full node is correctly starting with the intended feature support signals:

The state for each feature is also logged on new blocks, as described in the RFC:

Lastly, we can track the progress via the explorer:

And also visualize that blocks are indeed signaling:

[glevco]

We also noticed that the implementation of mandatory signaling described in the original RFC was missing.

It has been implemented and is under review in #785. The Phase Testing procedure will be restarted after this is merged and released.

[glevco]

The Phase Testing will be restarted with new NOP features, as defined in #879

[glevco]

Since the release of the full node version containing the new NOP features was a bit delayed, testnet blocks did not start signaling support right when the activation process started. Nevertheless, we released it 1-2 days after the start, with enough time to reach the configured threshold of 75%.

On block with height 3386879, in the Feature Activation panel of the explorer, we can see that there were no features under the activation process:

This is correct, as this is the block just before the start_height, which is 3386880.

We can also use this CloudWatch query to view the related logs:

fields @timestamp, @message
| sort @timestamp desc
| filter @message like 'height": 3386879'
| filter @logStream = 'testnet-golf-v0_58_0_rc4-20231221_release_candidate-cluster/node-scratch/eu-central-1-aaa612f6d80640c58d4efa1d9f945852'
| limit 100

And in the result we can see that the new NOP features are in the DEFINED state:

[glevco]

Then, on block at height 3386880, the process started but the block was not signaling support, as explained above:

And from the CloudWatch logs:

That happened at 12/7/2023 11:03:43 AM.

[glevco]

After a while, the threshold of 75% was passed for NOP_FEATURE_4:

NOP_FEATURE_5 is going to be activated by lock_in_on_timeout=True, and NOP_FEATURE_6 is going to be failed. That's why their acceptance is 0%.

Everything is working as expected, up to this point.

[glevco]

On block at height 3427199, we can check that the feature states are still STARTED. Then, on block at height 3427200, exactly 40320 blocks after the start_height, the features make their transitions:

From the logs:

This happened at 12/23/2023 5:08:25 AM. It's interesting to note that this is 16 days after the start of the process, instead of the expected 14 days. This is because the blocks are not being relayed consistently with 30 seconds apart.

[glevco]

At this time, the current best block is the one with height 3437279, from 12/26/2023 5:29:41 PM.

This is the current state:

There is one action point so far:

• Improve feature logging to include the block hash. It's possible to search logs with height, but using the hash is better and will be useful when we test on mainnet. Edit: done in chore(feature-activation): improve phased testing logs #905

[glevco]

Also, the MUST_SIGNAL phase started for NOP_FEATURE_5 on Dec 23rd, and today we've reached 25% of non-signaling blocks. We should have prepared a deploy for the tx-mining-service node with support enabled for this feature.

By human error, this wasn't done in time, so all blocks are being rejected in testnet since 17:29 BRT (the block linked above is the last one). At this time, we're already deploying a new node to fix this, with the support option enabled for this feature. Here are the tx-mining-service logs showing the last block that was found, and the stalling after that:

Nonetheless, this correctly tested the mandatory signaling behavior. Blocks that fail to signal support after 1-threshold non-signaling blocks must be rejected. Here's the error when trying to push such block, on my local node connected to the testnet:

So, the Feature Activation process is working as expected, up to this point.

[glevco]

Another action point, as suggested by @jansegre:

• Add the ability to edit feature support signals through sysctl, so we don't have to restart the full node to do this (done in feat(feature-activation): implement bit signaling sysctl #962).

[glevco]

Block mining has been restored. Here's the signaling on the most recent block:

And the acceptance for NOP_FEATURE_5 on MUST_SIGNAL is climbing:

[glevco]

Another action point suggested by @jansegre as an UX improvement:

• For updated nodes, when a feature reaches MUST_SIGNAL, the node should signal support by default, unless explicitly disabled by the node operator. Maybe we could have some ternary config, like "always-signal", "whatever-works", and "never-signal" (done in feat(feature-activation): automatically enable support in MUST_SIGNAL #963).

[glevco]

Today another Evaluation Interval block was reached, and the Feature Activation states advanced accordingly and correctly.

Here's the complete features table from the explorer:

We can see that NOP_FEATURE_6 failed, as expected. NOP_FEATURE_4's state didn't change, as its minimum activation height hasn't been reached yet, and NOP_FEATURE_5 transitioned from MUST_SIGNAL to LOCKED_IN.

Here's the signaling in the current best block:

Where we can confirm the same states.

And lastly, from the logs:

Then, in the next transition (~two weeks from now), we should see features 4 and 5 transitioning to ACTIVE.

[glevco]

The testnet Phased Testing has completed yesterday. Features 4 and 5 have transitioned to ACTIVE, as expected, generating logs that are displayed conditionally on those features, meaning that the process is fully working and ready to be tested on mainnet.

Here's the current state from the explorer:

And the moment the features transitioned, from block 3507839 to 3507840, activating the logs:

[glevco]

Reviewers: @msbrogli @jansegre

[glevco]

Closing this as the process is already up and running on mainnet.