Proposer Assign RPC Return 500 Error

[J1a-wei]

Hi Teku team,
When slot miss. e.g. https://beaconcha.in/slot/10143104
Call Proposer Assign RPC. Teku client return 500 Internal Error.

/eth/v1/validator/duties/proposer/{epoch}

Teku Args:

- --network=${NETWORK}
- --data-path=/data
- --data-beacon-path=/data/beacon
- --data-storage-archive-frequency=${ARCHIVE_FREQUENCY}
- --data-storage-mode=archive
- --checkpoint-sync-url=${CHECKPOINT_URL}
- --ee-endpoint=http://reth:8551
- --ee-jwt-secret-file=/reth/jwt.hex
- --p2p-enabled=true
- --p2p-advertised-ip=${PUBLIC_IP}
- --p2p-advertised-port=${P2P_PORT}
- --rest-api-enabled=true
- --rest-api-host-allowlist=*
- --rest-api-interface=0.0.0.0
- --rest-api-port=8080
- --rest-api-cors-origins=false

[lucassaldanha]

Hi! Thanks for reporting this issue.

To clarify, are you calling the Validator API Get block proposer duties method externally? Or did your Validator node report the RPC error? Or are you saying that your validator missed the proposal because the duties method returned 500?

[J1a-wei]

Just calling the Validator API Get block proposer duties method externally @lucassaldanha

[tbenr]

I think he is saying that if the epoch begins with an empty slot, then the api fails. Going to check if it is the case.

[tbenr]

@J1a-wei I cannot replicate the issue based on what I understood from your description.
Can you provide beacon node logs in the surrounding of the 500 error?
Can you also provide the epoch parameter you where using in the query?

[J1a-wei]

HI @tbenr
Sorry, I synced from the most recent checkpoint, and the previous data has been deleted.

I suspect that if the first slot of the epoch is missed, the RPC(/eth/v1/validator/duties/proposer/{epoch}) cannot be called.

When I checked the logs, it's highly likely that there wasn't any meaningful log because the debug log level wasn't enabled.

[tbenr]

@J1a-wei 500 errors are bad errors that do not require debug level logging to have more info.
If there were no error logs it, is it possible that the 500 error you're talking about was a 503?

It happens when you try to hit the endpoint while the node is syncing (like when you start from a checkpoint sync)

[J1a-wei]

@tbenr Maybe. I haven't encountered the issue again so far, but if it happens next time, I'll make sure to record the details carefully and report it to you. Sorry for the trouble!

[tbenr]

@J1a-wei sounds like a good plan. Please reach us out if happens again!

[J1a-wei]

This issue is occurred again

https://beaconcha.in/epoch/321088

But it is no any useful log(logging-level is all).

curl -X 'GET'   'http://localhost:31080/eth/v1/validator/duties/proposer/321088'   -H 'accept: application/json'
{"code":500,"message":"An unexpected error occurred"}

teku log

02:25:03.307 INFO  - Slot Event  *** Slot: 10278723, Block: 4dfcacf43b396163f71adcc6d63659e95934b79f2d4742d0c695d3a8617a4bb9, Justified: 321209, Finalized: 321208, Peers: 44
02:25:15.323 INFO  - Slot Event  *** Slot: 10278724, Block: 7891ccb9cfe519e7f4ab86b74011101904a19f8e9a1b044b76c4764aee58a320, Justified: 321209, Finalized: 321208, Peers: 56
02:25:27.276 INFO  - Slot Event  *** Slot: 10278725, Block: 45a5d90b3413fab1afd87bcfd2475ac3b8a070ce7fd17293ed57ec9b71fdc884, Justified: 321209, Finalized: 321208, Peers: 56
02:25:39.336 INFO  - Slot Event  *** Slot: 10278726, Block: 92621de8be22c456e705e8f95728e6fd1ef167518981d43eb208f071ec14197e, Justified: 321209, Finalized: 321208, Peers: 63
02:25:51.259 INFO  - Slot Event  *** Slot: 10278727, Block: 6590b3cf23dd0706e02a068077e986ccaa5ed11eef434d9fb962565298094cb6, Justified: 321209, Finalized: 321208, Peers: 58
02:26:03.285 INFO  - Slot Event  *** Slot: 10278728, Block: ed82783ce9bd7de29852846c1afb7dd8664604928f66591bb1dd2949a618b181, Justified: 321209, Finalized: 321208, Peers: 56
02:26:15.298 INFO  - Slot Event  *** Slot: 10278729, Block: dd027ee89d00fd7c43e3105335bba3d3c2daddab8d22e728be111813d5b547d1, Justified: 321209, Finalized: 321208, Peers: 55
02:26:27.275 INFO  - Slot Event  *** Slot: 10278730, Block: 993f36132d82c73b1b1dfe8481f798f1eff5afd557d86d1a050aa0b80614cbcd, Justified: 321209, Finalized: 321208, Peers: 66
02:26:39.339 INFO  - Slot Event  *** Slot: 10278731, Block: 77da487f74148a3db7b9189bfe089293ab32dca9ae789ab8be774afe433f9300, Justified: 321209, Finalized: 321208, Peers: 64
02:26:51.300 INFO  - Slot Event  *** Slot: 10278732, Block: 377d19a64f2f31391d0865ee6c0a93ad240538ce807c7e7bfe630258ea1d9a9b, Justified: 321209, Finalized: 321208, Peers: 64
02:27:03.278 INFO  - Slot Event  *** Slot: 10278733, Block: 62e8cf80fadade559019e1e031e20abcac288bcfb6cd37d508b7ef2ed3d9a8b3, Justified: 321209, Finalized: 321208, Peers: 60
2024-10-29T02:27:12.635328561Z JettyServerThreadPool-985 ERROR Recursive call to appender teku-log-appender
02:27:15.327 INFO  - Slot Event  *** Slot: 10278734, Block: fbf305974f95516eea2e1f79e997b7ca7c9324a02ac23387b0ea27848ab3283e, Justified: 321209, Finalized: 321208, Peers: 57
02:27:27.256 INFO  - Slot Event  *** Slot: 10278735, Block: 835d0d0d65170714476014e36fffa01b521f0f7e65dc549270d8403b9830df49, Justified: 321209, Finalized: 321208, Peers: 68
02:27:39.267 INFO  - Slot Event  *** Slot: 10278736, Block: 01f598cefb71cf3c3f685cdf3a519936350375cee242f3acd7d794823f76c1b8, Justified: 321209, Finalized: 321208, Peers: 70
02:27:51.283 INFO  - Slot Event  *** Slot: 10278737, Block: 9f678972d1900a06ec2f9baf9c30b57987b53f090e6a1c41b37f4c907687e6cc, Justified: 321209, Finalized: 321208, Peers: 67
02:28:03.285 INFO  - Slot Event  *** Slot: 10278738, Block: 11c052b6d17794b05d010111719fc4af31fdfb135b808f03627bc29e94e54b49, Justified: 321209, Finalized: 321208, Peers: 62
02:28:15.240 INFO  - Slot Event  *** Slot: 10278739, Block: 905755615a0b9c23d5f9058559562cdbd2f94c0b2270fafcee6980a0ec8b67a6, Justified: 321209, Finalized: 321208, Peers: 61
02:28:27.291 INFO  - Slot Event  *** Slot: 10278740, Block: 57cd384360e5cc000adda227d798a198f598d565543dbd2ace70b0b2d2ff18e1, Justified: 321209, Finalized: 321208, Peers: 60

Env

NETWORK=mainnet
RETH_IMAGE=ghcr.io/paradigmxyz/reth:v1.0.7
PUBLIC_IP=xx.xx.xx.xx
P2P_PORT=30305
TEKU_IMAGE=consensys/teku:24.8.0
CHECKPOINT_URL=https://beaconstate.ethstaker.cc
ARCHIVE_FREQUENCY=1
STORAGE_MODE=archive
RETAINED_SLOT=50400

Command

services:
  reth:
    image: '${RETH_IMAGE}'
    pull_policy: always
    container_name: reth
    restart: unless-stopped
    stop_signal: SIGINT
    stop_grace_period: 2m
    ports:
    - 30303:30303
    - 30303:30303/udp
    - 31545:8545
    - 31546:8546
    - 8551:8551
    volumes:
    - /data/reth:/data
    command:
    - node
    - --chain=${NETWORK}
    - --datadir=/data
    - --peers-file=/data/peers.file
    - --nat=extip:${PUBLIC_IP}
    - --port=30303
    - --http
    - --http.addr=0.0.0.0
    - --http.api=eth,net,web3,admin
    - --http.corsdomain=*
    - --ws
    - --ws.origins=*
    - --ws.addr=0.0.0.0
    - --ws.api=eth,net,web3
    - --authrpc.addr=0.0.0.0
    - --authrpc.jwtsecret=/data/jwt.hex
    - --authrpc.port=8551
  teku:
    image: '${TEKU_IMAGE}'
    pull_policy: always
    container_name: teku
    restart: unless-stopped
    stop_grace_period: 2m
    environment:
      JAVA_OPTS:  -XX:MinRAMPercentage=50.0 -XX:MaxRAMPercentage=80.0 -XX:+HeapDumpOnOutOfMemoryError
    volumes:
    - /data/teku:/data
    - /data/reth:/reth
    ports:
    - 31080:8080
    - ${P2P_PORT}:${P2P_PORT}
    - ${P2P_PORT}:${P2P_PORT}/udp
    command:
    - --network=${NETWORK}
    - --logging=all
    - --data-path=/data
    - --data-beacon-path=/data/beacon
    - --data-storage-archive-frequency=${ARCHIVE_FREQUENCY}
    - --data-storage-mode=${STORAGE_MODE}
    - --checkpoint-sync-url=${CHECKPOINT_URL}
    - --ee-endpoint=http://reth:8551
    - --ee-jwt-secret-file=/reth/jwt.hex
    - --p2p-enabled=true
    - --p2p-advertised-ip=${PUBLIC_IP}
    - --p2p-advertised-port=${P2P_PORT}
    - --rest-api-enabled=true
    - --rest-api-host-allowlist=*
    - --rest-api-interface=0.0.0.0
    - --rest-api-port=8080
    - --rest-api-cors-origins=false

@tbenr

[tbenr]

Hey @J1a-wei , are you looking in the log file (probably under /data/teku/logs/....log) or in the docker output? Since you're not using --log-destination=CONSOLE docker logs just contain minimal info.