web3signer: web3signer block proposal fails on pre-Bellatrix mainnet

With 22.8.1 and 22.8.0. 22.6.0 works.

Antares will be along shortly with more details no doubt 😃

{"log":"time=\"2022-08-26 08:28:59\" level=error msg=\"Failed to sign block\" error=\"could not sign block proposal: http: ContentLength=81281 with Body length 0\" prefix=validator pubKey=0xb12244f67aa9\n","stream":"stderr","time":"2022-08-26T08:28:59.535916835Z"}
{"log":"\u0009at java.lang.Thread.run(Unknown Source) ~[?:?]\n","stream":"stdout","time":"2022-08-26T08:28:59.535391133Z"}
{"log":"\u0009at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]\n","stream":"stdout","time":"2022-08-26T08:28:59.53538729Z"}
{"log":"\u0009at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[?:?]\n","stream":"stdout","time":"2022-08-26T08:28:59.535383744Z"}
{"log":"\u0009at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[?:?]\n","stream":"stdout","time":"2022-08-26T08:28:59.53538025Z"}
{"log":"\u0009at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157) ~[vertx-core-4.3.1.jar:4.3.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.53537658Z"}
{"log":"\u0009at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:101) ~[vertx-core-4.3.1.jar:4.3.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535372803Z"}
{"log":"\u0009at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159) ~[vertx-core-4.3.1.jar:4.3.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.53536882Z"}
{"log":"\u0009at io.vertx.ext.web.impl.BlockingHandlerDecorator.lambda$handle$0(BlockingHandlerDecorator.java:48) ~[vertx-web-4.3.1.jar:4.3.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535351231Z"}
{"log":"\u0009at tech.pegasys.web3signer.core.service.http.handlers.signing.eth2.Eth2SignForIdentifierHandler.handle(Eth2SignForIdentifierHandler.java:58) ~[web3signer-core-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535346757Z"}
{"log":"\u0009at tech.pegasys.web3signer.core.service.http.handlers.signing.eth2.Eth2SignForIdentifierHandler.handle(Eth2SignForIdentifierHandler.java:103) ~[web3signer-core-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.53534295Z"}
{"log":"\u0009at tech.pegasys.web3signer.core.service.http.handlers.signing.eth2.Eth2SignForIdentifierHandler.computeSigningRoot(Eth2SignForIdentifierHandler.java:249) ~[web3signer-core-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535338919Z"}
{"log":"\u0009at tech.pegasys.teku.api.schema.altair.BeaconBlockAltair.asInternalBeaconBlock(BeaconBlockAltair.java:49) ~[serializer-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535335142Z"}
{"log":"\u0009at tech.pegasys.teku.api.schema.BeaconBlockBody.asInternalBeaconBlockBody(BeaconBlockBody.java:139) ~[serializer-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535331444Z"}
{"log":"\u0009at tech.pegasys.teku.api.schema.altair.BeaconBlockBodyAltair.asInternalBeaconBlockBody(BeaconBlockBodyAltair.java:85) ~[serializer-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.53532776Z"}
{"log":"\u0009at tech.pegasys.teku.api.schema.BeaconBlockBody.asInternalBeaconBlockBody(BeaconBlockBody.java:95) ~[serializer-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.5353241Z"}
{"log":"\u0009at tech.pegasys.teku.spec.datastructures.blocks.blockbody.versions.bellatrix.BeaconBlockBodySchemaBellatrixImpl.createBlockBody(BeaconBlockBodySchemaBellatrixImpl.java:125) ~[spec-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535320188Z"}
{"log":"\u0009at tech.pegasys.teku.spec.datastructures.blocks.blockbody.versions.bellatrix.BeaconBlockBodyBuilderBellatrix.build(BeaconBlockBodyBuilderBellatrix.java:93) ~[spec-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535316027Z"}
{"log":"\u0009at tech.pegasys.teku.spec.datastructures.blocks.blockbody.versions.bellatrix.BeaconBlockBodyBuilderBellatrix.validate(BeaconBlockBodyBuilderBellatrix.java:79) ~[spec-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535311668Z"}
{"log":"\u0009at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:907) ~[guava-31.0.1-jre.jar:?]\n","stream":"stdout","time":"2022-08-26T08:28:59.535307591Z"}
{"log":"java.lang.NullPointerException: executionPayload must be specified\n","stream":"stdout","time":"2022-08-26T08:28:59.53530199Z"}
{"log":"2022-08-26 08:28:59.534+00:00 | vert.x-eventloop-thread-0 | ERROR | RoutingContext | Unhandled exception in router\n","stream":"stdout","time":"2022-08-26T08:28:59.535268562Z"}
{"log":"\u0009at java.lang.Thread.run(Unknown Source) ~[?:?]\n","stream":"stdout","time":"2022-08-26T08:28:59.535118656Z"}
{"log":"\u0009at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]\n","stream":"stdout","time":"2022-08-26T08:28:59.535114873Z"}
{"log":"\u0009at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[?:?]\n","stream":"stdout","time":"2022-08-26T08:28:59.535111308Z"}
{"log":"\u0009at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[?:?]\n","stream":"stdout","time":"2022-08-26T08:28:59.535107683Z"}
{"log":"\u0009at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157) ~[vertx-core-4.3.1.jar:4.3.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535101116Z"}
{"log":"\u0009at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:101) ~[vertx-core-4.3.1.jar:4.3.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535097082Z"}
{"log":"\u0009at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159) ~[vertx-core-4.3.1.jar:4.3.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535072966Z"}
{"log":"\u0009at io.vertx.ext.web.impl.BlockingHandlerDecorator.lambda$handle$0(BlockingHandlerDecorator.java:48) ~[vertx-web-4.3.1.jar:4.3.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535068624Z"}
{"log":"\u0009at tech.pegasys.web3signer.core.service.http.handlers.signing.eth2.Eth2SignForIdentifierHandler.handle(Eth2SignForIdentifierHandler.java:58) ~[web3signer-core-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535064092Z"}
{"log":"\u0009at tech.pegasys.web3signer.core.service.http.handlers.signing.eth2.Eth2SignForIdentifierHandler.handle(Eth2SignForIdentifierHandler.java:103) ~[web3signer-core-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535058895Z"}
{"log":"\u0009at tech.pegasys.web3signer.core.service.http.handlers.signing.eth2.Eth2SignForIdentifierHandler.computeSigningRoot(Eth2SignForIdentifierHandler.java:249) ~[web3signer-core-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535054358Z"}
{"log":"\u0009at tech.pegasys.teku.api.schema.altair.BeaconBlockAltair.asInternalBeaconBlock(BeaconBlockAltair.java:49) ~[serializer-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535050014Z"}
{"log":"\u0009at tech.pegasys.teku.api.schema.BeaconBlockBody.asInternalBeaconBlockBody(BeaconBlockBody.java:139) ~[serializer-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535045701Z"}
{"log":"\u0009at tech.pegasys.teku.api.schema.altair.BeaconBlockBodyAltair.asInternalBeaconBlockBody(BeaconBlockBodyAltair.java:85) ~[serializer-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535041348Z"}
{"log":"\u0009at tech.pegasys.teku.api.schema.BeaconBlockBody.asInternalBeaconBlockBody(BeaconBlockBody.java:95) ~[serializer-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535036913Z"}
{"log":"\u0009at tech.pegasys.teku.spec.datastructures.blocks.blockbody.versions.bellatrix.BeaconBlockBodySchemaBellatrixImpl.createBlockBody(BeaconBlockBodySchemaBellatrixImpl.java:125) ~[spec-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535032179Z"}
{"log":"\u0009at tech.pegasys.teku.spec.datastructures.blocks.blockbody.versions.bellatrix.BeaconBlockBodyBuilderBellatrix.build(BeaconBlockBodyBuilderBellatrix.java:93) ~[spec-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535027371Z"}
{"log":"\u0009at tech.pegasys.teku.spec.datastructures.blocks.blockbody.versions.bellatrix.BeaconBlockBodyBuilderBellatrix.validate(BeaconBlockBodyBuilderBellatrix.java:79) ~[spec-22.8.1.jar:22.8.1]\n","stream":"stdout","time":"2022-08-26T08:28:59.535022496Z"}
{"log":"\u0009at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:907) ~[guava-31.0.1-jre.jar:?]\n","stream":"stdout","time":"2022-08-26T08:28:59.535017408Z"}
{"log":"java.lang.NullPointerException: executionPayload must be specified\n","stream":"stdout","time":"2022-08-26T08:28:59.535011554Z"}
{"log":"2022-08-26 08:28:59.533+00:00 | vert.x-eventloop-thread-0 | ERROR | LogErrorHandler | Failed request: http://web3signer:6174/api/v1/eth2/sign/0xb12244f67aa9e872a770e659ecaf94fb06157cc8d04c644e65c404b6571019cf68fc8b511d47be81991761957b15788a\n","stream":"stdout","time":"2022-08-26T08:28:59.53497292Z"}

About this issue

Original URL
State: closed
Created 2 years ago
Reactions: 2
Comments: 24 (13 by maintainers)

Most upvoted comments

That’s a huge relief. I was really worried about my web3signer setup so close to merge. I will disable trace logs again.

yorickdowne on Sep 2, 2022

@siladu sorry for wasting your time, but it looks like the problem was a configuration error with a wrong network, at least I’m sure it was on one of the clusters. Today I updated one of the clusters back and made sure that the network is specified correctly, the blocks published successfully:

Sep 02 07:23:47.720 INFO Successfully published block slot: 4606617, graffiti: Some(\"StakeWise\"), attestations: 66, deposits: 0, block_type: Full, service: block

antares-sw on Sep 2, 2022

@siladu

teku:

--network=mainnet
--data-path=/data
--ee-endpoint=http://mainnet_geth_0:8551
--ee-jwt-secret-file=/data/jwtsecret
--p2p-port=30302
--rest-api-enabled=true
--rest-api-host-allowlist=*
--rest-api-interface=0.0.0.0
--rest-api-port=6003
--rest-api-cors-origins=*

lighthouse:

lighthouse
bn
--datadir=/data
--network=mainnet
--execution-endpoint=http://mainnet_besu_1:8551
--execution-jwt=/data/jwtsecret
--slots-per-restore-point=2048
--staking
--http
--http-port=6004
--http-address=0.0.0.0
--http-allow-origin=*
--port=30303
--enr-udp-port=30303

antares-sw on Sep 1, 2022

The only way I’ve managed to recreate this is by manually editing the CL’s request to web3signer. If you send a request with a beacon_block with version ALTAIR, but a slot number that is on or after BELLATRIX, then you get the stacktrace reported above.

I’m not sure how the validator client, especially teku, is able to produce this invalid request.

e.g.

{
    "type": "BLOCK_V2",
    "signingRoot": "0x8e33694496cff5c601e63b27183ff80935c24a332d2e889d64f7264842853409",
    "fork_info": {
        "fork": {
            "previous_version": "0x00000001",
            "current_version": "0x00000001",
            "epoch": "1"
        },
        "genesis_validators_root": "0x04700007fabc8282644aed6d1c7c9e21d38a03a0c4ba193f3afe428824b3a673"
    },
    "beacon_block": {
        "version": "ALTAIR",
        "block": {
            "slot": "4636672",
            "proposer_index": "4666673844721362956",
            "parent_root": "0x367cbd40ac7318427aadb97345a91fa2e965daf3158d7f1846f1306305f41bef",
            "state_root": "0xfd18cf40cc907a739be483f1ca0ee23ad65cdd3df23205eabc6d660a75d1f54e",
            "body": {
                ...
            }
        }
    }
}

where the mainnet BELLATRIX epoch is 144896 and its starting slot number is 4636672

siladu on Aug 31, 2022

Thanks @unxnn, can I also just confirm you’ve seen the “executionPayload must be specified” web3signer error with teku and prysm as well as lighthouse?

Yes, we’ve seen it on all clients.

antares-sw on Aug 30, 2022

@unxnn Nevermind the trace logging, I have located the potential problematic code.

usmansaleem on Aug 26, 2022