search

cuducos / minha-receita

🏢 Sua API web para consulta de informações do CNPJ da Receita Federal
https://minhareceita.org
MIT License
1.32k stars 132 forks source link

RecursionError: maximum recursion depth exceeded in comparison no docker-compose up feed #5

Closed koukunwlk closed 4 years ago

koukunwlk commented 4 years ago 
Traceback (most recent call last):
feed_1      |   File "import.py", line 130, in <module>
feed_1      |     main()
feed_1      |   File "import.py", line 104, in main
feed_1      |     if wait_for_postgres() and tables_exist():
feed_1      |   File "import.py", line 88, in wait_for_postgres
feed_1      |     return wait_for_postgres(retries)
feed_1      |   File "import.py", line 88, in wait_for_postgres
feed_1      |     return wait_for_postgres(retries)
feed_1      |   File "import.py", line 88, in wait_for_postgres
feed_1      |     return wait_for_postgres(retries)
feed_1      |   [Previous line repeated 984 more times]
feed_1      |   File "import.py", line 81, in wait_for_postgres
feed_1      |     result = psql("SELECT 1", capture_output=True)
feed_1      |   File "import.py", line 25, in psql
feed_1      |     return run(["psql", POSTGRES_URI, "-c", sql], capture_output=capture_output)
feed_1      |   File "/usr/local/lib/python3.7/subprocess.py", line 488, in run
feed_1      |     with Popen(*popenargs, **kwargs) as process:
feed_1      |   File "/usr/local/lib/python3.7/subprocess.py", line 800, in __init__
feed_1      |     restore_signals, start_new_session)
feed_1      |   File "/usr/local/lib/python3.7/subprocess.py", line 1472, in _execute_child
feed_1      |     for dir in os.get_exec_path(env))
feed_1      |   File "/usr/local/lib/python3.7/os.py", line 635, in get_exec_path
feed_1      |     warnings.simplefilter("ignore", BytesWarning)
feed_1      |   File "/usr/local/lib/python3.7/warnings.py", line 179, in simplefilter
feed_1      |     _add_filter(action, None, category, None, lineno, append=append)
feed_1      |   File "/usr/local/lib/python3.7/warnings.py", line 186, in _add_filter
feed_1      |     filters.remove(item)
feed_1      | RecursionError: maximum recursion depth exceeded in comparison

Usando ubuntu 20.4, com python 3.8

cuducos commented 4 years ago

Olá, @koukunwlk. Tomei a liberdade de editar teu post para adicionar as ``` antes e depois dos logs para melhorar a legibilidade.

Lendo o erro, me parece que pode ser algo do PostgreSQL. Pode compartilhar, também os logs do banco de dados? Se estiver rodando o padrão do projeto, docker-compose logs postgres : )

laurianops commented 4 years ago

É uma proteção contra um estouro de pilha, sim. Python (ou melhor, a implementação de CPython) não otimiza a recursão de cauda, ​​e a recursão desenfreada causa estouros de pilha. Você pode verificar o limite de recursão com sys.getrecursionlimit:

import sys print(sys.getrecursionlimit()) e altere o limite de recursão com sys.setrecursionlimit:

sys.setrecursionlimit(1500) mas fazer isso é perigoso - o limite padrão é um pouco conservador, mas os stackframes do Python podem ser bem grandes.

Python não é uma linguagem funcional e a recursão da cauda não é uma técnica particularmente eficiente. Reescrever o algoritmo iterativamente, se possível, geralmente é uma ideia melhor.

koukunwlk commented 4 years ago 
postgres_1  | 2020-09-22 13:53:59.842 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
postgres_1  | 2020-09-22 13:53:59.842 UTC [1] LOG:  listening on IPv6 address "::", port 5432
postgres_1  | 2020-09-22 13:53:59.854 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
postgres_1  | 2020-09-22 13:53:59.877 UTC [18] LOG:  database system was interrupted; last known up at 2020-09-22 12:47:04 UTC
postgres_1  | 2020-09-22 13:54:00.020 UTC [18] LOG:  database system was not properly shut down; automatic recovery in progress
postgres_1  | 2020-09-22 13:54:00.026 UTC [18] LOG:  redo starts at 0/165A1A0
postgres_1  | 2020-09-22 13:54:00.026 UTC [18] LOG:  invalid record length at 0/165A280: wanted 24, got 0
postgres_1  | 2020-09-22 13:54:00.026 UTC [18] LOG:  redo done at 0/165A248
postgres_1  | 2020-09-22 13:54:00.075 UTC [1] LOG:  database system is ready to accept connections
postgres_1  | 2020-09-22 14:09:53.426 UTC [1] LOG:  received smart shutdown request
postgres_1  | 2020-09-22 14:09:53.491 UTC [1] LOG:  background worker "logical replication launcher" (PID 24) exited with exit code 1
postgres_1  | 2020-09-22 14:09:53.492 UTC [19] LOG:  shutting down
postgres_1  | 2020-09-22 14:09:53.638 UTC [1] LOG:  database system is shut down
postgres_1  | 2020-09-22 14:12:03.759 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
postgres_1  | 2020-09-22 14:12:03.759 UTC [1] LOG:  listening on IPv6 address "::", port 5432
postgres_1  | 2020-09-22 14:12:03.762 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
postgres_1  | 2020-09-22 14:12:03.781 UTC [18] LOG:  database system was shut down at 2020-09-22 14:09:53 UTC
postgres_1  | 2020-09-22 14:12:03.790 UTC [1] LOG:  database system is ready to accept connections

Logs do postgres

cuducos commented 4 years ago

Oi, @koukunwlk. Você pode postar os logs do feed com timestamp também? Para eu poder ver qual o status do banco de dados quando o erro foi gerado…

cuducos commented 4 years ago

Sobre o comentário do @LaurianoElmiroDuarte:

Reescrever o algoritmo iterativamente, se possível, geralmente é uma ideia melhor.

Depende do critério de melhor na expressão melhor ideia. Digo isso pois pode existir um bug na lógica que pode ser reescrito com ou sem tail recrusion. E provavelmente se focar nesse bug específico é melhor do que se focar no argumento teórico-purista contra tail recursion. O argumento do Lauriano é perfeito tecnicamente, mas perde o contexto da aplicação.

No caro, a pilha estoura aqui:

def wait_for_postgres(retries=64):
    result = psql("SELECT 1", capture_output=True)
    if not result.stderr:
        return True

    sleep(1)
    print("Waiting for PostgreSQL…")
    retries -= 1
    return wait_for_postgres(retries)

Em teoria, como o retries começa em 64 (segunda linha de código do traceback do @koukunwlk), e depois é chamado na linha 88 inúmeras vezes, decrescido. O problemas é que… não tem nenhum if retries nessa função para interromper o processo caso retries chege em zero. Obrigado, vocês me ajudaram a achar esse bug :purple_heart:

É o bug wue leva ao estouro de pilha. Mais, como cada recursão tem um sleep(1), isso me sugere que teu PostgreSQL pode estar levando ais de 1min para subir… o que é atípico.

Você pode tentar o seguinte:

$ docker-compose up postgres

Esperar a mensagem database system is ready to accept connections e, em outro terminal, chamar docker-compose up feed quando o banco estiver disponível.

cuducos commented 4 years ago

Resumo do bug a ser resolvido

Para quem está interessado no bug em si, essa issue acaba por aqui. O restante é uma ajuda específica ao @LeonardoFurtado : )

koukunwlk commented 4 years ago 
feed_1      | Waiting for PostgreSQL…
feed_1      | Waiting for PostgreSQL…
feed_1      | Waiting for PostgreSQL…
feed_1      | Waiting for PostgreSQL…
feed_1      | Traceback (most recent call last):
feed_1      |   File "import.py", line 130, in <module>
feed_1      |     main()
feed_1      |   File "import.py", line 104, in main
feed_1      |     if wait_for_postgres() and tables_exist():
feed_1      |   File "import.py", line 88, in wait_for_postgres
feed_1      |     return wait_for_postgres(retries)
feed_1      |   File "import.py", line 88, in wait_for_postgres
feed_1      |     return wait_for_postgres(retries)
feed_1      |   File "import.py", line 88, in wait_for_postgres
feed_1      |     return wait_for_postgres(retries)
feed_1      |   [Previous line repeated 984 more times]
feed_1      |   File "import.py", line 81, in wait_for_postgres
feed_1      |     result = psql("SELECT 1", capture_output=True)
feed_1      |   File "import.py", line 25, in psql
feed_1      |     return run(["psql", POSTGRES_URI, "-c", sql], capture_output=capture_output)
feed_1      |   File "/usr/local/lib/python3.7/subprocess.py", line 488, in run
feed_1      |     with Popen(*popenargs, **kwargs) as process:
feed_1      |   File "/usr/local/lib/python3.7/subprocess.py", line 800, in __init__
feed_1      |     restore_signals, start_new_session)
feed_1      |   File "/usr/local/lib/python3.7/subprocess.py", line 1472, in _execute_child
feed_1      |     for dir in os.get_exec_path(env))
feed_1      |   File "/usr/local/lib/python3.7/os.py", line 635, in get_exec_path
feed_1      |     warnings.simplefilter("ignore", BytesWarning)
feed_1      |   File "/usr/local/lib/python3.7/warnings.py", line 179, in simplefilter
feed_1      |     _add_filter(action, None, category, None, lineno, append=append)
feed_1      |   File "/usr/local/lib/python3.7/warnings.py", line 186, in _add_filter
feed_1      |     filters.remove(item)
feed_1      | RecursionError: maximum recursion depth exceeded in comparison
feed_1      | Waiting for PostgreSQL…
feed_1      | Waiting for PostgreSQL…
feed_1      | Waiting for PostgreSQL…

Oi, tentei usando o docker-compose up postegres, porem deu o mesmo erro.

cuducos commented 4 years ago

Oi @koukunwlk, vamos lá! Tu podes me dizer mais ou menos quanto você entende de Docker para me ajudar a te ajudar? Digo isso pois perguntei sobre logs com timestamp e vc me mandou logs sem timestamp, então fico na mesma, sem nada novo para te ajudar a explorar.

Na minha cabeça tem duas coisas claras:

  1. O resolver o bug encontrado provavelmente não vai resolver teu problema
  2. Teu problema é que um serviço/container não consegue se conectar ao serviço/container do banco de dados

Para isso, me fiz as seguintes perguntas:

1. Será que o banco de dados está demorando muito para subir?

Para saber isso eu preciso dos logs com marcação de data e hora (e segundos!) dos dois serviços, feed e postgres, ou do log deles intercalados para saber se as tentativas de conexão com o banco de dados acontecem depois ou antes do da mensagem de que o banco de dados está pronto para receber conexões.

Pelo jeito o log do feed sai sem timestamp, então talvez uma alternativa para você pode conseguir isso com (1), docker-compose stop para parar todos os serviços, (b) docker-compose up feed (descarte a saída) e (c) depois compartilhe o resultado de docker-compose logs feed postgres — assim os logs devem sair intercalados.

2. Como está tem .env?

O .env é onde o feed vai buscar as informações para se conectar ao banco de dados (servidor, usuário, senha, etc.). Um errinho de digitação ali pode causar erro de conexão.

3. Como está teu docker-compose.yml?

Ali também existem configurações para que um container “fale” com o outro, então, se tu mudou algo, seria com compartilhar.

4. Manualmente, você consegue ver se no container feed existe a variável de ambiente POSTGRES_URI?

Para testar isso, entre no container e digite um comando que imprime a variável no terminal:

$ docker-compose run --rm feed /bin/bash
Starting minha-receita_postgres_1 ... done
root@620bc673fb34:/feed# echo $POSTGRES_URI
postgres://minhareceita:minhareceita@postgres:5432/minhareceita

5. Manualmente, você consegue se conectar no banco de dados a partir do feed?

Semelhante ao exemplo anterior:

$ docker-compose run --rm feed /bin/bash
Starting minha-receita_postgres_1 ... done
root@23b2276ea67f:/feed# psql $POSTGRES_URI
psql (11.9 (Debian 11.9-1.pgdg100+1), server 11.4)
Type "help" for help.

minhareceita=# \dt
                List of relations
 Schema |      Name       | Type  |    Owner     
--------+-----------------+-------+--------------
 public | cnae            | table | minhareceita
 public | cnae_secundaria | table | minhareceita
 public | empresa         | table | minhareceita
 public | socio           | table | minhareceita
(4 rows)

minhareceita=# \q
root@23b2276ea67f:/feed# exit

Então, se você puder epxlorar essas coisas e ir compartilhando o que descobrir aqui, fica mais fácil da gente destravar isso : )

koukunwlk commented 4 years ago

Consegui!! o problema estava na configuração do $POSTGRES_URI, eu não tenho conhecimento prévio em docker e sou bem novato em python, Consegui popular o banco. porem quando eu subo a API

api_1       | [2020-09-22 20:24:08 +0000] [1] [ERROR] Exception occurred while handling uri: 'http://0.0.0.0:8000/cnpj=0331637000120'
api_1       | Traceback (most recent call last):
api_1       |   File "/root/.local/share/virtualenvs/api-ORERwo9D/lib/python3.7/site-packages/sanic/app.py", line 918, in handle_request
api_1       |     handler, args, kwargs, uri = self.router.get(request)
api_1       |   File "/root/.local/share/virtualenvs/api-ORERwo9D/lib/python3.7/site-packages/sanic/router.py", line 407, in get
api_1       |     return self._get(request.path, request.method, "")
api_1       |   File "/root/.local/share/virtualenvs/api-ORERwo9D/lib/python3.7/site-packages/sanic/router.py", line 470, in _get
api_1       |     raise NotFound("Requested URL {} not found".format(url))
api_1       | sanic.exceptions.NotFound: Requested URL /cnpj=0331637000120 not found
api_1       | [2020-09-22 20:24:08 +0000] - (sanic.access)[INFO][172.18.0.1:39444]: POST http://0.0.0.0:8000/cnpj=0331637000120  404 50

e tento fazer uma consulta, ele me retorna esse erro. Caso eu faça um post somente no "/" ele me retorna "Error: CNPJ não enviado na requisição POST.",

cuducos commented 4 years ago

Consegui!!

Boooa :tada:

Eu não tenho conhecimento prévio em docker e sou bem novato em python

Isso não é problema, espero ter ajudado : )

Consegui popular o banco. porem quando eu subo a API

Vi ali no teu erro: sanic.exceptions.NotFound: Requested URL /cnpj=0331637000120 not found

Essa URL não existe mesmo. Como mostra essa tabela, a única URL existente é / (não existe /cnpj=033…). A parte cnpj=033… tem que ser enviada no corpo de uma requisição do tipo POST.

Com o curl tem um exemplo na documentação. Com você está tentando fazer a requisição?

koukunwlk commented 4 years ago

Eu fiz a requisição usando o exemplo na primeira vez, porem, sem sucesso. Eu sou iniciante e estou aprendendo a usar API's, no caso o corpo da requisição tem que ir em JSON?

cuducos commented 4 years ago

Eu fiz a requisição usando o exemplo na primeira vez

Qual exemplo? Me dê detalhes para me ajudar a te ajudar. Na minha mensagem, falei do curl que aparece na documentação. Qual aplicativo você utilizou? Qual comando entrou? Qual a saída?

koukunwlk commented 4 years ago

Eu tentei fazer usando curl como estava no exemplo, tentei também pelo insomnia

cuducos commented 4 years ago

Eu vou aguardar a resposta das duas perguntas que você ignorou, senão não consigo te ajudar:

Qual aplicativo você utilizou? Qual comando entrou? Qual a saída?

Digo isso pois tua primeira resposta é incoerente com o log. Compartilhe tudo, copiando e colando, assim eu vejo exatamente o que foi digitado e o que veio de retorno.

koukunwlk commented 4 years ago

Faço uma requisição com o curl

curl -i -X POST  cnpj=19131243000197 0.0.0.0:8000
curl: (6) Could not resolve host: cnpj=19131243000197
HTTP/1.1 404 Not Found
Connection: keep-alive
Keep-Alive: 5
Content-Length: 46
Content-Type: text/plain; charset=utf-8

Error: CNPJ não enviado na requisição POST

a api me retorna isso:

Attaching to minha-receita_api_1
api_1       | [2020-09-23 11:34:33 +0000] [1] [INFO] Goin' Fast @ http://0.0.0.0:8000
api_1       | [2020-09-23 11:34:33 +0000] [1] [INFO] Starting worker [1]
api_1       | [2020-09-23 12:25:52 +0000] [1] [ERROR] Exception occurred while handling uri: 'http://0.0.0.0:8000/'
api_1       | Traceback (most recent call last):
api_1       |   File "/root/.local/share/virtualenvs/api-ORERwo9D/lib/python3.7/site-packages/sanic/app.py", line 942, in handle_request
api_1       |     response = await response
api_1       |   File "/api/api/__init__.py", line 18, in search
api_1       |     raise NotFound("CNPJ não enviado na requisição POST.")
api_1       | sanic.exceptions.NotFound: CNPJ não enviado na requisição POST.
api_1       | [2020-09-23 12:25:52 +0000] - (sanic.access)[INFO][172.18.0.1:58122]: POST http://0.0.0.0:8000/  404 46
cuducos commented 4 years ago

Bingo! Está faltando um -f na chamada do curl, antes do cnpj=033… ✨

koukunwlk commented 4 years ago

Colocando o -f

curl -i -X POST -f cnpj=19131243000197 0.0.0.0:8000
curl: (6) Could not resolve host: cnpj=19131243000197
curl: (22) The requested URL returned error: 404 Not Found

na api:

api_1       | [2020-09-23 12:42:45 +0000] [1] [INFO] Goin' Fast @ http://0.0.0.0:8000
api_1       | [2020-09-23 12:42:45 +0000] [1] [INFO] Starting worker [1]
api_1       | [2020-09-23 12:42:48 +0000] [1] [ERROR] Exception occurred while handling uri: 'http://0.0.0.0:8000/'
api_1       | Traceback (most recent call last):
api_1       |   File "/root/.local/share/virtualenvs/api-ORERwo9D/lib/python3.7/site-packages/sanic/app.py", line 942, in handle_request
api_1       |     response = await response
api_1       |   File "/api/api/__init__.py", line 18, in search
api_1       |     raise NotFound("CNPJ não enviado na requisição POST.")
api_1       | sanic.exceptions.NotFound: CNPJ não enviado na requisição POST.
api_1       | [2020-09-23 12:42:48 +0000] - (sanic.access)[INFO][172.18.0.1:58274]: POST http://0.0.0.0:8000/  404 46
cuducos commented 4 years ago

Repare o que o erro está te dizendo: Could not resolve host: cnpj=19131243000197.

A tua versão do curl está interpretando o que vem depois do -f como o servidor (host), e não como o dado de formulário. Ou seja… você encontrou mais um bug — dessa vez, na documentação!

Reli aqui a documentação do curl e podes tentar com -d ao invés de -f?

koukunwlk commented 4 years ago

tentei com -d me retornou:

 curl -i -X POST -d cnpj=19131243000197 0.0.0.0:8000
HTTP/1.1 500 Internal Server Error
Connection: keep-alive
Keep-Alive: 5
Content-Length: 144
Content-Type: text/html; charset=utf-8

    <h1>Internal Server Error</h1>
    <p>
        The server encountered an internal error and cannot complete
        your request.
    </p>

na api:

api_1       | Traceback (most recent call last):
api_1       |   File "/root/.local/share/virtualenvs/api-ORERwo9D/lib/python3.7/site-packages/sanic/app.py", line 942, in handle_request
api_1       |     response = await response
api_1       |   File "/api/api/__init__.py", line 24, in search
api_1       |     async with connect() as connection:
api_1       |   File "/usr/local/lib/python3.7/contextlib.py", line 170, in __aenter__
api_1       |     return await self.gen.__anext__()
api_1       |   File "/api/api/db.py", line 19, in connect
api_1       |     pool = await aiopg.create_pool(dsn)
api_1       |   File "/root/.local/share/virtualenvs/api-ORERwo9D/lib/python3.7/site-packages/aiopg/pool.py", line 155, in from_pool_fill
api_1       |     await self._fill_free_pool(False)
api_1       |   File "/root/.local/share/virtualenvs/api-ORERwo9D/lib/python3.7/site-packages/aiopg/pool.py", line 199, in _fill_free_pool
api_1       |     **self._conn_kwargs)
api_1       |   File "/root/.local/share/virtualenvs/api-ORERwo9D/lib/python3.7/site-packages/aiopg/connection.py", line 551, in _connect
api_1       |     await self._poll(self._waiter, self._timeout)
api_1       |   File "/root/.local/share/virtualenvs/api-ORERwo9D/lib/python3.7/site-packages/aiopg/connection.py", line 207, in _poll
api_1       |     await asyncio.wait_for(self._waiter, timeout, loop=self._loop)
api_1       |   File "/usr/local/lib/python3.7/asyncio/tasks.py", line 442, in wait_for
api_1       |     return fut.result()
api_1       |   File "/root/.local/share/virtualenvs/api-ORERwo9D/lib/python3.7/site-packages/aiopg/connection.py", line 106, in _ready
api_1       |     state = self._conn.poll()
api_1       | psycopg2.OperationalError: could not connect to server: Connection refused
api_1       |   Is the server running on host "localhost" (127.0.0.1) and accepting
api_1       |   TCP/IP connections on port 5432?
api_1       | could not connect to server: Cannot assign requested address
api_1       |   Is the server running on host "localhost" (::1) and accepting
api_1       |   TCP/IP connections on port 5432?
api_1       | 
api_1       | [2020-09-23 12:58:17 +0000] - (sanic.access)[INFO][172.18.0.1:58526]: POST http://0.0.0.0:8000/  500 144
cuducos commented 4 years ago

A mensagem de erro está dizendo que teu banco de dados não está rodando em localhost:

api_1       | psycopg2.OperationalError: could not connect to server: Connection refused
api_1       |   Is the server running on host "localhost" (127.0.0.1) and accepting
api_1       |   TCP/IP connections on port 5432?

Ele não deveria. Já pedi teu .env e você não compartilhou. Fica difícil te ajudar assim : (

koukunwlk commented 4 years ago

:c eu to tentando, desculpa

SANIC_HOST=0.0.0.0
SANIC_PORT=8000
SANIC_DEBUG=False

POSTGRES_URI=postgres://postgres:123456@postgres:5432/minhareceita
POSTGRES_PASSWORD=123456
POSTGRES_USER=postgres
POSTGRES_DB=minhareceita
POSTGRES_HOST=localhost
POSTGRES_PORT=5432

meu env

cuducos commented 4 years ago

O teu POSTGRES_HOST está diferente do recomendado no .env.sample, pode ser isso… Tente mudar para POSTGRES_HOST=postgres e veja que que dá ; )

koukunwlk commented 4 years ago

Consegui, desde já muito obrigado, pela paciência em me explicar os meus erros, eu aprendi muito so configurando o programa e espero aprender ainda mais consumido a API que vocês desenvolveram. Obrigado!!!

cuducos commented 4 years ago

Uhuu :tada: Aí sim, ganhei meu dia :purple_heart: