[gitec] SAPL lento com milhares de documentos

Adriano Rafael Gomes adriano-gomes em camaranh.rs.gov.br
Terça Março 5 16:52:16 BRT 2013


Olá, lista.

Solicito a ajuda de vocês para resolver o problema de lentidão no SAPL da
nossa Câmara, conforme descrevo a seguir.

O servidor
----------

Meu servidor é uma VM Xen com 4GB de RAM.

$ free -m
             total       used       free     shared    buffers     cached
Mem:          4065       4044         20          0         24       1577
-/+ buffers/cache:       2443       1622
Swap:         1023         14       1009

$ cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 6
model           : 15
model name      : Intel(R) Xeon(R) CPU           E5310  @ 1.60GHz
stepping        : 7
cpu MHz         : 1600.039
cache size      : 4096 KB
fpu             : yes
fpu_exception   : yes
cpuid level     : 10
wp              : yes
flags           : fpu de tsc msr pae cx8 sep cmov pat clflush mmx fxsr sse
sse2 ss ht syscall lm constant_tsc up rep_good aperfmperf pni ssse3 cx16
hypervisor lahf_lm
bogomips        : 3200.07
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

$ df -h
Sist. Arq.            Size  Used Avail Use% Montado em
/dev/xvda2             48G   21G   25G  46% /
tmpfs                 2,0G     0  2,0G   0% /lib/init/rw
udev                  2,0G   32K  2,0G   1% /dev
tmpfs                 2,0G  4,0K  2,0G   1% /dev/shm


DocumentosSapl.fs
-----------------

Usamos o SAPL desde 2008. Nosso DocumentosSapl.fs está com 6,8GB. Fazemos
pack na base a cada sexta-feira, pelo cron.

Temos milhares de documentos no DocumentosSapl.fs:
   * sapl_documentos/norma_juridica/    ~7300
   * sapl_documentos/proposicao/        ~22000
   * sapl_documentos/materia/           ~20500


Medição da lentidão
-------------------

Acontece lentidão em vários pontos, mas nem sempre ela se repete nos mesmo
pontos. Às vezes, um ponto responde em 1 segundo, em outras vezes, o mesmo
ponto demora mais de 200 segundos. Cronometramos a lentidão, ela tem uma
duração quase uniforme de 210 segundos.

Um exemplo de lentidão acontece durante o recebimento de proposições. A
tabela abaixo mostra os tempos medidos.

 NP| BD| CM|  S|  C|  L|  E|  C|  S
176|  2|  1|  1|  1|  1|  1|  1|218
177|  1|  3|215|  1|213|  2|212|  4
178|  2|  1|  4|  2|212|  4|214|  4
179|  1|  2|116|  4|210|210|208|  2
180|  1|  1|  6|  6|199|  6|201|201

Legenda:
NP=Número da Proposição
BD=Buscar dados
CM=Criar Matéria
S =Salvar
C =Continuar
L =Livro (clicar no livro do texto integral)
E =Excluir

Cada coluna da tabela acima representa um passo no fluxo de trabalho do
recebimento de proposição que foi medido. Por exemplo: digita-se o
identificador da proposição constante no recibo, clica-se em buscar dados
(BD), depois em criar matéria (CM), e assim sucessivamente. Cada linha
representa o recebimento de uma proposição. Cada célula numérica, com
exceção do número da proposição (NP), representa o tempo medido em
segundos para a conclusão do passo.


O sistema durante a lentidão
----------------------------

Durante a lentidão, o servidor lê dados do HD a uma taxa de ~10MB/s, e não
escreve nada, conforme o "vmstat". O processo do zope consome 2.2GB de
RAM, conforme o "top", e o consumo de RAM pelo zope não muda.

$ vmstat 1

procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa
 0  0  14576  22356  24880 1612736    0    0     0     0   18   35  0  0
100  0
 0  0  14576  22356  24880 1612736    0    0     0     0   17   29  0  0
100  0
 0  0  14576  22356  24880 1612736    0    0     0     0   15   28  0  0
100  0
 0  0  14576  22356  24880 1612736    0    0     0     0   16   27  0  1
100  0
 0  0  14576  22356  24880 1612736    0    0     0     0   14   26  0  0
100  0
 0  0  14576  22356  24888 1612736    0    0     0    16   20   36  0  0
100  0
 0  0  14576  22356  24888 1612736    0    0     0     0   16   33  0  0
100  0
 0  0  14576  22356  24888 1612736    0    0     0     0   25   25  0  0
100  0
 1  1  14576  21736  24888 1613496    0    0   788     0   38   42  0  0
94  5
 0  1  14576  19256  24888 1616176    0    0 10856     0  400  321  1  0
10 90
 1  1  14576  20248  24888 1615120    0    0 10212     0  424  400  2  2
16 81
 0  1  14576  20248  24884 1615072    0    0 10660    16  421  338  1  2
10 88
 1  1  14576  18884  24884 1616568    0    0  9944     0  385  347  1  0
22 77
 0  1  14576  18140  24884 1617304    0    0 12036     0  438  337  1  0
15 84
 1  1  14576  18512  24884 1616888    0    0 10864     0  413  382  1  1
11 88
 0  1  14576  19504  24876 1616004    0    0 10360     0  410  312  1  1
11 87
 1  1  14576  19132  24864 1616396    0    0 11360     0  437  370  1  0 
9 90
 0  1  14576  19752  24860 1615720    0    0 10584    16  407  365  1  1 
4 95
 1  1  14576  19876  24860 1615600    0    0 11196     0  434  364  1  0
15 84
 0  1  14576  18512  24860 1617072    0    0 12664     0  449  322  1  0
15 84
 1  1  14576  19008  24860 1616432    0    0 10176     4  408  343  1  1
11 88

Testes
------

Testei a velocidade de leitura do HD com o programa "stress" e com o "cat"
e fica em torno de 50MB/s. Testei a alocação de memória por processo com o
"stress" e consegui 4GB por processo.


Hipóteses
---------

A quantidade de documentos no DocumentosSapl.fs está grande demais e causa
lentidão no Zope, porque o Zope, ao acessar alguma das pastas com milhares
de documentos, precisa fazer grandes leituras no disco quando os dados não
estão em cache. Talvez usar [1]BTreeFolder2 resolveria o problema?

[1]https://pypi.python.org/pypi/Products.BTreeFolder2


Socorro! :-)
------------

Como posso resolver o problema de lentidão relatado?

Muito obrigado.

-- 
Adriano Rafael Gomes
Analista de Suporte
Câmara Municipal de Novo Hamburgo




Mais detalhes sobre a lista de discussão GITEC