Blockscout: ERROR 40P01 (deadlock_detected) deadlock detected

[leonprou]

Occasionally we keep seeing this error on our blockscout explorer.
I suspect that this error's crashes the explorer and causes a restart (we see from out monitoring that sometimes the explorer isn't responding)

2020-10-07T09:27:30.927 application=plug request_id=FjurrL9734mjTnIADQ-S [info] Sent 200 in 31ms
2020-10-07T09:27:32.713 fetcher=internal_transaction count=7 [error] Task Indexer.Fetcher.InternalTransaction started from #PID<0.5596.2> terminating
** (Postgrex.Error) ERROR 40P01 (deadlock_detected) deadlock detected

    hint: See server log for query details.

Process 6028 waits for ShareLock on transaction 29810542; blocked by process 6045.
Process 6045 waits for ShareLock on transaction 29810539; blocked by process 6028.
    (ecto_sql 3.3.4) lib/ecto/adapters/sql.ex:612: Ecto.Adapters.SQL.raise_sql_call_error/1
    (ecto_sql 3.3.4) lib/ecto/adapters/sql.ex:545: Ecto.Adapters.SQL.execute/5
    (ecto 3.3.4) lib/ecto/repo/queryable.ex:192: Ecto.Repo.Queryable.execute/4
    (ecto 3.3.4) lib/ecto/repo/queryable.ex:17: Ecto.Repo.Queryable.all/3
    (explorer 0.0.1) lib/explorer/chain/import/runner/internal_transactions.ex:235: Explorer.Chain.Import.Runner.InternalTransactions.acquire_blocks/2
    (ecto 3.3.4) lib/ecto/multi.ex:585: Ecto.Multi.apply_operation/5
    (elixir 1.10.3) lib/enum.ex:2111: Enum."-reduce/3-lists^foldl/2-0-"/3
    (ecto 3.3.4) lib/ecto/multi.ex:569: anonymous fn/5 in Ecto.Multi.apply_operations/5
Function: &Indexer.BufferedTask.log_run/1
    Args: [%{batch: [7439064, 7439058, 7439060, 7439056, 7439055, 7439069, 7439068], callback_module: Indexer.Fetcher.InternalTransaction, callback_module_state: [transport: EthereumJSONRPC.HTTP, transport_options: [http: EthereumJSONRPC.HTTP.HTTPoison, url: "https://explorer-node.fuse.io", method_to_url: [eth_getBalance: "https://explorer-node.fuse.io", trace_block: "https://explorer-node.fuse.io", trace_replayTransaction: "https://explorer-node.fuse.io"], http_options: [recv_timeout: 600000, timeout: 600000, hackney: [pool: :ethereum_jsonrpc]]], variant: EthereumJSONRPC.Parity], metadata: [fetcher: :internal_transaction]}]

Environment

• Elixir & Erlang/OTP versions (elixir -version): Elixir 1.10.3 (compiled with Erlang/OTP 22)
• Operating System: Alpine Linux v3.11 (Runs in a docker on AWS Ubunu 18)
• Blockscout Version/branch: We are running a fork of 3.3.2. The live version is https://explorer-v3.fuse.io/.

[ArseniiPetrovich]

I digged this issue yesterday and found out that it is caused by deadlock that appears when we are trying to insert a block validation record.
Here are the logs form RDS database:

2020-10-29 10:12:25 UTC:172.31.27.161(53549):fuse@fusenet_explorer:[16327]:ERROR:  deadlock detected
2020-10-29 10:12:25 UTC:172.31.27.161(53549):fuse@fusenet_explorer:[16327]:DETAIL:  Process 16327 waits for ShareLock on transaction 37769062; blocked by process 16295.
    Process 16295 waits for AccessShareLock on tuple (240712,40) of relation 18711 of database 18697; blocked by process 31566.
    Process 31566 waits for ShareLock on transaction 37769078; blocked by process 16327.
    Process 16327: SELECT b0."hash" FROM "blocks" AS b0 WHERE (b0."number" = ANY($1) AND b0."consensus") ORDER BY b0."hash" FOR UPDATE
    Process 16295: INSERT INTO "block_rewards" AS b0 ("address_hash","address_type","block_hash","inserted_at","reward","updated_at") VALUES ($1,$2,$3,$4,$5,$6),($7,$8,$9,$10,$11,$12),($13,$14,$15,$16,$17,$18) ON CONFLICT ("address_hash","address_type","block_hash") DO UPDATE SET "reward" = EXCLUDED.reward WHERE (EXCLUDED.reward IS DISTINCT FROM b0."reward") RETURNING "updated_at", "inserted_at", "block_hash", "address_hash", "reward", "address_type"
    Process 31566: SELECT b0."hash" FROM "blocks" AS b0 WHERE (b0."number" = ANY($1) AND b0."consensus") ORDER BY b0."hash" FOR UPDATE
2020-10-29 10:12:25 UTC:172.31.27.161(53549):fuse@fusenet_explorer:[16327]:HINT:  See server log for query details.
2020-10-29 10:12:25 UTC:172.31.27.161(53549):fuse@fusenet_explorer:[16327]:CONTEXT:  while locking tuple (240712,41) in relation "blocks"
2020-10-29 10:12:25 UTC:172.31.27.161(53549):fuse@fusenet_explorer:[16327]:STATEMENT:  SELECT b0."hash" FROM "blocks" AS b0 WHERE (b0."number" = ANY($1) AND b0."consensus") ORDER BY b0."hash" FOR UPDATE

From I research I believe these lines of code are affected => https://github.com/poanetwork/blockscout/blob/master/apps/explorer/lib/explorer/chain/import/runner/block/rewards.ex#L46, however I'm not that good in building ECTO queries on Elixir and I don't think I can fix it fast enough.
@vbaranov Could you look at it, please?

[vbaranov]

@leonprou please try to apply 2 changes (2 lines of code) at your instance of application:

1. https://github.com/poanetwork/blockscout/commit/c2335b96f6b983adeec4c78d19c33884e6a9e1f5#diff-8e8773598d5990a9807c5c5d15e7c92c7cbf9ff58e75885c7ad7d6d15d83d37cR64
2. https://github.com/poanetwork/blockscout/commit/c2335b96f6b983adeec4c78d19c33884e6a9e1f5#diff-f18cb636a2b06db285f7436022971439a663c36c378b2c1235afdaa451c7765cR56

and please, let me know the results regarding deadlocks issue. Also, I urge you to update your instance to the latest release (3.3.3 currently). It has various improvements prior to 3.3.2.

[ArseniiPetrovich]

Can't see any of the deadlocks after the upgrade. Thank you, @vbaranov! 👍

[leonprou]

@vbaranov Thanks for the fix! Yep I though we were pretty up to date but looking into the changelog many fixed and new features. Will try to update in the near feauture.

@ArseniiPetrovich thank you as well 😄