Otimizar o uso de ACbrAAC.SalvarArquivo/FlushtoDisk.

[EMBarbosa]

Olá pessoal,

Gostaria de saber se algum de vocês chegaram a analisar a necessidade do FlushtoDisk. O motivo é que reparamos que há uma queda considerável na performance ao implementar os requisitos do Arquivo Auxiliar Criptografado(AAC). Veja a imagem como exemplo:

Para 53 chamadas concluídas de TACBrECF.VendeItem temos um tempo gasto de 34,41 segundos. Sendo que desses, 10,35 foram gastos com a recuperação do GT e 14,14 foram gastos com a atualização do AAC. Essa perda para a recuperação do GT é realmente esperada e não acho que dê pra fazer nada sobre isso. Mas a com a atualização do AAC também é considerável. Então estamos tentando otimizar o tempo gasto com esse tipo de chamada.

Analisando a chamada ACBRAAC.AtualizaValorGT, percebemos que o maior tempo, 12,84 segundos, é gasto com o método FlushToDisk. Tudo bem que 12,84 segundos não é muita coisa para 53 chamadas (dá 0,242 aproximadamente por chamada). Mas continua sendo 37% do tempo gasto com a venda de itens. E daí a questão foi levantada. Evidentemente não esperamos zerar isso, mas talvez reduzir para uns 15%?

O que poderíamos fazer?

1. Nada e aceitar esse tempo até que as impressoras possam vender o item e retornar o valorGT só com uma chamada.

2. Eliminar a FlushToDisk sem fazer nada e ficar com a possibilidade de corromper o AAC... (não acho que seja recomendado)

3. Abrir o AAC de forma que não seja necessário o FlushToDisk. (http://stackoverflow.com/a/1636308)

Não tive tempo hábil ainda de testar algumas dessas sugestões, e acredito que vocês talvez possam ter tido outras ideias.

Gostaria de ouvir opiniões.

[Daniel Simoes]

Para usarmos a dica do site indicado seria necessário modificar o ACBrAAC para que ele mesmo mantenha o Handle do arquivo do AAC, hoje ele usa uma simples chamada a função: WriteToTXT da ACBrUtil...

Desabilitando a propriedade ACBrAAC.EfetuarFlush o desempenho aumenta muito ?

[EMBarbosa]

Se e simplesmente desabilitar a FlushtoDisk usando a propriedade mencionada, por exemplo, a velocidade aumenta em cerca de 37%. Ou seja, no exemplo dado, o tempo gasto para 53 itens cai de 34,41 segundos para apenas 21,57. Isso em apenas um cupom talvez pareça pouco. Mas imagine em vários cupons com um número de itens talvez muito maior. É um tempo bem considerável. É mais ou menos o tempo gasto para fazer uma chamada adicional ao ECF a cada item vendido.

Mas não sei se é recomendado fazer isso, pois não sei o motivo de terem incluído o FlushtoDisk.

Quanto a ter que manter o Handle: acredito que possa-se passar os mesmos parâmetros toda vez que abrir o arquivo evitando o cache do SO.

[Daniel Simoes]

O FlushToDisk serve apenas para manter o AAC seguro, gravado em disco e suportar quedas de energia ou deligamentos

A função WriteToTXT abre e fecha o arquivo, ela precisaria ser substituída por um método interno...

Seria bom termos um mini-projeto para testarmos o desempenho com o novo método, pode ser que a dica não de uma melhora tão significativa.

[EMBarbosa]

Ok. Posso tentar providenciar esse exemplo para testes. Acha que é necessário ficar abrindo e fechando o arquivo toda hora?

[Daniel Simoes]

Não é necessário...

Acho que um bom programa de testes seria gravar sempre um mesmo bloco no mesmo arquivo... Usando 2 opções...

- WriteToTXT seguido de FlushToDisk (como é feito hoje em dia)

- Abrindo o Arquivo com a opção citada e mantendo o Handle aberto

Acho que também é bom testar por quedas de energia, e verificar a robustez da 2 opção

[EMBarbosa]

Entendi. Não sei o quanto a remoção do FlushToDisk iria prejudicar no quesito robustez.

Mas com certeza, se abrir com os parâmetros mencionados, irá ser até mais confiável que usando o método atual.

Vou providenciar.

[EMBarbosa]

Estou trabalhando nesse tópico.

Montei com base no DEMO do ACBrECF (ECFTeste) um aplicativo para teste de velocidade. Testei até o momento apenas com base nas três opções possíveis no código até agora. A partir de hoje vou tentar fazer as modificações no ACBrAAC e verificar se o ganho de desempenho é considerável.

O arquivo anexo tem a diferença de velocidades para Venda de 53 itens "com o AAC fazendo o FlushtoDisk", "com o AAC sem fazer o FlushtoDisk" e Sem o AAC. O método usado para medir o tempo não é muito confiável, foi baseado apenas nas funções now e secondSpam. A medida que implementar o resto vou usar métodos mais confiáveis.

Em resumo, o resultado foi, usando o emulador da Bematech:

com AAC com Flush Diferença: 43,11 segundos

com AAC sem Flush Diferença: 36,86 segundos

sem AAC Diferença: 20,55 segundos

O ganho de performance ao desabilitar o FlushtoDisk aqui foi menor do que eu havia previsto nas medições diretas no meu PAF (apenas aproximadamente 15%). Pensando em longo prazo, mesmo que esses números se confirmem, acho que compensa verificar uma possível otimização. Mas vou verificar mais a fundo o assunto.

Fiquem à vontade para participar.

performance.txt

[EMBarbosa]

Daniel.

eu percebi algo aqui que me passou despercebido esse tempo todo. O AAC está fazendo Flush no Drive inteiro ao invés de apenas no arquivo AAC . Estou refazendo o código apenas alterando essa parte, para testar de quanto seria o ganho de desempenho, se há mesmo algum.

Por enquanto, parece que só essa correção já resolveria os problemas.

[EMBarbosa]

Quando chamamos a função Apenas para o arquivo, o retorno é praticamente instantâneo. Vou colocar abaixo a função, mas antes de alterar o componente, vou postar amanhã pela manhã resultados dos testes. Daí se todos tiverem de acordo posso fazer a alteração.

procedure EfetuaFlushArquivo(const nomearquivo: String);

  var

    hFile: THandle;

    bResult: boolean;

    lastErr: Cardinal;

    filenome: string;

  begin

    bResult := False;

    filenome := '\\.\' + nomearquivo; //Para usar a versão Wide da função CreateFile e aceitar o caminho completo do arquivo


    hFile := Windows.CreateFile( PWideChar(filenome),

                GENERIC_READ or GENERIC_WRITE,

                FILE_SHARE_READ or FILE_SHARE_WRITE, nil, OPEN_EXISTING,

                FILE_ATTRIBUTE_NORMAL  or FILE_FLAG_WRITE_THROUGH or FILE_FLAG_NO_BUFFERING, 0);


    bResult := FlushFileBuffers(hFile);



    CloseHandle(hFile);[/code]


Só chamando a atenção, que todos os componentes que no momento usam o ACBrUtil.FlushToDisk, na verdade estão fazendo o Flush do Drive inteiro e não do o arquivo passado por parâmetro.

[EMBarbosa]

Não vai dar para postar os testes todos hoje, então abaixo eu deixei um teste simples.

Ativar

#0#0#0#0#0#0#0

- + - + - + - + - + - + - + - + - + - + - + -

Com AAC 200 com Flush

Do Drive Todo

Cupons: 1 Itens: 53

Imprimindo 53 itens.

Iniciando Cupom: StopWatch

Diferença: 33504 milisegundos

---------------------------------

#0#0#0#0

- + - + - + - + - + - + - + - + - + - + - + -

Com AAC 200 com Flush

Apenas do Arquivo

Cupons: 1 Itens: 53

Imprimindo 53 itens.

Iniciando Cupom: StopWatch

Diferença: 24773 milisegundos

---------------------------------

#0#0#0#0

- + - + - + - + - + - + - + - + - + - + - + -

Também anexei o programa (em Delphi) que estou usando para fazer o teste dos tempos juntamente com o arquivo AAC alterado, com a opção para tanto o comportamento atual (efetuar flush do Drive) como para efetuar o flush apenas do arquivo. Assim todos podem testar nas suas próprias máquinas.

Poderão perceber que ele permite atualmente 2 métodos de medição e impressão dos itens e 1 sem nenhum método, para ser usado com um profiler externo.

TesteVelocidade.rar

[EMBarbosa]

Para corrigir a situação, eu sugiro criar uma função FlushFiletoDisk no ACBrUtil.pas e fazer o ACBrAAC chamar essa função ao invés da atual FlushtoDisk. Assim, se algum outro componente precisar do Flush no Drive pode continuar usando a atual chamada, mas o AAC não vai ter perda de performance por causa disso. Quase 9 (nove) segundos numa venda de apenas 53 itens ao meu ver, é um tempo considerável. E isso pode ser muito maior dependendo do número de arquivos abertos/alterados por outros programas mas que não tiveram seus buffers gravados no drive.

O que acham?

[Juliomar Marchetti]

Eu concordo..

acompanhei seu post desde o inicio

e efetuei testes do mesmo sentido e usei também seu exemplo

o ganho é significativo ainda mais em casos de vendas frenéticas como um supermercado

eu acho válida a alteração, não sei quanto ao Daniel, André, Régys, Isaque.... o que eles dizem

[EMBarbosa]

Esqueci de mencionar outra vantagem, é que o FlushtoDisk pode pedir privilégios administrativos, mas o FlushFiletoDisk não.

[Daniel Simoes]

A mudança é ótima... Elton, pode preparar um Patch ? Ou até mesmo subir direto para o SVN...

[EMBarbosa]

Vou fazer a modificação no SVN então.

[EMBarbosa]

Implementado na revisão 3597.

Eu compilei aqui no Delphi XE e Lazarus e passou. Mas seria bom se outros usuários pudessem testar também.

A função ACBrUtil.FlushtoDisk também é chamado pelo TACBrTEFDArquivo.GravarArquivo (definido em ACBrTEFDClass.pas).

Pelo que percebi do código, também não há necessidade ser usada FlsuhtoDisk, mas apenas o FlushFiletoDisk.

Se concordarem gostaria de modificar isso também.

[Juliomar Marchetti]

Elton se tiver ganho na velocidade acho valido

e também não dar problema com o que já tem..

[EMBarbosa]

O ganho de velocidade no ACBrTEFD existe. Mas como a chamada não é tão frenética, não é tão perceptível quanto no ACBrAAC.

Não daria problema com o que já existe.

Na verdade, o método usado quando compilado para LINUX faz o flush apenas do arquivo. O do Windows é que faz flush do Drive inteiro ocorrendo essa perda de performance.

A média de chamada para o FlushFileToDisk é por volta de 26,880 milissegundos (média máxima de 55,912 milissegundos) enquanto a do FlushtoDisk é de 183,050 milissegundos (média máxima de 240,762 milissegundos).

[EMBarbosa]

Só pra constar: A alteração no ACBrTEFD foi feita na revisão 3741 deixando assim o componente com um comportamento idêntico tanto no LINUX como no Windows e com um pequeno ganho de performance no Windows.

[Luiz Paulo]

Olá pessoal,

 

estou com um problema de lentidão ao atualizar o GT (ACbrAAC.SalvarArquivo). Isso acontece em apenas um PC (Windows 8) e não é sempre.

 

Situação

O operador abre o cupom, vende um item, as vezes mais, e o processo é realizado normalmente. 

De repente ao vender um item qualquer, sua impressão ocorre, mas o PC trava por alguns segundos (20,30 ou 40 segundos mais ou menos).

Descobri que o problema acontece ao atualizar o GT (pelos testes que fiz a demora deve estar ocorrendo ao executar o WriteToTXT), mas não é sempre, não segue um padrão específico.

Fiz testes até mesmo não usando o FlushFileToDisk e a lentidão continua.

 

Como é apenas em um PC, acredito que a lentidão deve estar relacionado com alguma coisa do PC, como o sistema operacional, antivírus ou algo assim. Mas não consegui achar uma solução ainda. 

 

O Log abaixo se refere a Atualização do GT, disparada algumas vezes a partir de um Loop, onde houve lentidão. (Esse foi apenas um teste de velocidade onde não ocorreu impressão de cupom) 

17/04 16:35:35:433 - AchaECF( BE091210100011210254 )
17/04 16:35:35:434 -   Ok
17/04 16:35:35:434 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:955.386,22 Para:0,00
17/04 16:35:35:434 - GravarArqRegistro
17/04 16:35:35:775 - AchaECF( BE091210100011210254 )
17/04 16:35:35:775 -   Ok
17/04 16:35:35:775 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:0,00 Para:955.386,22
17/04 16:35:35:775 - GravarArqRegistro
17/04 16:35:59:178 - AchaECF( BE091210100011210254 )
17/04 16:35:59:179 -   Ok
17/04 16:35:59:179 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:955.386,22 Para:0,00
17/04 16:35:59:179 - GravarArqRegistro
17/04 16:35:59:364 - AchaECF( BE091210100011210254 )
17/04 16:35:59:364 -   Ok
17/04 16:35:59:364 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:0,00 Para:955.386,22
17/04 16:35:59:364 - GravarArqRegistro
17/04 16:35:59:382 - AchaECF( BE091210100011210254 )
17/04 16:35:59:382 -   Ok
17/04 16:35:59:382 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:955.386,22 Para:0,00
17/04 16:35:59:382 - GravarArqRegistro
17/04 16:35:59:565 - AchaECF( BE091210100011210254 )
17/04 16:35:59:565 -   Ok
17/04 16:35:59:565 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:0,00 Para:955.386,22
17/04 16:35:59:565 - GravarArqRegistro
17/04 16:35:59:592 - AchaECF( BE091210100011210254 )
17/04 16:35:59:592 -   Ok
17/04 16:35:59:592 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:955.386,22 Para:0,00
17/04 16:35:59:592 - GravarArqRegistro
17/04 16:35:59:778 - AchaECF( BE091210100011210254 )
17/04 16:35:59:778 -   Ok
17/04 16:35:59:782 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:0,00 Para:955.386,22
17/04 16:35:59:782 - GravarArqRegistro
17/04 16:35:59:809 - AchaECF( BE091210100011210254 )
17/04 16:35:59:809 -   Ok
17/04 16:35:59:809 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:955.386,22 Para:0,00
17/04 16:35:59:809 - GravarArqRegistro
17/04 16:35:59:984 - AchaECF( BE091210100011210254 )
17/04 16:35:59:984 -   Ok
17/04 16:35:59:984 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:0,00 Para:955.386,22
17/04 16:35:59:984 - GravarArqRegistro
17/04 16:36:00:001 - AchaECF( BE091210100011210254 )
17/04 16:36:00:001 -   Ok
17/04 16:36:00:001 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:955.386,22 Para:0,00
17/04 16:36:00:001 - GravarArqRegistro
17/04 16:36:00:182 - AchaECF( BE091210100011210254 )
17/04 16:36:00:182 -   Ok
17/04 16:36:00:182 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:0,00 Para:955.386,22
17/04 16:36:00:183 - GravarArqRegistro
17/04 16:36:00:204 - AchaECF( BE091210100011210254 )
17/04 16:36:00:204 -   Ok
17/04 16:36:00:204 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:955.386,22 Para:0,00
17/04 16:36:00:204 - GravarArqRegistro
17/04 16:36:00:384 - AchaECF( BE091210100011210254 )
17/04 16:36:00:384 -   Ok
17/04 16:36:00:384 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:0,00 Para:955.386,22
17/04 16:36:00:384 - GravarArqRegistro
17/04 16:36:00:402 - AchaECF( BE091210100011210254 )
17/04 16:36:00:403 -   Ok
17/04 16:36:00:403 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:955.386,22 Para:0,00
17/04 16:36:00:403 - GravarArqRegistro
17/04 16:36:00:586 - AchaECF( BE091210100011210254 )
17/04 16:36:00:586 -   Ok
17/04 16:36:00:586 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:0,00 Para:955.386,22
17/04 16:36:00:586 - GravarArqRegistro
17/04 16:36:32:373 - AchaECF( BE091210100011210254 )
17/04 16:36:32:373 -   Ok
17/04 16:36:32:373 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:955.386,22 Para:0,00
17/04 16:36:32:373 - GravarArqRegistro
17/04 16:36:32:562 - AchaECF( BE091210100011210254 )
17/04 16:36:32:563 -   Ok
17/04 16:36:32:563 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:0,00 Para:955.386,22
17/04 16:36:32:563 - GravarArqRegistro
17/04 16:36:32:635 - AchaECF( BE091210100011210254 )
17/04 16:36:32:635 -   Ok
17/04 16:36:32:635 - AtualizarGTECF - NumSerie: BE091210100011210254 - De:955.386,22 Para:0,00
17/04 16:36:32:635 - GravarArqRegistro

 

Destaque para as linhas abaixo onde a lentidão ocorreu:

(...)
17/04 16:35:35:775 - GravarArqRegistro
17/04 16:35:59:178 - AchaECF( BE091210100011210254 )
(...)
17/04 16:36:00:586 - GravarArqRegistro
17/04 16:36:32:373 - AchaECF( BE091210100011210254 )
(...)

Alguém, já passou por uma situação assim ou tem uma sugestão do que posso fazer?

 

 

 

 

Editado 17 Abril, 2015 por Luiz Paulo

[EMBarbosa]

Olá Luiz,

 

  Como você mesmo descobriu, o problema não é na parte do FlushFileToDisk. Poderia ser se você não tivesse atualizado seu código e estivesse sendo usado o Flush do Drive inteiro.

  O que poderia ser então? Lógico que sem ver a máquina é difícil de dizer, mas eu começaria a olhar por coisas benignas (Antivírus, Firewall, AntiMalware, aplicativos de proteção bancária, aplicativos de aceleração que varrem os arquivos mais utilizados) e vírus e Malwares...

 

  Falando sobre antivírus, eu me lembro de ter tido um problema parecido em um cliente. O detalhe era que mesmo desabilitando o Antivírus, ele ainda continuava varrendo os arquivos. Não bastava marcar o Antivírus para ficar inativo por um tempo. Nós tivemos que colocar o executável, o banco de dados, os arquivos temporários do TEF e o arquivo AAC na lista de arquivos confiáveis dele.

  Finalmente, resolvemos trocar de antivírus e resolveu... Só que já não me lembro qual foi o antivírus...

[Luiz Paulo]

Elton,

 

Obrigado pelo retorno,

agora pouco estava verificando isso em meu cliente e a lentidão sumiu. 

Infelizmente, como alterei tantas coisas como essas que você mencionou, não sei o que exatamente eu fiz para resolver o problema. 

 

Se tiver uma nova posição sobre o assunto eu informo no tópico.