Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Blockscout reports too many error logs #2308

Open
rjl493456442 opened this issue Jul 8, 2019 · 13 comments

Comments

Projects
None yet
4 participants
@rjl493456442
Copy link
Contributor

commented Jul 8, 2019

Describe your issue here.

Environment

  • Elixir & Erlang/OTP versions (elixir -version):
  • Operating System:

Steps to reproduce

Attach blockscout to a goerli node.

Actual behaviour

Lots of error logs

Function: &Indexer.Block.Catchup.Fetcher.task/1
    Args: [%Indexer.Block.Catchup.Fetcher{block_fetcher: %Indexer.Block.Fetcher{broadcast: :catchup, callback_module: Indexer.Block.Catchup.Fetcher, json_rpc_named_arguments: [transport: EthereumJSONRPC.HTTP, transport_options: [http: EthereumJSONRPC.HTTP.HTTPoison, url: "http://localhost:8545", http_options: [recv_timeout: 600000, timeout: 600000, hackney: [pool: :ethereum_jsonrpc]]], variant: EthereumJSONRPC.Geth], receipts_batch_size: 250, receipts_concurrency: 10}, blocks_batch_size: 10, blocks_concurrency: 10, memory_monitor: Indexer.Memory.Monitor}]
2019-07-08T05:38:46.038 application=indexer fetcher=block_catchup [error] Catchup index stream exited with reason ({{:badmatch, {:error, :econnrefused}}, [{Indexer.Block.Catchup.Fetcher, :task, 1, [file: 'lib/indexer/block/catchup/fetcher.ex', line: 75]}, {Task.Supervised, :invoke_mfa, 2, [file: 'lib/task/supervised.ex', line: 90]}, {Task.Supervised, :reply, 5, [file: 'lib/task/supervised.ex', line: 35]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}). Restarting
2019-07-08T05:38:46.038 fetcher=block_catchup [error] Task #PID<0.16351.1> started from Indexer.Block.Catchup.BoundIntervalSupervisor terminating
** (MatchError) no match of right hand side value: {:error, :econnrefused}
    (indexer) lib/indexer/block/catchup/fetcher.ex:75: Indexer.Block.Catchup.Fetcher.task/1
    (elixir) lib/task/supervised.ex:90: Task.Supervised.invoke_mfa/2
    (elixir) lib/task/supervised.ex:35: Task.Supervised.reply/5
    (stdlib) proc_lib.erl:249: :proc_lib.init_p_do_apply/3

@vbaranov vbaranov added the question label Jul 8, 2019

@vbaranov

This comment has been minimized.

Copy link
Collaborator

commented Jul 8, 2019

@rjl493456442 what is your setup? Seems, there is no fully synchronized archive node on http://localhost:8545

@rjl493456442

This comment has been minimized.

Copy link
Contributor Author

commented Jul 8, 2019

Yes. The node is still syncing.

Btw I ran the blockscout in the docker, and there are lots of logs like

Function: &:erlang.apply/2
    Args: [#Function<9.87331822/1 in Ecto.Repo.Preloader.maybe_pmap/4>, [{{:assoc, %Ecto.Association.BelongsTo{cardinality: :one, defaults: [], field: :miner, on_cast: nil, on_repl
ace: :raise, owner: Explorer.Chain.Block, owner_key: :miner_hash, queryable: Explorer.Chain.Address, related: Explorer.Chain.Address, related_key: :hash, relationship: :parent, uni
que: true, where: []}, {0, :hash}}, nil, nil, [names: {nil, nil, []}]}]]
2019-07-08T08:55:15.299 [error] Task #PID<0.28301.5> started from #PID<0.27863.5> terminating
** (DBConnection.ConnectionError) connection not available and request was dropped from queue after 128ms. You can configure how long requests wait in the queue using :queue_target
 and :queue_interval. See DBConnection.start_link/2 for more information
    (ecto_sql) lib/ecto/adapters/sql.ex:620: Ecto.Adapters.SQL.raise_sql_call_error/1
    (ecto_sql) lib/ecto/adapters/sql.ex:553: Ecto.Adapters.SQL.execute/5
    (ecto) lib/ecto/repo/queryable.ex:147: Ecto.Repo.Queryable.execute/4
    (ecto) lib/ecto/repo/queryable.ex:18: Ecto.Repo.Queryable.all/3
    (ecto) lib/ecto/repo/preloader.ex:188: Ecto.Repo.Preloader.fetch_query/8
    (ecto) lib/ecto/repo/preloader.ex:119: Ecto.Repo.Preloader.preload_assoc/10
    (elixir) lib/task/supervised.ex:90: Task.Supervised.invoke_mfa/2
    (elixir) lib/task/supervised.ex:35: Task.Supervised.reply/5
Function: &:erlang.apply/2

The container can restart over and over again. Not sure the error can cause panic.

Is there any env I can config the request frequency to reduce the db connection?

@karalabe

This comment has been minimized.

Copy link

commented Jul 8, 2019

Our use case is to start a docker container with a Geth node from scratch, doing an archive sync on Goerli, and a Blockscout node indexing Geth. For some reason, blockscout seems to spit out a ton of errors (non stop, tens per second), and after a while (1 minute) tears itself down.

@karalabe

This comment has been minimized.

Copy link

commented Jul 8, 2019

I've created a repro for you via docker at https://github.com/karalabe/blockscout-goerli-repro.

$ cd /tmp && git clone https://github.com/karalabe/blockscout-goerli-repro
$ cd /tmp/blockscout-goerli-repro && docker build --tag=repro --no-cache --pull .
$ docker run -p 4000:4000 repro

And here's a sample crash: https://gist.github.com/karalabe/db9fb1ac76e896e337f360de4207175b

@karalabe

This comment has been minimized.

Copy link

commented Jul 8, 2019

Btw, I can confirm that if I wait until Geth is in sync and only afterwards start up blockscout, then everything seems to work ok. Still, this is a bit of a problem, because it indicates that if Geth restarts and reimports a batch of blocks, that might murder blockscout for whatever reason. Imho a fast moving chain should not cause bs to die.

@vbaranov

This comment has been minimized.

Copy link
Collaborator

commented Jul 8, 2019

Thank you for the details. Let us reproduce the mentioned behaviour.

@ayrat555

This comment has been minimized.

Copy link
Member

commented Jul 15, 2019

I could reproduce your issue. It's caused by a large amount of new blocks transferred through a web socket connection from the node. Can you please try this pr (#2358) ?

@rjl493456442

This comment has been minimized.

Copy link
Contributor Author

commented Jul 16, 2019

@ayrat555 Hi, I try the PR you offered, but unfortunately blockscout still has lots of error and a crash happens immediately.

Check the crash log here https://gist.github.com/rjl493456442/32d7b1597228f0c0f3c932679cddcec7

@ayrat555

This comment has been minimized.

Copy link
Member

commented Jul 16, 2019

Btw I saw you're configuring postgres in the elixir docker. I think it may be error-prone. I tested my PR on a docker-compose with posgres started in a separate docker. I used official postgres docker.

@ayrat555

This comment has been minimized.

Copy link
Member

commented Jul 16, 2019

please take a look ayrat555@c96d635.

docker-compose up

Also, I think geth also can be started from a separate docker

@rjl493456442

This comment has been minimized.

Copy link
Contributor Author

commented Jul 17, 2019

@ayrat555 Hi, I try the compose version. Here is a compose demo https://github.com/rjl493456442/blockscout_explorer_docker/tree/blockscout-compose

Unfortunately the same error occurs which can eventually lead to a crash.

The rjl493456442/blockscout image is built upon #2358

@ayrat555

This comment has been minimized.

Copy link
Member

commented Jul 17, 2019

I'll take a look at this now. Thanks

@ayrat555

This comment has been minimized.

Copy link
Member

commented Jul 17, 2019

@rjl493456442

  1. You have an error in your docker-compose file - DockerfilePostgres -> DockerfileExplorer
  2. I ran blockscout for a while with your configuration. Everything's ok so it may depend on a machine. You can try increasing WebSocket timeout from 60s to 120s - https://github.com/poanetwork/blockscout/pull/2358/files#diff-2b79eddc1d44c927db36ab82f726d0ddR39
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.