Snapchain / zkValidium-quickstart

16 stars 31 forks source link

sequencer could not sync #36

Closed simonzg closed 9 months ago

simonzg commented 9 months ago

Hi Polygon team,

I'm trying out the CDK, and the containers are up and running. However, when I take a closer look at zkevm-sequencer , there're lines of errors printed repeatedly in the logs as the following. I'm hoping you guys could shed some light on this. Thank you.

The error:

2024-01-19T23:26:36.470Z    INFO    sequencer/sequencer.go:69   waiting for synchronizer to sync... {"pid": 1, "version": "v0.0.3-RC2"}
2024-01-19T23:26:37.471Z    ERROR   sequencer/sequencer.go:251  failed to get last batch num, err: state not synchronized%!(EXTRA string=
/src/log/log.go:142 github.com/0xPolygonHermez/zkevm-node/log.appendStackTraceMaybeArgs()
/src/log/log.go:251 github.com/0xPolygonHermez/zkevm-node/log.Errorf()
/src/sequencer/sequencer.go:251 github.com/0xPolygonHermez/zkevm-node/sequencer.(*Sequencer).isSynced()
/src/sequencer/sequencer.go:68 github.com/0xPolygonHermez/zkevm-node/sequencer.(*Sequencer).Start()
)   {"pid": 1, "version": "v0.0.3-RC2"}
github.com/0xPolygonHermez/zkevm-node/sequencer.(*Sequencer).isSynced
    /src/sequencer/sequencer.go:251
github.com/0xPolygonHermez/zkevm-node/sequencer.(*Sequencer).Start
    /src/sequencer/sequencer.go:68
2024-01-19T23:26:37.471Z    INFO    sequencer/sequencer.go:69   waiting for synchronizer to sync... {"pid": 1, "version": "v0.0.3-RC2"}
2024-01-19T23:26:38.471Z    ERROR   sequencer/sequencer.go:251  failed to get last batch num, err: state not synchronized%!(EXTRA string=

Here's the output from docker compose ps

NAME                               IMAGE                                               COMMAND                  SERVICE                            CREATED             STATUS                       PORTS
explorer-backend-l1                blockscout/blockscout:6.0.0.commit.ce735c12         "sh -c 'bin/blocksco…"   explorer-backend-l1                About an hour ago   Up About an hour             0.0.0.0:4000->4000/tcp, :::4000->4000/tcp
explorer-backend-l1-db             postgres:15                                         "docker-entrypoint.s…"   explorer-backend-l1-db             About an hour ago   Up About an hour             0.0.0.0:5436->5432/tcp, :::5436->5432/tcp
explorer-backend-l2                blockscout/blockscout-zkevm:6.0.0                   "sh -c 'bin/blocksco…"   explorer-backend-l2                About an hour ago   Up About an hour             0.0.0.0:4001->4000/tcp, :::4001->4000/tcp
explorer-backend-l2-db             postgres:15                                         "docker-entrypoint.s…"   explorer-backend-l2-db             About an hour ago   Up About an hour             0.0.0.0:5437->5432/tcp, :::5437->5432/tcp
explorer-frontend-l1               ghcr.io/blockscout/frontend:v1.21.2                 "./entrypoint.sh nod…"   explorer-frontend-l1               About an hour ago   Up About an hour             0.0.0.0:3000->3000/tcp, :::3000->3000/tcp
explorer-frontend-l2               ghcr.io/blockscout/frontend:v1.21.2                 "./entrypoint.sh nod…"   explorer-frontend-l2               About an hour ago   Up About an hour             0.0.0.0:3001->3000/tcp, :::3001->3000/tcp
explorer-proxy-l1                  nginx:1.25.3                                        "/docker-entrypoint.…"   explorer-proxy-l1                  About an hour ago   Up About an hour             0.0.0.0:81->80/tcp, :::81->80/tcp, 0.0.0.0:8082->8080/tcp, :::8082->8080/tcp
explorer-proxy-l2                  nginx:1.25.3                                        "/docker-entrypoint.…"   explorer-proxy-l2                  About an hour ago   Up About an hour             0.0.0.0:80->80/tcp, :::80->80/tcp, 0.0.0.0:8084->8080/tcp, :::8084->8080/tcp
explorer-sig-provider              ghcr.io/blockscout/sig-provider:v1.0.0              "./sig-provider-serv…"   explorer-sig-provider              About an hour ago   Up About an hour             0.0.0.0:8151->8050/tcp, :::8151->8050/tcp
explorer-smart-contract-verifier   ghcr.io/blockscout/smart-contract-verifier:v1.6.0   "./smart-contract-ve…"   explorer-smart-contract-verifier   About an hour ago   Up About an hour             0.0.0.0:8150->8050/tcp, :::8150->8050/tcp
explorer-stats-db-l1               postgres:15                                         "docker-entrypoint.s…"   explorer-stats-db-l1               About an hour ago   Up About an hour             0.0.0.0:7433->5432/tcp, :::7433->5432/tcp
explorer-stats-db-l2               postgres:15                                         "docker-entrypoint.s…"   explorer-stats-db-l2               About an hour ago   Up About an hour             0.0.0.0:7434->5432/tcp, :::7434->5432/tcp
explorer-stats-l1                  ghcr.io/blockscout/stats:v1.5.0                     "./stats-server"         explorer-stats-l1                  About an hour ago   Up About an hour             0.0.0.0:8153->8050/tcp, :::8153->8050/tcp
explorer-stats-l2                  ghcr.io/blockscout/stats:v1.5.0                     "./stats-server"         explorer-stats-l2                  About an hour ago   Up About an hour             0.0.0.0:8154->8050/tcp, :::8154->8050/tcp
explorer-visualizer                ghcr.io/blockscout/visualizer:v0.2.0                "./visualizer-server"    explorer-visualizer                About an hour ago   Up About an hour             0.0.0.0:8152->8050/tcp, :::8152->8050/tcp
visualizer-proxy                   nginx:1.25.3                                        "/docker-entrypoint.…"   explorer-visualizer-proxy          About an hour ago   Up About an hour             80/tcp, 0.0.0.0:8083->8081/tcp, :::8083->8081/tcp
zkevm-aggregator                   hermeznetwork/cdk-validium-node:v0.0.3-RC2          "/bin/sh -c '/app/zk…"   zkevm-aggregator                   About an hour ago   Up About an hour             8123/tcp, 0.0.0.0:50081->50081/tcp, :::50081->50081/tcp, 0.0.0.0:9093->9091/tcp, :::9093->9091/tcp
zkevm-bridge-db                    postgres:15                                         "docker-entrypoint.s…"   zkevm-bridge-db                    About an hour ago   Up About an hour             5438/tcp, 0.0.0.0:5438->5432/tcp, :::5438->5432/tcp
zkevm-bridge-ui                    hermeznetwork/zkevm-bridge-ui:mainnet               "/bin/sh /app/script…"   zkevm-bridge-ui                    About an hour ago   Up About an hour             0.0.0.0:8088->80/tcp, :::8088->80/tcp
zkevm-data-availability            hermeznetwork/cdk-data-availability:v0.0.3          "/bin/sh -c '/app/cd…"   zkevm-data-availability            About an hour ago   Up About an hour             0.0.0.0:8444->8444/tcp, :::8444->8444/tcp
zkevm-data-node-db                 postgres:15                                         "docker-entrypoint.s…"   zkevm-data-node-db                 About an hour ago   Up About an hour (healthy)   0.0.0.0:5444->5432/tcp, :::5444->5432/tcp
zkevm-eth-tx-manager               hermeznetwork/cdk-validium-node:v0.0.3-RC2          "/bin/sh -c '/app/zk…"   zkevm-eth-tx-manager               About an hour ago   Up About an hour             8123/tcp, 0.0.0.0:9094->9091/tcp, :::9094->9091/tcp
zkevm-event-db                     postgres:15                                         "docker-entrypoint.s…"   zkevm-event-db                     About an hour ago   Up About an hour             0.0.0.0:5435->5432/tcp, :::5435->5432/tcp
zkevm-explorer-json-rpc            hermeznetwork/cdk-validium-node:v0.0.3-RC2          "/bin/sh -c '/app/zk…"   zkevm-explorer-json-rpc            About an hour ago   Up About an hour             0.0.0.0:8124->8124/tcp, :::8124->8124/tcp, 8123/tcp, 0.0.0.0:8134->8134/tcp, :::8134->8134/tcp
zkevm-json-rpc                     hermeznetwork/cdk-validium-node:v0.0.3-RC2          "/bin/sh -c '/app/zk…"   zkevm-json-rpc                     About an hour ago   Up About an hour             0.0.0.0:8123->8123/tcp, :::8123->8123/tcp, 0.0.0.0:8133->8133/tcp, :::8133->8133/tcp, 0.0.0.0:9091->9091/tcp, :::9091->9091/tcp
zkevm-l2gaspricer                  hermeznetwork/cdk-validium-node:v0.0.3-RC2          "/bin/sh -c '/app/zk…"   zkevm-l2gaspricer                  About an hour ago   Up About an hour             8123/tcp
zkevm-mock-l1-network              snapchain/geth-cdk-validium-contracts:v0.0.2        "geth --http --http.…"   zkevm-mock-l1-network              About an hour ago   Up About an hour             0.0.0.0:8545-8546->8545-8546/tcp, :::8545-8546->8545-8546/tcp, 30303/tcp, 30303/udp
zkevm-pool-db                      postgres:15                                         "docker-entrypoint.s…"   zkevm-pool-db                      About an hour ago   Up About an hour             0.0.0.0:5433->5432/tcp, :::5433->5432/tcp
zkevm-prover                       hermeznetwork/zkevm-prover:v3.0.2                   "zkProver -c /usr/sr…"   zkevm-prover                       About an hour ago   Up About an hour             0.0.0.0:50061->50061/tcp, :::50061->50061/tcp, 0.0.0.0:50071->50071/tcp, :::50071->50071/tcp
zkevm-sequence-sender              hermeznetwork/cdk-validium-node:v0.0.3-RC2          "/bin/sh -c '/app/zk…"   zkevm-sequence-sender              About an hour ago   Up About an hour             8123/tcp
zkevm-sequencer                    hermeznetwork/cdk-validium-node:v0.0.3-RC2          "/bin/sh -c '/app/zk…"   zkevm-sequencer                    About an hour ago   Up About an hour             0.0.0.0:6060->6060/tcp, :::6060->6060/tcp, 0.0.0.0:6900->6900/tcp, :::6900->6900/tcp, 8123/tcp, 0.0.0.0:9092->9091/tcp, :::9092->9091/tcp
zkevm-state-db                     postgres:15                                         "docker-entrypoint.s…"   zkevm-state-db                     About an hour ago   Up About an hour             0.0.0.0:5432->5432/tcp, :::5432->5432/tcp
bap2pecs commented 9 months ago

it looks like your synchronizer is not running.

if you docker compose ps -a | grep "Exited", you should see the synchronizer exited unexpectedly.

could you check its logs?

simonzg commented 9 months ago

Yes exactly the zkevm-sync was exited

the last few lines of zkevm-sync's log looks like this:

nizer Data:[] Json:<nil>}   {"pid": 1, "version": "v0.0.3-RC2"}
2024-01-19T22:51:37.788Z    INFO    cmd/run.go:274  running migrations for zkevm-pool-db    {"pid": 1, "version": "v0.0.3-RC2"}
2024-01-19T22:51:37.788Z    INFO    db/db.go:47 running migrations up   {"pid": 1, "version": "v0.0.3-RC2"}
2024-01-19T22:51:37.874Z    FATAL   cmd/run.go:277  ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index" (SQLSTATE 23505) handling 0011.sql
/src/log/log.go:142 github.com/0xPolygonHermez/zkevm-node/log.appendStackTraceMaybeArgs()
/src/log/log.go:223 github.com/0xPolygonHermez/zkevm-node/log.Fatal()
/src/cmd/run.go:277 main.runMigrations()
/src/cmd/run.go:270 main.runPoolMigrations()
/src/cmd/run.go:501 main.createPool()
/src/cmd/run.go:219 main.start()
/go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/command.go:274 github.com/urfave/cli/v2.(*Command).Run()
/go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/command.go:267 github.com/urfave/cli/v2.(*Command).Run()
/go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/app.go:332 github.com/urfave/cli/v2.(*App).RunContext()
/go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/app.go:309 github.com/urfave/cli/v2.(*App).Run()
/src/cmd/main.go:191 main.main()
/usr/local/go/src/runtime/proc.go:267 runtime.main()
    {"pid": 1, "version": "v0.0.3-RC2"}
main.runMigrations
    /src/cmd/run.go:277
main.runPoolMigrations
    /src/cmd/run.go:270
main.createPool
    /src/cmd/run.go:501
main.start
    /src/cmd/run.go:219
github.com/urfave/cli/v2.(*Command).Run
    /go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/command.go:274
github.com/urfave/cli/v2.(*Command).Run
    /go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/command.go:267
github.com/urfave/cli/v2.(*App).RunContext
    /go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/app.go:332
github.com/urfave/cli/v2.(*App).Run
    /go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/app.go:309
main.main
    /src/cmd/main.go:191
runtime.main
    /usr/local/go/src/runtime/proc.go:267
bap2pecs commented 9 months ago

@simonzg it seems the error happens here when are you doing a up migration for the pool db.

specifically, it's at the execution of the script https://github.com/0xPolygon/cdk-validium-node/blob/v0.0.3-RC2/db/migrations/pool/0011.sql

per this and this, it's likely you faced some race conditions at CREATE TABLE

it shouldn't happen if you follow the CDK quickstart steps exactly. were you starting up all the service with sudo make run? I need a bit more context to understand how you got this error

one thing you can try is to sudo make run stop and sudo make run

simonzg commented 9 months ago

Thanks for your reply. I cloned the repo to a new Ubuntu vps and followed the steps, and the issue is gone.