Fail starting after upgrade to 24.3.3 due to Invalid metadata file

[onemoz]

Description

After an update from 24.3.1 to 24.3.3, Besu fails to start with Invalid metadata file /ethclient/besu/DATABASE_METADATA.json:

rocketpool_eth1  | 2024-04-15 13:43:24.744+00:00 | main | INFO  | DatabaseMetadata | Lookup database metadata file in data directory: /ethclient/besu
rocketpool_eth1  | 2024-04-15 13:43:24.755+00:00 | main | ERROR | Besu | Failed to start Besu
rocketpool_eth1  | picocli.CommandLine$ExecutionException: Invalid metadata file /ethclient/besu/DATABASE_METADATA.json
rocketpool_eth1  | 	at org.hyperledger.besu.cli.BesuCommand.buildController(BesuCommand.java:1777)
rocketpool_eth1  | 	at org.hyperledger.besu.cli.BesuCommand.run(BesuCommand.java:1096)
rocketpool_eth1  | 	at picocli.CommandLine.executeUserObject(CommandLine.java:2026)
rocketpool_eth1  | 	at picocli.CommandLine.access$1500(CommandLine.java:148)
rocketpool_eth1  | 	at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2461)
rocketpool_eth1  | 	at picocli.CommandLine$RunLast.handle(CommandLine.java:2453)
rocketpool_eth1  | 	at picocli.CommandLine$RunLast.handle(CommandLine.java:2415)
rocketpool_eth1  | 	at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2273)
rocketpool_eth1  | 	at picocli.CommandLine$RunLast.execute(CommandLine.java:2417)
rocketpool_eth1  | 	at picocli.CommandLine.execute(CommandLine.java:2170)
rocketpool_eth1  | 	at org.hyperledger.besu.cli.util.ConfigOptionSearchAndRunHandler.handle(ConfigOptionSearchAndRunHandler.java:66)
rocketpool_eth1  | 	at org.hyperledger.besu.cli.util.ConfigOptionSearchAndRunHandler.handle(ConfigOptionSearchAndRunHandler.java:33)
rocketpool_eth1  | 	at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2273)
rocketpool_eth1  | 	at picocli.CommandLine$RunLast.execute(CommandLine.java:2417)
rocketpool_eth1  | 	at picocli.CommandLine.execute(CommandLine.java:2170)
rocketpool_eth1  | 	at org.hyperledger.besu.cli.BesuCommand.parse(BesuCommand.java:1261)
rocketpool_eth1  | 	at org.hyperledger.besu.cli.BesuCommand.parse(BesuCommand.java:1051)
rocketpool_eth1  | 	at org.hyperledger.besu.Besu.main(Besu.java:39)
rocketpool_eth1  | Caused by: java.lang.IllegalStateException: Invalid metadata file /ethclient/besu/DATABASE_METADATA.json
rocketpool_eth1  | 	at org.hyperledger.besu.plugin.services.storage.rocksdb.configuration.DatabaseMetadata.resolveDatabaseMetadata(DatabaseMetadata.java:157)
rocketpool_eth1  | 	at org.hyperledger.besu.plugin.services.storage.rocksdb.configuration.DatabaseMetadata.lookUpFrom(DatabaseMetadata.java:122)
rocketpool_eth1  | 	at org.hyperledger.besu.plugin.services.storage.rocksdb.RocksDBKeyValueStorageFactory.readDatabaseVersion(RocksDBKeyValueStorageFactory.java:260)
rocketpool_eth1  | 	at org.hyperledger.besu.plugin.services.storage.rocksdb.RocksDBKeyValueStorageFactory.init(RocksDBKeyValueStorageFactory.java:236)
rocketpool_eth1  | 	at org.hyperledger.besu.plugin.services.storage.rocksdb.RocksDBKeyValueStorageFactory.create(RocksDBKeyValueStorageFactory.java:172)
rocketpool_eth1  | 	at org.hyperledger.besu.ethereum.storage.keyvalue.KeyValueStorageProviderBuilder.lambda$build$0(KeyValueStorageProviderBuilder.java:62)
rocketpool_eth1  | 	at java.base/java.util.HashMap.computeIfAbsent(HashMap.java:1220)
rocketpool_eth1  | 	at org.hyperledger.besu.ethereum.storage.keyvalue.KeyValueStorageProvider.getStorageBySegmentIdentifier(KeyValueStorageProvider.java:97)
rocketpool_eth1  | 	at org.hyperledger.besu.ethereum.storage.keyvalue.KeyValueStorageProvider.createVariablesStorage(KeyValueStorageProvider.java:66)
rocketpool_eth1  | 	at org.hyperledger.besu.controller.BesuControllerBuilder.build(BesuControllerBuilder.java:589)
rocketpool_eth1  | 	at org.hyperledger.besu.controller.TransitionBesuControllerBuilder.build(TransitionBesuControllerBuilder.java:295)
rocketpool_eth1  | 	at org.hyperledger.besu.cli.BesuCommand.buildController(BesuCommand.java:1775)
rocketpool_eth1  | 	... 17 more
rocketpool_eth1  | Caused by: com.fasterxml.jackson.databind.exc.UnrecognizedPropertyException: Unrecognized field "v2" (class org.hyperledger.besu.plugin.services.storage.rocksdb.configuration.DatabaseMetadata), not marked as ignorable (2 known properties: "version", "privacyVersion"])
rocketpool_eth1  |  at [Source: REDACTED (`StreamReadFeature.INCLUDE_SOURCE_IN_LOCATION` disabled); line: 6, column: 2] (through reference chain: org.hyperledger.besu.plugin.services.storage.rocksdb.configuration.DatabaseMetadata["v2"])
rocketpool_eth1  | 	at com.fasterxml.jackson.databind.exc.UnrecognizedPropertyException.from(UnrecognizedPropertyException.java:61)
rocketpool_eth1  | 	at com.fasterxml.jackson.databind.DeserializationContext.handleUnknownProperty(DeserializationContext.java:1153)
rocketpool_eth1  | 	at com.fasterxml.jackson.databind.deser.std.StdDeserializer.handleUnknownProperty(StdDeserializer.java:2224)
rocketpool_eth1  | 	at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.handleUnknownProperty(BeanDeserializerBase.java:1793)
rocketpool_eth1  | 	at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.handleUnknownProperties(BeanDeserializerBase.java:1743)
rocketpool_eth1  | 	at com.fasterxml.jackson.databind.deser.BeanDeserializer._deserializeUsingPropertyBased(BeanDeserializer.java:546)
rocketpool_eth1  | 	at com.fasterxml.jackson.databind.deser.BeanDeserializerBase.deserializeFromObjectUsingNonDefault(BeanDeserializerBase.java:1493)
rocketpool_eth1  | 	at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserializeFromObject(BeanDeserializer.java:348)
rocketpool_eth1  | 	at com.fasterxml.jackson.databind.deser.BeanDeserializer.deserialize(BeanDeserializer.java:185)
rocketpool_eth1  | 	at com.fasterxml.jackson.databind.deser.DefaultDeserializationContext.readRootValue(DefaultDeserializationContext.java:342)
rocketpool_eth1  | 	at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:4899)
rocketpool_eth1  | 	at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3711)
rocketpool_eth1  | 	at org.hyperledger.besu.plugin.services.storage.rocksdb.configuration.DatabaseMetadata.resolveDatabaseMetadata(DatabaseMetadata.java:152)
rocketpool_eth1  | 	... 28 more
rocketpool_eth1  | Invalid metadata file /ethclient/besu/DATABASE_METADATA.json
rocketpool_eth1  |
rocketpool_eth1  | To display full help:
rocketpool_eth1  | besu [COMMAND] --help

The content of the file is

{
  "v2" : {
    "format" : "BONSAI",
    "version" : 2
  }
}

Which seems related to #6555

This issue has been hitting couple of people (at least in the rocket pool community, 3 or 4 people had this issue).
Doing a resync did fix the issue in their case, and the content of their DATABASE_METADATA.json became

{"version":2}

I tried to backup my old DATABASE_METADATA.json and copy this content inside and start with 24.3.3, but that didn't work, Besu still fails starting with the same error message.

When I rollback to Besu 24.3.1 and the old metadata file, this keeps working.

Expected behavior: Keep working after the upgrade to 24.3.3

Actual behavior: Besu doesn't start anymore

**Expected from the Besu team:

• The list of modification I need to do on the metadata file so I can upgrade to 24.3.3
• Would be nice to find a way for Besu to gracefully handle this use case or to automatically migrate metadata file to the good format

Thank you in advance!

[ahamlat]

Hi @onemoz,
I upgraded from 24.3.0 to 24.3.3 and couldn't reproduce the issue. Did you mean that you had the issue when you downgraded from 23.3.3 to 23.3.1

On my side, when I downgrade from a higher version to a lower one, I have this first error message, which is expected
"Besu version 24.3.0 is lower than version 24.4 that last started. Remove --version-compatibility-protection option to allow Besu to start at the lower version (warning - this may have unrecoverable effects on the database).","throwable":""}

Then I restart with --version-compatibility-protection=false and I have a second error message, that is expected as well :

{"@timestamp":"2024-04-29T12:53:06,272","level":"ERROR","thread":"main","class":"Besu","message":"Failed to start Besu",
"throwable":" picocli.CommandLine$ExecutionException: Invalid metadata file /data/besu/DATABASE_METADATA.json\n\tat 
org.hyperledger.besu.cli.BesuCommand.buildController(BesuCommand.java:1777)\n .... 

As explained in #6555, to downgrade, you need to execute this subcommand storage revert-metadata v2-to-v1 to change the DATABASE_METADATA.json file :

sudo [besu_binaries/path]/bin/besu --data-path=/data/besu storage revert-metadata v2-to-v1
2024-04-29 13:03:00.608+00:00 | main | INFO  | RevertMetadataSubCommand | Successfully reverted database metadata from v2 to v1 in /data/besu/DATABASE_METADATA.json 

This subcommand changes DATABASE_METADATA.json content from

{
  "v2" : {
    "format" : "BONSAI",
    "version" : 2
  }
}

to

{
  "version" : 2
}

If you changed it manually, it should work as well, but you need to restart besu. Are you sure you changed the one that is inside besu data folder directory (--data-path parameter value) ?

[onemoz]

Thank @ahamlat for your prompt answer!!

I upgraded from 24.3.0 to 24.3.3 and couldn't reproduce the issue. Did you mean that you had the issue when you downgraded from 23.3.3 to 23.3.1

I never had an issue when downgrading from 24.3.3 to 24.3.1. I was running 24.3.1 without issue, I then used the docker image 24.3.3, this shows the error describe in the issue and then because it was failing I went back to use 24.3.1, and it keeps working.

So 24.3.1 always worked in my case. Only 24.3.3 was failing.

I could run the command to revert the database version from v2 to v1:

root@2ebf98cd5810:/ethclient/besu# besu --data-path=/ethclient/besu/ storage  revert-metadata v2-to-v1
2024-04-29 13:27:17.923+00:00 | main | INFO  | RevertMetadataSubCommand | Successfully reverted database metadata from v2 to v1 in /ethclient/besu/DATABASE_METADATA.json

Which indeed changed the file to the expected value.

Then upgraded to the 24.3.3 version, and that's working now!

rocketpool_eth1  | 2024-04-29 13:28:08.167+00:00 | main | INFO  | Runner | Ethereum main loop is up.

Thanks a lot for helping me fixing this :)

Is this expected the 24.3.3 doesn't support v2 of the metadata file?

[ahamlat]

Thanks for the update @onemoz.
24.3.3 is working fine with v2, I just did the the test. Besu was able to restart without any issue with this DATABASE_METADATA.json

{
  "version" : 2
}

[onemoz]

Ha yes, sorry I assumed wrongly the medatada format one v1 and v2, when both are v2.

Thanks a lot for your help!

[ahamlat]

I'm going to close this issue then and you can re-open if you notice any unexpected behaviour.

[siladu]

FYI, our discord announcement last month should give some context about what happened here:

Hi everyone - some announcements on the Besu release confusion with version 24.4.0:
We recently changed our build / release processes, so we are ironing out some hiccups. The 24.3.1 release you may have > seen is not-official and should not be used. it was generated as an artifacting bug and can be safely ignored.

Unfortunately, some users updated to the bad 24.3.1 release, mostly via RocketPool. We had already deleted it from the github releases page before we realised this which might be adding to the confusion here.

[onemoz]

FYI, our discord announcement last month should give some context about what happened here:

Thanks! This explains everything. My bad for not joining the besu discord and look for the information there (I find discord harder/messier to search into for this kind of problem compare to github issues or regular documentation).

[siladu]

FYI, our discord announcement last month should give some context about what happened here:

Thanks! This explains everything. My bad for not joining the besu discord and look for the information there (I find discord harder/messier to search into for this kind of problem compare to github issues or regular documentation).

@onemoz It was definitely our bad for the release mishap!
Will make sure it's clear in the release notes too.