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

dados duplicados e importação parada em 98% #146

Closed italoag closed 2 years ago

italoag commented 2 years ago

Estou tendo problemas para importar os últimos dados de setembro, na primeira fase de criação do JSON data para cada CNPJ existe um registro que estranhamente está duplicado e mesmo corrigindo esse registro a importação para em 98%.

o registro duplicado é o CNPJ -> 8464718000140, apaguei o registro logo após ele ser inserido aos 48% da fase Creating the JSON data for each CNPJ ele é inserido novamente aos 93%.

VM1 - GCP 8 cores - 32GB Adding base CNPJ, partners and taxes info 98% (104729130/106151828, 2509 it/s) [18h37m56s:9m27s]Closing readers...

VM1 - Azure 8 cores 32GB Adding base CNPJ, partners and taxes info 98% | (104718336/106151828, 18057 it/s) [7h59m9s:7m51s]Closing readers…

estou executando com a opção --no-privacy configurações padrão.

cuducos commented 2 years ago

Estou tendo problemas para importar os últimos dados de setembro

Ainda não consegui baixar a base de setembro (já reclamei no FalaBR).

Tem alguma amostra dos dados que eu consiga reproduzir o erro aqui?

UPDATE Aliás, obrigado por reportar o bug 💜

urbancompasspony commented 2 years ago

Também estou com o mesmo problema. Mesmo CNPJ duplicado na hora de rodar a importação, ele dá erro e gera um PANIC. Não identifiquei exatamente aonde ele causa o erro, vou depurar e reporto logo. Mas é o mesmo CNPJ citado: 8464718000140

Build local num Ryzen 3.

Eu consegui baixar os dados de 11/09/22 e hospedei na minha nuvem particular: https://cs.linuxuniverse.com.br/index.php/s/8gCFMgFKkdsqKWs Fiquem à vontade, o download será bem melhor. Baixem 1 por vez pra não pesar muito aqui.

Aos amigos que tiverem dificuldade com o download direto da Receita, recomendo uma extensão para o Chrome pra gerenciar os downloads, vai sofrido mas vai depois de 1 semana kkkkkkkkk Esta: chrome://extensions/?id=nljkibfhlpcnanjgbnlnbjecgicbjkge

cuducos commented 2 years ago

Muito obrigado, @urbancompasspony. Baixado.

Algum de vocês pode postar o erro completo aqui que aparece no CLI do Minha Receita? Ainda não peguei no código, mas estou estudando PostgreSQL para ver algumas possibilidades.

urbancompasspony commented 2 years ago

Detalharei o máximo que puder pra ajudar. Estou configurando o meu pelo Docker.

Eu iniciei um terminal com:

$ docker-compose up

Ou seja, quando o minha-receita-main_postgres_1 inicia, e deixei aberto pra ver em tempo real.

E em outro terminal eu rodei este:

$ docker-compose run --rm minha-receita transform --no-privacy -d /mnt/data/

Que é o início do container minha-receita-main_minha-receita_run.

No terminal do minha-receita-main_postgres_1 o erro fica descrito como:

postgres_test_1  | 2022-10-03 19:34:58.559 UTC [1] LOG:  database system is ready to accept connections
postgres_1       | 2022-10-03 20:35:49.802 UTC [5358] ERROR:  duplicate key value violates unique constraint "cnpj_pkey"
postgres_1       | 2022-10-03 20:35:49.802 UTC [5358] DETAIL:  Key (id)=(8464718000140) already exists.
postgres_1       | 2022-10-03 20:35:49.802 UTC [5358] CONTEXT:  COPY cnpj, line 6282
postgres_1       | 2022-10-03 20:35:49.802 UTC [5358] STATEMENT:  COPY  cnpj FROM STDIN DELIMITER ',' CSV HEADER;
postgres_1       | 2022-10-03 23:59:29.705 UTC [5417] LOG:  incomplete message from client
postgres_1       | 2022-10-03 23:59:29.705 UTC [5417] CONTEXT:  COPY cnpj, line 6270
postgres_1       | 2022-10-03 23:59:29.705 UTC [5417] STATEMENT:  COPY  cnpj FROM STDIN DELIMITER ',' CSV HEADER;
postgres_1       | 2022-10-03 23:59:29.727 UTC [5417] ERROR:  unexpected EOF on client connection with an open transaction
postgres_1       | 2022-10-03 23:59:29.727 UTC [5417] CONTEXT:  COPY cnpj, line 6270
postgres_1       | 2022-10-03 23:59:29.727 UTC [5417] STATEMENT:  COPY  cnpj FROM STDIN DELIMITER ',' CSV HEADER;
postgres_1       | 2022-10-03 23:59:29.728 UTC [5417] FATAL:  terminating connection because protocol synchronization was lost
postgres_1       | 2022-10-03 23:59:29.728 UTC [5417] LOG:  could not send data to client: Broken pipe

E lá no minha-receita-main_minha-receita_run o momento do erro fica semelhante. O erro é:

Creating the JSON data for each CNPJ  78% || (42590208/53963368, 25391 it/s) [1h4m34s:7m27s]Error: error saving companies: error saving companies: error while importing data to postgres ERROR:  duplicate key value violates unique constraint "cnpj_pkey"
DETAIL:  Key (id)=(8464718000140) already exists.
CONTEXT:  COPY cnpj, line 2573
: exit status 1
panic: send on closed channel

goroutine 98 [running]:
github.com/cuducos/minha-receita/transform.(*venuesTask).consumeRows(0xc00019a000)
    /minha-receita/transform/venues.go:86 +0x2e5
created by github.com/cuducos/minha-receita/transform.(*venuesTask).run
    /minha-receita/transform/venues.go:119 +0x158
ERROR: 2

Espero que isso ajude a elucidar a questão.

cuducos commented 2 years ago

Muito obrigado, @urbancompasspony. Consegui confirmar o que eu queria.

Eu tentei simular com uma base de dados menor e parece que #147 resolve. Mas ainda não consegui testar com os ~55 milhões de CNPJs para ver se a lentidão de verificar num cache é aceitável.

Se quiser testar e comentar no PR, sinta-se em casa. Vou ver se testo essa branch com os dados todos amanhã!

urbancompasspony commented 2 years ago

Opa, maravilha. Vou começar uma nova build. Mais tarde retorno se isso resolve o erro! Abraços

EDIT: Comecei a Build agora às 19:50, de fato ele está um pouco mais lento, mas vejo como um feature, não bug. Faço builds locais e o PC agora não trava como antes, essa "lentidão" dá mais time slices de processamento para o resto do sistema. Mais tarde quando concluir reporto o resultado.

urbancompasspony commented 2 years ago

Atualizei o post acima com o erro completo de ambos os terminais, tinha mais coisas no primeiro tambem.

Mesmo com o novo pull ele deu erro também. Mas eu acho que cometi alguns erros, vou limpar toda a instalação e começar do zero. - Imaginei que ele deduplicaria então poderia passar por cima do que já existe e poupar tempo mas foi um ato leigo meu, perdão.

Volto mais tarde com novidades.

cuducos commented 2 years ago

Mesmo com o novo pull ele deu erro também.

Não esquece de dar um build na imagem do Docker. Senão o código está atualiado, mas o container q vc está rodando não ; )

urbancompasspony commented 2 years ago

Mesmo com o novo pull ele deu erro também.

Não esquece de dar um build na imagem do Docker. Senão o código está atualiado, mas o container q vc está rodando não ; )

Putz, essa fui noob, esqueci de rebuildar mesmo kkkkkkk refazer tudo do zero. Aviso qqr novidade

italoag commented 2 years ago

vocês conseguiram importar depois que passa do registro duplicado? O meu fica parado nos 98% da ultima fase.

cuducos commented 2 years ago

Bem estranho, mas muito obrigado pelo feedback, @urbancompasspony. Rascunhei uma solução melhor aqui: #149 — vou tentar testar mais tarde.

urbancompasspony commented 2 years ago

Eu cometi um grande erro de nao ter pego o código do pull request, porque não foi merged. DE fato ta BEM mais lento que o anterior, +1h e 40% ainda. Sem erros por enquanto, aviso qualquer novidade. To rodando a build na edição de ontem. Reporto os erros dela se houverem.

cuducos commented 2 years ago

Isso no #147, né?

Estou testando agora o #149, deve ser melhor.

cuducos commented 2 years ago

vocês conseguiram importar depois que passa do registro duplicado?

Pela lógica que eu lembro, não é para terminar, @italoag. Pois isso siginificaria que a base está incompleta, e é melhor encerrar com o erro. Estranho estar parado…

urbancompasspony commented 2 years ago

Exato, estou no #147, na verdade tem +2h que ta rodando e ta em 40%. Agora que vi o novo #149. Vou esperar terminar pra ter uma margem melhor de depuração; vou anotar os erros que der e testo o 149 em seguida.

Edit: cancelei, vou direto pro #149

italoag commented 2 years ago

vou fazer um teste com a #149 e ver se muda alguma coisa aí registro os erros encontrados com mais detalhes. Só achei estranho pq verifiquei os arquivos e aparentemente estão todos certo.

urbancompasspony commented 2 years ago

Passando pra informar que houve um imprevisto no desenvolvimento vou ter que refatorar tudo. Inclusive por isso não vou mais usar o código. A build tava prevista pra terminar em 9h, parei ela, então não vou reportar problemas. Até aonde a build foi, não haviam erros. O time pediu umas features extras que vão demandar a construção de um código totalmente novo, não vou poder aproveitar este como eu gostaria. Agradeço a paciência e atenção na solução dos problemas relatados, espero que o amigo @cuducos consiga resolver os bugs e o @italoag consiga usa-lo. Abraços.

cuducos commented 2 years ago

Aqui o #149 funcionou liso.

Está agora na parte de enriquecimento (ou seja outro processo: incluir nos CNPJs criados o quadro societário, informações do Simples etc.)

Assim que terminar, faço o merge.

italoag commented 2 years ago

@cuducos fiz um teste com a versão #149 e fica congelado em 98% não apresenta nenhum erro simplesmente para, capturei o log do processamento, no banco estranhamente não ocorre nenhum erro.

2022/10/04 17:58:14 Dropping table public.cnpj… 2022/10/04 17:58:20 Creating table public.cnpj… 2022/10/04 17:58:20 Saving the updated at date to the database… 2022/10/04 17:58:20 Loading Estabelecimentos files… Creating the JSON data for each CNPJ 100% | (53963368/53963368, 63594 it/s) 2022/10/04 18:18:55 Creating indexess… 2022/10/04 18:44:19 Loading Empresas files… 2022/10/04 18:45:51 Loading Socios files… 2022/10/04 18:46:40 Loading Simples files… Adding base CNPJ, partners and taxes info 98% | (104718336/106151828, 1721 it/s) [7h30m42s:13m52s]Closing readers… Adding base CNPJ, partners and taxes info 98% | (104973002/106151828, 24471 it/s) [7h31m13s:48s]

Parece que é algo relacionado ao GC, ou alguma questão de memória, pq ele subitamente sobe o nr de iterações de 1721 para 24471 e então trava, percebi também que a aplicação estava consumindo muita memória agora no fim do processamento, cerca de 5.4Gb após travar ela caiu para 480Mb e em seguida foi para 160Mb

Testou testando em duas VMs AMD Epyc 8 vCPUs 32Gi - uma na Azure e outra no GCP, OS Ubuntu 22.04

cuducos commented 2 years ago

Ok. Vamos por partes.

Creating the JSON data for each CNPJ 100% | (53963368/53963368, 63594 it/s)

Isso diz que essa issue está resolvida. O problema de inserção de dados que causava duplicate key value violates unique constraint "cnpj_pkey" só faz sentido nessa etapa.

fica congelado em 98%

Isso pode ser outro bug. Estou rodando o processo aqui também, vamos ver se descubro algo. O comportamento tem muita cara de esgotamento de recurso (memória, espaço em disco, seja na máquina rodando o processo, seja na máquina do banco de dados).

Closing readers…

Isso diz que todos os CSVs foram lidos e os dados foram enfileirados para serem inseridos no banco de dados. Como pára nos 98%, o problema deve estar na escrita no banco de dados. Vc consegue compartilhar os logs do Postgres?

italoag commented 2 years ago

Meu Postgres esta rodando na configuração padrão do container alpine-postgres-14, então não esta enviando os logs detalhados, mas peguei esse erro aqui que ocorreu um pouco antes dele congelar. Só que eu havia aumentado o numero de conexões para 500.

2022-10-05 07:59:24.062 UTC [28] ERROR: canceling autovacuum task 2022-10-05 07:59:24.062 UTC [28] CONTEXT: while scanning block 630576 of relation "public.cnpj" automatic vacuum of table "minhareceita.public.cnpj" 2022-10-05 08:10:11.859 UTC [155] FATAL: sorry, too many clients already 2022-10-05 08:10:11.959 UTC [156] FATAL: sorry, too many clients already 2022-10-05 08:10:12.006 UTC [157] FATAL: sorry, too many clients already 2022-10-05 08:10:12.124 UTC [158] FATAL: sorry, too many clients already 2022-10-05 08:10:12.144 UTC [159] FATAL: sorry, too many clients already 2022-10-05 08:10:12.166 UTC [160] FATAL: sorry, too many clients already 2022-10-05 08:10:12.167 UTC [161] FATAL: sorry, too many clients already 2022-10-05 08:10:12.195 UTC [162] FATAL: sorry, too many clients already 2022-10-05 08:10:12.223 UTC [163] FATAL: sorry, too many clients already 2022-10-05 08:10:12.231 UTC [164] FATAL: sorry, too many clients already 2022-10-05 08:10:12.268 UTC [165] FATAL: sorry, too many clients already 2022-10-05 08:10:12.367 UTC [166] FATAL: sorry, too many clients already 2022-10-05 08:10:12.371 UTC [167] FATAL: sorry, too many clients already 2022-10-05 08:10:12.406 UTC [168] FATAL: sorry, too many clients already 2022-10-05 08:10:12.420 UTC [169] FATAL: sorry, too many clients already 2022-10-05 08:10:12.421 UTC [170] FATAL: sorry, too many clients already 2022-10-05 08:10:12.431 UTC [171] FATAL: sorry, too many clients already 2022-10-05 08:10:12.455 UTC [172] FATAL: sorry, too many clients already 2022-10-05 08:10:12.459 UTC [173] FATAL: sorry, too many clients already 2022-10-05 08:10:12.475 UTC [174] FATAL: sorry, too many clients already 2022-10-05 08:10:12.476 UTC [175] FATAL: sorry, too many clients already 2022-10-05 08:10:12.497 UTC [176] FATAL: sorry, too many clients already 2022-10-05 08:10:12.522 UTC [177] FATAL: sorry, too many clients already 2022-10-05 08:10:12.556 UTC [178] FATAL: sorry, too many clients already 2022-10-05 08:10:12.559 UTC [179] FATAL: sorry, too many clients already 2022-10-05 08:10:12.568 UTC [181] FATAL: sorry, too many clients already 2022-10-05 08:10:12.572 UTC [182] FATAL: sorry, too many clients already 2022-10-05 08:10:12.578 UTC [180] FATAL: sorry, too many clients already

Aparentemente as conexões não estão sendo encerradas.

As VMs uma possue SSD de 300Gi outra um NMVe de 300Gi para o PostgreSQL/Aplicação e outro de 50Gi do sistema.

Agora estou rodando novamente em uma VM Serie E do GCP com 64Gi e 16 vCPU no GCP. abaixo o gráfico de consumo.

image

Você pode notar que ele praticamente não usa o CPU mas a aplicação está consumindo 11Gi de memória.

cuducos commented 2 years ago

CPU é o de menos nessa aplicação. O gargalo é total I/O no banco. FATAL: sorry, too many clients already me diz que teu banco não está aguentando o volume de conexões…

Só que eu havia aumentado o numero de conexões para 500.

Não entendi se vc:

  1. configurou o PostgreSQL para aceitar 500 conexões
  2. ou configurou o minha-receita para utilizar 500 conexões
italoag commented 2 years ago

@cuducos o banco está configurado para aceitar 500 conexões e o minha-receita para utilizar 64. O que não faz muito sentido é que já rodei em várias máquinas diferentes e o resultado é sempre o mesmo, com configurações que vão de 2 vCPUs, 8Gi até 16 vCPUs com 64Gi, eu percebo que a performance vai degradando com o passar do tempo, caindo a performance de +/-10000 it/s para +/-2000 it/s entre os 2% e os 80%

Vocês costumam executar utilizando as configurações padrão do docker certo? fazem isso em cloud ou bare metal?

cuducos commented 2 years ago

Vocês costumam executar utilizando as configurações padrão do docker certo?

Eu costumo usar DBaaS, como descrito nessa novela aqui hahaha…

italoag commented 2 years ago

A performance do disco está razoável também. Se levar em conta que o minha-receita está rodando ela está bem aderente a um disco SSD.

ioping -q -c 10 -s 8k .

--- . (ext4 /dev/sda1 387.5 GiB) ioping statistics --- 9 requests completed in 1.08 ms, 72 KiB read, 8.37 k iops, 65.4 MiB/s generated 10 requests in 9.00 s, 80 KiB, 1 iops, 8.89 KiB/s min/avg/max/mdev = 80.1 us / 119.5 us / 175.6 us / 34.6 us

cuducos commented 2 years ago

Não acho que o ioping dá conta dessa complexidade de IO que o Postres tem nessa etapa, ou seja, 104.973.002 (mais de 104 milhões) de execuções dessa query ou dessa outra query.