Skip to content
This repository has been archived by the owner on Jun 10, 2024. It is now read-only.

Unrecoverable error when connecting to sandbox while sandbox is starting #13

Open
itkach opened this issue Feb 12, 2020 · 2 comments
Open

Comments

@itkach
Copy link

itkach commented Feb 12, 2020

Steps to reproduce:

  • Create file flextesa.yml with the following content:
version: '3.7'
services:
  sandbox:
    image: registry.gitlab.com/tezos/flextesa:image-babylonbox-run
    command: babylonbox start
    ports:
      - 20000:20000
  • Create file tzindex.yml:
version: '3.7'
services:
  indexer:
    image: blockwatch/tzindex
    environment:
      TZ_RPC_HOST: sandbox
      TZ_RPC_PORT: 20000
    ports:
      - 8000:8000
    depends_on:
      - sandbox
  • Initialize docker swarm:
docker swarm init
  • Deploy docker stack consisting of these two services - sandbox (flextesa) and indexer (tzindex) pointing to the sandbox:
docker stack deploy -c tzindex.yml -c flextesa.yml test
  • Observe tzindex logs and notice Unrecoverable error logged after some seconds:
» docker service logs test_indexer --follow                                                 itkach@Igors-MacBook-Pro
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.670541 INFO MAIN Using configuration file config.json
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.670597 INFO MAIN Blockwatch tzindex v5.3.2 -- 3109ffb
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.670610 INFO MAIN (c) Copyright 2018-2020 -- KIDTSUNAMI UG
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.670622 INFO MAIN Starting Blockwatch-tzindex/v5.3.2.3109ffb on 8 cores
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.670635 INFO MAIN Go version go1.13.6
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.770784 INFO MAIN Profiling mutex/blocking at 1.00% sample rate.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.770860 INFO MAIN Using bolt database ./db/xtz
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.774384 INFO BLOC Initializing blockchain crawler in sync mode.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.774412 INFO BLOC Creating blockchain storage.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.775338 INFO BLOC Creating account index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.796761 INFO BLOC Creating contract index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.818056 INFO BLOC Creating block index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.847749 INFO BLOC Creating op index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.874028 INFO BLOC Creating flow index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.885023 INFO BLOC Creating chain index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.903453 INFO BLOC Creating supply index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.922705 INFO BLOC Creating rights index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.936550 INFO BLOC Creating snapshot index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.951671 INFO BLOC Creating income index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.974373 INFO BLOC Creating gov index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:37.998875 INFO BLOC Creating bigmap index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.023952 INFO BLOC Initializing account index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.026509 INFO BLOC Initializing contract index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.029012 INFO BLOC Initializing block index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.030599 INFO BLOC Initializing op index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.032090 INFO BLOC Initializing flow index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.033498 INFO BLOC Initializing chain index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.034988 INFO BLOC Initializing supply index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.036352 INFO BLOC Initializing rights index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.037707 INFO BLOC Initializing snapshot index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.039024 INFO BLOC Initializing income index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.040470 INFO BLOC Initializing gov index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.042135 INFO BLOC Initializing bigmap index.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.043660 INFO BLOC Connecting to RPC server.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:38.046906 ERRO BLOC Connection failed: Get http://sandbox:20000/chains/main/blocks/head/header: dial tcp: lookup sandbox on 127.0.0.11:53: no such host
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:43.051672 INFO BLOC Fetching genesis block.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:43.055457 INFO BLOC Crawling Tezos Mainnet.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:43.058721 INFO BLOC Starting blockchain crawler.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:43.058802 WARN SRVR HTTP Server reachable on all interfaces (0.0.0.0)
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:43.058938 INFO BLOC Starting blockchain sync from height 1.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:43.058987 INFO BLOC Starting blockchain ingest.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:43.058998 INFO BLOC Starting blockchain monitor.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:43.059030 INFO BLOC Already synchronized. Starting in monitor mode.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:43.061253 INFO SRVR Starting HTTP server at 0.0.0.0:8000
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:45.878358 INFO BLOC Building genesis dataset.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:45.882883 INFO BLOC Happy New Blockchain Quarter 2 at block 1!
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:36:45.882962 INFO BLOC Happy New Blockchain Year 2 at block 1!
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:37:01.879147 INFO BLOC New protocol PsBabyM1eUXZseaJdmXFApDSBqj8YBfwELoxZHHW77EMcAbbwAS detected at 2
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:37:01.881311 INFO BLOC Upgrade to v005: registered 0 buggy delegates
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:37:01.881337 INFO BLOC Upgrade to v005: dropped 0 empty delegates
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:37:01.881758 INFO BLOC Upgrade to v005: executed 0 airdrops
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:37:01.881835 ERRO BLOC Unrecoverable error: runtime error: index out of range [0] with length 0
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:37:01.882026 ERRO BLOC {"stack":["goroutine 37 [running]:","runtime/debug.Stack(0xc000174c00, 0xc420fd, 0x17)","\t/usr/local/go/src/runtime/debug/stack.go:24 +0x9d","blockwatch.cc/tzindex/etl.(*Crawler).syncBlockchain.func1(0xc000114018, 0xc000150380, 0xd71c60, 0xc000ea8000)","\t/go/src/tzindex/etl/crawler.go:720 +0xe5","panic(0xbd49a0, 0xc000117ee0)","\t/usr/local/go/src/runtime/panic.go:679 +0x1b2","blockwatch.cc/tzindex/etl.(*Builder).Decorate(0xc0000e1ea0, 0xd71c60, 0xc000ea8000, 0x0, 0x0, 0x79028e)","\t/go/src/tzindex/etl/builder.go:885 +0x1bc9","blockwatch.cc/tzindex/etl.(*Builder).Build(0xc0000e1ea0, 0xd71c60, 0xc000ea8000, 0xc0002543c0, 0xc000ecc640, 0x33, 0x0)","\t/go/src/tzindex/etl/builder.go:226 +0x1cb","blockwatch.cc/tzindex/etl.(*Crawler).syncBlockchain(0xc000150380)","\t/go/src/tzindex/etl/crawler.go:854 +0x44b","created by blockwatch.cc/tzindex/etl.(*Crawler).Start","\t/go/src/tzindex/etl/crawler.go:344 +0x9c"]}
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:37:01.882059 INFO BLOC Stopping blockchain sync at height 1.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:37:01.931491 INFO BLOC Context cancelled. Stopping blockchain ingest.
test_indexer.1.rydsedftrqze@docker-desktop    | 2020/02/12 14:37:01.931702 ERRO BLOC Exiting monitor loop on cancelled context
@itkach
Copy link
Author

itkach commented Feb 12, 2020

Overriding command for tzindex image to add a delay appears to fix it, like so:

...
indexer:
  ...
  command: ["sh", "-c", "sleep 10 && tzindex run"]

@echa
Copy link
Contributor

echa commented Feb 13, 2020

Thanks for the report.

I assume your use of mainnet genesis block produces block 1 at a high priority. The indexer logic is not prepared for this edge case, in fact this is an architectural issue. I wonder why it worked on other sandbox networks before.

Fixing the issue is quite expensive. The builder and rights index logic need to be refactored. Builder may be relatively easy, but rights index is not.

Right now there are too many high priority items in my work queue, so I don't expect to get to this issue anytime soon.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants