Categorias
Uncategorized

Impacto de Two Phase Commit (2PC / XA) na disponibilidade / performance

Two Phase Commit é utilizado para garantir a consistência entre dois recursos (por exemplo: banco de dados e servidor de filas) para que os recursos participem de um contexto transacional de forma atômica, isto é, ou ambos sejam executados ou ambos façam o rollback (na falha de algum dos recursos).

O problema com esse tipo de protocolo é que ele causa um problema de escalabilidade no sistema já que o protocolo trabalha de forma blocante. Um outro problema comum que vemos é que ele segura os recursos compartilhados (por exemplo conexões com banco de dados) até o término da transação. No caso de uma lentidão num servidor de filas JMS, o que pode ocorrer com a aplicação é a falta de conexão com o banco de dados já que a mesma só é liberada após o término da transação.

Vamos simular esse problemas com o código disponibilizado em https://github.com/fabionb/artigo_2pc

A aplicação está configurada com 10 conexões no pool (padrão do Hikari) e 5 segundos de espera para obter a conexão do pool, após esse tempo a aplicação irá receber um erro caso não consiga obter a conexão, além disso está configurada para permitir até 30 conexões com um servidor JMS.

A aplicação possui um endpoint que insere um registro no banco e publica uma mensagem JMS com o id do registro inserido. Sem o Two Phase Commit ela foi implementada da seguinte forma:

BEGIN -- Início da transação
  Select da sequence
  Insert do registro no banco
COMMIT -- Término da transação
Publicação da mensagem JMS com o id do registro

Já com Two Phase Commit ela foi implementada da seguinte forma:

BEGIN -- Início da transação
  Select da sequence
  Insert do registro no banco
  Publicação da mensagem JMS com o id do registro
COMMIT -- Término da transação

Esse endpoint está disponível em http://localhost:8081/produce

Vamos agora tentar realizar um simples teste de carga. Vamos simular a concorrência de 30 usuários realizando 300 requests nessa url:

ab -c 30 -n 3000 http://localhost:8081/produce
This is ApacheBench, Version 2.3 <$Revision: 1903618 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient)
Completed 300 requests
Completed 600 requests
Completed 900 requests
Completed 1200 requests
Completed 1500 requests
Completed 1800 requests
Completed 2100 requests
Completed 2400 requests
Completed 2700 requests
Completed 3000 requests
Finished 3000 requests


Server Software:        
Server Hostname:        localhost
Server Port:            8081

Document Path:          /produce
Document Length:        8 bytes

Concurrency Level:      30
Time taken for tests:   3.032 seconds
Complete requests:      3000
Failed requests:        0
Total transferred:      339000 bytes
HTML transferred:       24000 bytes
Requests per second:    989.31 [#/sec] (mean)
Time per request:       30.324 [ms] (mean)
Time per request:       1.011 [ms] (mean, across all concurrent requests)
Transfer rate:          109.17 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    1   1.4      0      18
Processing:     5   29  19.3     21     143
Waiting:        5   28  19.3     21     143
Total:          6   30  19.3     22     145

Percentage of the requests served within a certain time (ms)
  50%     22
  66%     27
  75%     34
  80%     41
  90%     63
  95%     71
  98%     82
  99%     93
 100%    145 (longest request)

Como podemos ver, não tivemos erros e a o tempo médio por request foi 22 ms, percentil 90 em 63 ms e o maior tempo de resposta foi de 145 ms.

Agora vamos simular uma lentidão na fila JMS. Para isso basta executar o comando:

docker update --cpus 0.05 activemq-artemis

E o teste de carga:

ab -c 30 -n 3000 http://localhost:8081/produce
This is ApacheBench, Version 2.3 <$Revision: 1903618 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient)
Completed 300 requests
Completed 600 requests
Completed 900 requests
Completed 1200 requests
Completed 1500 requests
Completed 1800 requests
Completed 2100 requests
Completed 2400 requests
Completed 2700 requests
Completed 3000 requests
Finished 3000 requests


Server Software:        
Server Hostname:        localhost
Server Port:            8081

Document Path:          /produce
Document Length:        8 bytes

Concurrency Level:      30
Time taken for tests:   93.214 seconds
Complete requests:      3000
Failed requests:        0
Total transferred:      339000 bytes
HTML transferred:       24000 bytes
Requests per second:    32.18 [#/sec] (mean)
Time per request:       932.136 [ms] (mean)
Time per request:       31.071 [ms] (mean, across all concurrent requests)
Transfer rate:          3.55 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   1.1      0      24
Processing:    99  891 762.1    701    9392
Waiting:       98  891 762.2    700    9392
Total:         99  892 762.3    701    9395

Percentage of the requests served within a certain time (ms)
  50%    701
  66%    901
  75%   1100
  80%   1202
  90%   1506
  95%   1805
  98%   2400
  99%   4403
 100%   6204 (longest request)

Com esse teste, não tivemos erro mas o tempo médio por request foi 701 ms, percentil 90 em 1506 ms e o maior tempo de resposta foi de 6204 ms.

Vamos agora utilizar o Two Phase Commit com o Narayana Transaction Manager. Ele está configurado com os mesmos valores de pool sem 2PC.

Realizando o mesmo teste de carga:

ab -c 30 -n 3000 http://localhost:8081/produce
This is ApacheBench, Version 2.3 <$Revision: 1903618 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient)
Completed 300 requests
Completed 600 requests
Completed 900 requests
Completed 1200 requests
Completed 1500 requests
Completed 1800 requests
Completed 2100 requests
Completed 2400 requests
Completed 2700 requests
Completed 3000 requests
Finished 3000 requests


Server Software:        
Server Hostname:        localhost
Server Port:            8081

Document Path:          /produce
Document Length:        8 bytes

Concurrency Level:      30
Time taken for tests:   6.272 seconds
Complete requests:      3000
Failed requests:        0
Total transferred:      339000 bytes
HTML transferred:       24000 bytes
Requests per second:    478.32 [#/sec] (mean)
Time per request:       62.720 [ms] (mean)
Time per request:       2.091 [ms] (mean, across all concurrent requests)
Transfer rate:          52.78 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.2      0       5
Processing:     9   62  30.2     55     280
Waiting:        9   62  30.2     55     280
Total:          9   62  30.3     55     281

Percentage of the requests served within a certain time (ms)
  50%     55
  66%     61
  75%     66
  80%     74
  90%     96
  95%    110
  98%    145
  99%    188
 100%    281 (longest request)

Como podemos ver, não tivemos erros e a o tempo médio por request foi 55 ms, percentil 90 em 96 ms e o maior tempo de resposta foi de 281 ms. Comparando com o resultado sem 2PC, o tempo de resposta deu uma leve piorada.

Vamos agora simular a lentição na fila JMS com o mesmo comando utilizado acima:

ab -c 30 -n 3000 http://localhost:8081/produce
This is ApacheBench, Version 2.3 <$Revision: 1903618 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient)
Completed 300 requests
Completed 600 requests
Completed 900 requests
Completed 1200 requests
Completed 1500 requests
Completed 1800 requests
Completed 2100 requests
Completed 2400 requests
Completed 2700 requests
Completed 3000 requests
Finished 3000 requests


Server Software:        
Server Hostname:        localhost
Server Port:            8081

Document Path:          /produce
Document Length:        8 bytes

Concurrency Level:      30
Time taken for tests:   164.494 seconds
Complete requests:      3000
Failed requests:        23
   (Connect: 0, Receive: 0, Length: 23, Exceptions: 0)
Non-2xx responses:      23
Total transferred:      341300 bytes
HTML transferred:       26300 bytes
Requests per second:    18.24 [#/sec] (mean)
Time per request:       1644.937 [ms] (mean)
Time per request:       54.831 [ms] (mean, across all concurrent requests)
Transfer rate:          2.03 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.3      0       5
Processing:    97 1634 1101.8   1204    7900
Waiting:       95 1634 1101.8   1204    7900
Total:         98 1635 1101.9   1204    7900

Percentage of the requests served within a certain time (ms)
  50%   1204
  66%   1504
  75%   1903
  80%   2197
  90%   3301
  95%   4100
  98%   5003
  99%   5291
 100%   7900 (longest request)

Como podemos ver, tivemos 23 erros e a o tempo médio por request foi 1204 ms, percentil 90 em 3301 ms e o maior tempo de resposta foi de 7900 ms.

A causa dos erros foi a falta de conexão no pool com o banco de dados:

java.util.NoSuchElementException: Timeout waiting for idle object, borrowMaxWaitDuration=PT5S
        at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:312) ~[commons-pool2-2.11.1.jar:2.11.1]
        at org.apache.commons.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:223) ~[commons-pool2-2.11.1.jar:2.11.1]
        at org.apache.commons.dbcp2.managed.ManagedConnection.updateTransactionStatus(ManagedConnection.java:302) ~[commons-dbcp2-2.9.0.jar:2.9.0]
        at org.apache.commons.dbcp2.managed.ManagedConnection.<init>(ManagedConnection.java:89) ~[commons-dbcp2-2.9.0.jar:2.9.0]
        at org.apache.commons.dbcp2.managed.ManagedDataSource.getConnection(ManagedDataSource.java:64) ~[commons-dbcp2-2.9.0.jar:2.9.0]
        at org.apache.commons.dbcp2.BasicDataSource.getConnection(BasicDataSource.java:731) ~[commons-dbcp2-2.9.0.jar:2.9.0]
        at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:38) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:108) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:138) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:50) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$1.doPrepare(StatementPreparerImpl.java:90) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:176) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareStatement(StatementPreparerImpl.java:75) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.id.enhanced.SequenceStructure$1.getNextValue(SequenceStructure.java:105) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.id.enhanced.NoopOptimizer.generate(NoopOptimizer.java:40) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.id.enhanced.SequenceStyleGenerator.generate(SequenceStyleGenerator.java:534) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.event.internal.AbstractSaveEventListener.saveWithGeneratedId(AbstractSaveEventListener.java:114) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.event.internal.DefaultPersistEventListener.entityIsTransient(DefaultPersistEventListener.java:185) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.event.internal.DefaultPersistEventListener.onPersist(DefaultPersistEventListener.java:128) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.event.internal.DefaultPersistEventListener.onPersist(DefaultPersistEventListener.java:55) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:107) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.internal.SessionImpl.firePersist(SessionImpl.java:756) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at org.hibernate.internal.SessionImpl.persist(SessionImpl.java:742) ~[hibernate-core-5.6.14.Final.jar:5.6.14.Final]
        at jdk.internal.reflect.GeneratedMethodAccessor50.invoke(Unknown Source) ~[na:na]
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
        at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
        at org.springframework.orm.jpa.ExtendedEntityManagerCreator$ExtendedEntityManagerInvocationHandler.invoke(ExtendedEntityManagerCreator.java:362) ~[spring-orm-5.3.25.jar:5.3.25]
        at jdk.proxy2/jdk.proxy2.$Proxy99.persist(Unknown Source) ~[na:na]
        at jdk.internal.reflect.GeneratedMethodAccessor50.invoke(Unknown Source) ~[na:na]
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
        at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
        at org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:311) ~[spring-orm-5.3.25.jar:5.3.25]
        at jdk.proxy2/jdk.proxy2.$Proxy99.persist(Unknown Source) ~[na:na]
        at br.com.fnbrandao.artigo_2pc.twophasecommit.ProducerService2PC.createAndPersistEntity(ProducerService2PC.java:32) ~[main/:na]
        at br.com.fnbrandao.artigo_2pc.twophasecommit.ProducerService2PC.produce(ProducerService2PC.java:25) ~[main/:na]

Durante o teste, se abrirmos o jconsole e verificarmos o pool do banco de dados, vemos as seguintes informações:

Conclusões

O uso de 2PC causa um problema de escalabilidade e performance na aplicação já que o mesmo mantém recursos compartilhados “presos” até o término da transação e, caso algum desses recursos externos fique lento, poderá faltar algum desses recursos compartilhados para atender os requests pela aplicação.

Não mostramos no artigo mas basta rodar o exemplo e veremos que até o consumo total das mensagens dos testes demora mais com o Two Phase Commit habilitado.

Uma maneira de contornar esse problema é não utilizar o 2PC e delimitar corretamente os contextos transacionais de cada um desses recursos. O problema com essa abordagem é que ela faz com que parte das coisas possam não acontecer. Nesse exemplo, o insert no banco poderia ser commitado mas a mensagem na fila JMS poderia não acontecer. Isso pode ser resolvido de várias maneiras e o intuito desse artigo não é discutir essas abordagens, mas há referências muito boas em:

https://microservices.io/patterns/data/saga.html

https://microservices.io/patterns/data/event-sourcing.html

https://microservices.io/patterns/data/transactional-outbox.html

https://microservices.io/patterns/data/transaction-log-tailing.html

https://microservices.io/patterns/data/polling-publisher.html

Deixe um comentário

O seu endereço de e-mail não será publicado. Campos obrigatórios são marcados com *

Esse site utiliza o Akismet para reduzir spam. Aprenda como seus dados de comentários são processados.

css.php