Bom, agora com o cache reativado, está fazendo menos consultas no banco
(somente os inserts que precisam) e o tempo de processamento voltou para
125 linhas por minuto. Ainda assim, no inicio, o código processou 3888
linhas no primeiro minuto, e depois foi decaindo. Como o PHP nao está
engargalando nem na memoria (mal ocupa 500MB em uma máquina com 128GB de
ram), o gargalo ainda parece ser a quantidade de registrar que tem no banco
(no momento 943.238 apenas, o que não deveria ser um problema).

O tempo que deve levar para processar foi melhorado de 81 horas para 44
horas, o que ainda assim é um exagero, e pensando que a performance eh
degradante, nao deve se manter muito rápido por muito tempo.

Alguma outra idéia além desses parâmetros que eu passei que poderiam dar
uma ajuda?

AH!!!

OS LOGS!!! Acho que descobri o gargalo!

2017-03-12 22:34:44.304 UTC [19347] xpreso@geoagent_dev LOG:  execute
pdo_stmt_00000714: select * from "geofinder"."postcode_locus" where
("postcode_id" = $1 and "locus_id" = $2) limit 1
2017-03-12 22:34:44.304 UTC [19347] xpreso@geoagent_dev DETAIL:
 parameters: $1 = '41927', $2 = '2044027'
2017-03-12 22:34:44.366 UTC [19347] xpreso@geoagent_dev LOG:  duration:
62.482 ms
2017-03-12 22:34:44.366 UTC [19347] xpreso@geoagent_dev LOG:  statement:
DEALLOCATE pdo_stmt_00000714
2017-03-12 22:34:44.366 UTC [19347] xpreso@geoagent_dev LOG:  duration:
0.029 ms
2017-03-12 22:34:44.367 UTC [19347] xpreso@geoagent_dev LOG:  duration:
0.043 ms
2017-03-12 22:34:44.367 UTC [19347] xpreso@geoagent_dev LOG:  duration:
0.025 ms
2017-03-12 22:34:44.367 UTC [19347] xpreso@geoagent_dev LOG:  execute
pdo_stmt_00000715: insert into "geofinder"."postcode_locus" ("postcode_id",
"locus_id") values ($1, $2) returning "id"
2017-03-12 22:34:44.367 UTC [19347] xpreso@geoagent_dev DETAIL:
 parameters: $1 = '41927', $2 = '2044027'
2017-03-12 22:34:44.367 UTC [19347] xpreso@geoagent_dev LOG:  duration:
0.036 ms
2017-03-12 22:34:44.367 UTC [19347] xpreso@geoagent_dev LOG:  statement:
DEALLOCATE pdo_stmt_00000715
2017-03-12 22:34:44.367 UTC [19347] xpreso@geoagent_dev LOG:  duration:
0.018 ms
2017-03-12 22:34:44.367 UTC [19347] xpreso@geoagent_dev LOG:  duration:
0.045 ms
2017-03-12 22:34:44.367 UTC [19347] xpreso@geoagent_dev LOG:  duration:
0.046 ms
2017-03-12 22:34:44.367 UTC [19347] xpreso@geoagent_dev LOG:  execute
pdo_stmt_00000716: select * from "geofinder"."postcode_locus_name" where
("postcode_id" = $1 and "locus_name_id" = $2) limit 1
2017-03-12 22:34:44.367 UTC [19347] xpreso@geoagent_dev DETAIL:
 parameters: $1 = '41927', $2 = '2044023'
2017-03-12 22:34:44.430 UTC [19347] xpreso@geoagent_dev LOG:  duration:
62.315 ms
2017-03-12 22:34:44.430 UTC [19347] xpreso@geoagent_dev LOG:  statement:
DEALLOCATE pdo_stmt_00000716
2017-03-12 22:34:44.430 UTC [19347] xpreso@geoagent_dev LOG:  duration:
0.033 ms
2017-03-12 22:34:44.430 UTC [19347] xpreso@geoagent_dev LOG:  duration:
0.050 ms
2017-03-12 22:34:44.430 UTC [19347] xpreso@geoagent_dev LOG:  duration:
0.028 ms


Em 12 de março de 2017 22:15, Pablo Sánchez <[email protected]> escreveu:

> Acho que achei o problema: o cache realmente não está funcionando, quer
> dizer, está inchando, mas está toda a hora batendo no banco com um milhão
> de consultas que deveriam pegar do cache. Ê KCT! XD
>
> Vou corrigir isso. Só vi quando ativei o log das statements mesmo. Valeu
> por me lembrar disso. Tem uma semana que estou escrevendo o código e estava
> de boa até comecar a popular o banco para valer, é tanta recursividade que
> eu fiquei meio lelé.
>
> Em 12 de março de 2017 22:05, Pablo Sánchez <[email protected]> escreveu:
>
>> Bom, como evidencia tenho o fato de que matar o processo e iniciar
>> novamente (o que liberaria os recursos) nao está mudando a velocidade do
>> processamento.
>>
>> O arquivo em si é pequeno (um CSV de 115MB) que é processado linha a
>> linha, esquecendo completamente o que foi processado ao mudar de linha e
>> liberando. Sem a persistencia, a leitura e cacheamento dos objetos na
>> memoria duram minutos (questao de uns 3 minutos apenas).
>>
>> Eu realmente nao logei todas as statements no servidor, e estou matando o
>> processo novamente agora para entao, novamente, iniciar o processo e ver o
>> log.
>>
>> Eis o que já foi feito até o momento no postgresql.conf:
>>
>> shared_buffers = 4GB
>> work_mem = 32GB
>> dynamic_shared_memory_type = posix
>> fsync =  off
>> synchronous_commit =off
>> full_page_writes = off
>> wal_buffers = -1
>> commit_delay =0
>> commit_siblings = 1
>> effective_cache_size = 4GB
>> logging_collector = off
>> log_min_error_statement = panic
>> log_min_duration_statement = -1
>>
>> Agora vou definir log_statement='all' e já digo o que aconteceu.
>>
>> Obs: se eu tiver baguncado alguma configuracão acima, fique livre para me
>> corrigir, porque eu realmente já estou dando pipoco aqui. XD
>>
>>
>> Em 12 de março de 2017 21:10, Tiago José Adami <[email protected]>
>> escreveu:
>>
>>> Em 12 de março de 2017 17:40, Pablo Sánchez <[email protected]>
>>> escreveu:
>>> > Estou quase pensando em processar o CSV e criar CSV's por separado para
>>> > fazer o copy mesmo.
>>> >
>>> > É um modelo de enderecos basicamente, com apenas umas 8 tabelas, onde
>>> um
>>> > endereco/locus pode ser pai de outro. Ex: Brasil é pai de DF que é pai
>>> de
>>> > Brasília, que é pai de asa sul, que é pai de SQS 116 que é pai de
>>> bloco G,
>>> > por exemplo. Entao a linha tem que ser decomposta, buscar o pai no
>>> banco se
>>> > já existe (mas eu cacheio pelo hash do objeto que foi gerado no PHP
>>> para não
>>> > ficar indo no banco o tempo todo), e aí tem tipos e etc que também são
>>> > cacheados. Ou seja, nada de outro planeta.
>>> >
>>> > Só que está degradando, e não é no PHP, pois é save que
>>> automaticamente o
>>> > arquivo todo é processado em questão de minutos, e o consumo de
>>> memória mal
>>> > chega a 500MB.
>>> >
>>> > Agora estou em 300.000 registros já, e a velocidade está em 20 linhas
>>> do CSV
>>> > por, mas no comeco, no primeiro minuto, ele processa facilmente 2000
>>> linhas.
>>> > Enfim... Tá foda. :-D
>>>
>>> Pablo, no início você escreveu sobre o problema: "que não tem relacão
>>> com o código, mas sim o Postgres".
>>>
>>> Ainda não ficou claro onde está o problema. Parece que você não está
>>> fazendo uma importação direto no banco de dados, haja vista que "o
>>> arquivo todo é processado em questão de minutos".
>>>
>>> Quais as suas evidências para ter certeza que o problema é no Postgres?
>>>
>>> Você chegou a configurar os logs do PostgreSQL para gravar todos os
>>> comandos SQL e o tempo de execução de cada um?
>>>
>>> Os comandos SQL são enviados para o banco de dados com que frequência?
>>>
>>> Você pouco detalhou o procedimento, mas pelo o que eu estou imaginando
>>> você importou o arquivo todo para uma tabela na sua forma original (um
>>> registro por linha) e depois passou a ler e processar todos os
>>> registros desta tabela (ou do cache do PHP) gravando em outras
>>> tabelas, é isso?
>>>
>>> Especifique exatamente o(s) ponto(s) em que o Postgres está demorando
>>> e detalhe melhor o seu processo para podermos ajudá-lo.
>>>
>>> Adami
>>> _______________________________________________
>>> pgbr-geral mailing list
>>> [email protected]
>>> https://listas.postgresql.org.br/cgi-bin/mailman/listinfo/pgbr-geral
>>>
>>
>>
>>
>> --
>>
>>
>>
>>
>>
>> *Pablo Santiago Sánchez*
>> ZCE ZEND006757
>> [email protected]
>> (61) 9843-0883
>> http://www.sansis.com.br
>> *"Pluralitas non est ponenda sine necessitate"*
>>
>
>
>
> --
>
>
>
>
>
> *Pablo Santiago Sánchez*
> ZCE ZEND006757
> [email protected]
> (61) 9843-0883
> http://www.sansis.com.br
> *"Pluralitas non est ponenda sine necessitate"*
>



-- 





*Pablo Santiago Sánchez*
ZCE ZEND006757
[email protected]
(61) 9843-0883
http://www.sansis.com.br
*"Pluralitas non est ponenda sine necessitate"*
_______________________________________________
pgbr-geral mailing list
[email protected]
https://listas.postgresql.org.br/cgi-bin/mailman/listinfo/pgbr-geral

Responder a