search

apache / shardingsphere

Distributed SQL transaction & query engine for data sharding, scaling, encryption, and more - on any database.
Apache License 2.0
19.84k stars 6.72k forks source link

ss-jdbc executes sql, and the transaction type is local. Each time a sql is executed, the xa transaction operation is performed. #19149

Closed peilinqian closed 1 year ago

peilinqian commented 2 years ago

Bug Report

For English only, other languages will not accept.

Before report a bug, make sure you have:

Please pay attention on issues you submitted, because we maybe need more details. If no response anymore and we cannot reproduce it on current information, we will close it.

Please answer these questions before submitting your issue. Thanks!

Which version of ShardingSphere did you use?

we find java version: java8, full_version=1.8.0_282 ShardingSphere-5.1.3-SNAPSHOT Commit ID: 7c67365b394d2e3ac562329b550c135c31ea764d Commit Message: Avoid overhead of invoking method in Optional.orElse (#18921) Branch: 7c67365b394d2e3ac562329b550c135c31ea764d Build time: 2022-07-08T19:24:17+0800

Which project did you use? ShardingSphere-JDBC or ShardingSphere-Proxy?

ShardingSphere-JDBC

Expected behavior

ss-jdbc executes sql, the transaction type is local, each time a sql is executed, the xa transaction operation is not performed.

Actual behavior

ss-jdbc executes sql, and the transaction type is local. Each time a sql is executed, the xa transaction operation is performed.

Reason analyze (If you can)

Steps to reproduce the behavior, such as: SQL to execute, sharding rule configuration, when exception occur etc.

[INFO ] 2022-07-14 16:49:58,816 --main-- [org.apache.zookeeper.ZooKeeper] Client environment:java.io.tmpdir=C:\Users\Admin532~1\AppData\Local\Temp\ 
[INFO ] 2022-07-14 16:49:58,816 --main-- [org.apache.zookeeper.ZooKeeper] Client environment:java.compiler=<NA> 
[INFO ] 2022-07-14 16:49:58,816 --main-- [org.apache.zookeeper.ZooKeeper] Client environment:os.name=Windows 10 
[INFO ] 2022-07-14 16:49:58,816 --main-- [org.apache.zookeeper.ZooKeeper] Client environment:os.arch=amd64 
[INFO ] 2022-07-14 16:49:58,816 --main-- [org.apache.zookeeper.ZooKeeper] Client environment:os.version=10.0 
[INFO ] 2022-07-14 16:49:58,816 --main-- [org.apache.zookeeper.ZooKeeper] Client environment:user.name=Admin 
[INFO ] 2022-07-14 16:49:58,816 --main-- [org.apache.zookeeper.ZooKeeper] Client environment:user.home=C:\Users\Admin 
[INFO ] 2022-07-14 16:49:58,816 --main-- [org.apache.zookeeper.ZooKeeper] Client environment:user.dir=D:\shardingsphere-test-master1\shardingsphere-test-master\shardingsphere-test-master\shardingsphere-feature-test\shardingsphere-jdbc-feature-test 
[INFO ] 2022-07-14 16:49:58,816 --main-- [org.apache.zookeeper.ZooKeeper] Client environment:os.memory.free=199MB 
[INFO ] 2022-07-14 16:49:58,816 --main-- [org.apache.zookeeper.ZooKeeper] Client environment:os.memory.max=3639MB 
[INFO ] 2022-07-14 16:49:58,816 --main-- [org.apache.zookeeper.ZooKeeper] Client environment:os.memory.total=245MB 
[INFO ] 2022-07-14 16:49:58,821 --main-- [org.apache.zookeeper.ZooKeeper] Initiating client connection, connectString=7.212.123.28:2181 sessionTimeout=60000000 watcher=org.apache.curator.ConnectionState@6c1a5b54 
[INFO ] 2022-07-14 16:49:58,832 --main-- [org.apache.zookeeper.common.X509Util] Setting -D jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated TLS renegotiation 
[INFO ] 2022-07-14 16:49:58,863 --main-- [org.apache.zookeeper.ClientCnxnSocket] jute.maxbuffer value is 1048575 Bytes 
[INFO ] 2022-07-14 16:49:58,920 --main-- [org.apache.zookeeper.ClientCnxn] zookeeper.request.timeout value is 0. feature enabled=false 
[INFO ] 2022-07-14 16:49:58,949 --main-SendThread(7.212.123.28:2181)-- [org.apache.zookeeper.ClientCnxn] Opening socket connection to server kwemhisprc10431/7.212.123.28:2181. 
[INFO ] 2022-07-14 16:49:58,949 --main-- [org.apache.curator.framework.imps.CuratorFrameworkImpl] Default schema 
[INFO ] 2022-07-14 16:49:58,949 --main-SendThread(7.212.123.28:2181)-- [org.apache.zookeeper.ClientCnxn] SASL config status: Will not attempt to authenticate using SASL (unknown error) 
[INFO ] 2022-07-14 16:49:58,975 --main-SendThread(7.212.123.28:2181)-- [org.apache.zookeeper.ClientCnxn] Socket connection established, initiating session, client: /CS_IP:51501, server: kwemhisprc10431/7.212.123.28:2181 
[INFO ] 2022-07-14 16:49:59,009 --main-SendThread(7.212.123.28:2181)-- [org.apache.zookeeper.ClientCnxn] Session establishment complete on server kwemhisprc10431/7.212.123.28:2181, session id = 0x1001acd34aa011f, negotiated timeout = 40000 
[INFO ] 2022-07-14 16:49:59,026 --main-EventThread-- [org.apache.curator.framework.state.ConnectionStateManager] State change: CONNECTED 
[INFO ] 2022-07-14 16:49:59,082 --main-EventThread-- [org.apache.curator.framework.imps.EnsembleTracker] New config event received: {} 
[INFO ] 2022-07-14 16:49:59,082 --main-EventThread-- [org.apache.curator.framework.imps.EnsembleTracker] New config event received: {} 
[INFO ] 2022-07-14 16:50:00,429 --main-- [com.zaxxer.hikari.HikariDataSource] HikariPool-1 - Starting... 
[INFO ] 2022-07-14 16:50:00,619 --main-- [org.opengauss.core.v3.ConnectionFactoryImpl] [4af6b17c-264e-4ec8-8f9f-c143a6491129] Try to connect. IP: Og_IP1:14000 
[INFO ] 2022-07-14 16:50:00,910 --main-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51502/Og_IP1:14000] Connection is established. ID: 4af6b17c-264e-4ec8-8f9f-c143a6491129 
[INFO ] 2022-07-14 16:50:01,169 --main-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 4af6b17c-264e-4ec8-8f9f-c143a6491129 
[INFO ] 2022-07-14 16:50:01,375 --main-- [com.zaxxer.hikari.HikariDataSource] HikariPool-1 - Start completed. 
[INFO ] 2022-07-14 16:50:01,396 --main-- [com.zaxxer.hikari.HikariDataSource] HikariPool-2 - Starting... 
[INFO ] 2022-07-14 16:50:01,398 --main-- [org.opengauss.core.v3.ConnectionFactoryImpl] [a97dbf47-66c5-4389-b045-9eb191625d7e] Try to connect. IP: Og_IP2:14000 
[INFO ] 2022-07-14 16:50:01,497 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [bf0f28b5-00a0-4491-b672-fd233ddf803d] Try to connect. IP: Og_IP1:14000 
[INFO ] 2022-07-14 16:50:01,558 --main-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51503/Og_IP2:14000] Connection is established. ID: a97dbf47-66c5-4389-b045-9eb191625d7e 
[INFO ] 2022-07-14 16:50:01,695 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51505/Og_IP1:14000] Connection is established. ID: bf0f28b5-00a0-4491-b672-fd233ddf803d 
[INFO ] 2022-07-14 16:50:01,707 --main-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: a97dbf47-66c5-4389-b045-9eb191625d7e 
[INFO ] 2022-07-14 16:50:01,822 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: bf0f28b5-00a0-4491-b672-fd233ddf803d 
[INFO ] 2022-07-14 16:50:01,858 --main-- [com.zaxxer.hikari.HikariDataSource] HikariPool-2 - Start completed. 
[INFO ] 2022-07-14 16:50:01,893 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [3a6773f3-2066-4067-8d8a-612ff067efb4] Try to connect. IP: Og_IP1:14000 
[INFO ] 2022-07-14 16:50:02,024 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [b1beb284-8db3-4935-bb10-59c9dd754133] Try to connect. IP: Og_IP2:14000 
[INFO ] 2022-07-14 16:50:02,051 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51506/Og_IP1:14000] Connection is established. ID: 3a6773f3-2066-4067-8d8a-612ff067efb4 
[INFO ] 2022-07-14 16:50:02,163 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51507/Og_IP2:14000] Connection is established. ID: b1beb284-8db3-4935-bb10-59c9dd754133 
[INFO ] 2022-07-14 16:50:02,176 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 3a6773f3-2066-4067-8d8a-612ff067efb4 
[INFO ] 2022-07-14 16:50:02,292 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [c3fca1ce-fadf-4096-a3fd-466ee0aaea08] Try to connect. IP: Og_IP1:14000 
[INFO ] 2022-07-14 16:50:02,350 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: b1beb284-8db3-4935-bb10-59c9dd754133 
[INFO ] 2022-07-14 16:50:02,416 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [1345f8e8-55ba-44d3-bb4a-6724936f7427] Try to connect. IP: Og_IP2:14000 
[INFO ] 2022-07-14 16:50:02,442 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51508/Og_IP1:14000] Connection is established. ID: c3fca1ce-fadf-4096-a3fd-466ee0aaea08 
[INFO ] 2022-07-14 16:50:02,560 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51509/Og_IP2:14000] Connection is established. ID: 1345f8e8-55ba-44d3-bb4a-6724936f7427 
[INFO ] 2022-07-14 16:50:02,573 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: c3fca1ce-fadf-4096-a3fd-466ee0aaea08 
[INFO ] 2022-07-14 16:50:02,639 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [f3aebd64-4ecb-4e44-9018-8b35d027ad3f] Try to connect. IP: Og_IP1:14000 
[INFO ] 2022-07-14 16:50:02,685 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 1345f8e8-55ba-44d3-bb4a-6724936f7427 
[INFO ] 2022-07-14 16:50:02,753 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [298ce212-c4ba-4cfd-b93c-3b00735ca982] Try to connect. IP: Og_IP2:14000 
[INFO ] 2022-07-14 16:50:02,795 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51510/Og_IP1:14000] Connection is established. ID: f3aebd64-4ecb-4e44-9018-8b35d027ad3f 
[INFO ] 2022-07-14 16:50:02,900 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51511/Og_IP2:14000] Connection is established. ID: 298ce212-c4ba-4cfd-b93c-3b00735ca982 
[INFO ] 2022-07-14 16:50:02,921 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: f3aebd64-4ecb-4e44-9018-8b35d027ad3f 
[INFO ] 2022-07-14 16:50:02,988 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [d493cd9a-8213-44b3-a913-adcd9235079f] Try to connect. IP: Og_IP1:14000 
[INFO ] 2022-07-14 16:50:03,024 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 298ce212-c4ba-4cfd-b93c-3b00735ca982 
[INFO ] 2022-07-14 16:50:03,091 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [2598366c-9d06-4c37-97ef-ebfe16158561] Try to connect. IP: Og_IP2:14000 
[INFO ] 2022-07-14 16:50:03,132 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51512/Og_IP1:14000] Connection is established. ID: d493cd9a-8213-44b3-a913-adcd9235079f 
[INFO ] 2022-07-14 16:50:03,213 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51513/Og_IP2:14000] Connection is established. ID: 2598366c-9d06-4c37-97ef-ebfe16158561 
[INFO ] 2022-07-14 16:50:03,236 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: d493cd9a-8213-44b3-a913-adcd9235079f 
[INFO ] 2022-07-14 16:50:03,298 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [36b2333d-027a-44c6-8a13-ad7c28ffacae] Try to connect. IP: Og_IP1:14000 
[INFO ] 2022-07-14 16:50:03,318 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 2598366c-9d06-4c37-97ef-ebfe16158561 
[INFO ] 2022-07-14 16:50:03,385 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [abf4dea8-1aa2-41e7-ad3a-82362cb78e77] Try to connect. IP: Og_IP2:14000 
[INFO ] 2022-07-14 16:50:03,447 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51514/Og_IP1:14000] Connection is established. ID: 36b2333d-027a-44c6-8a13-ad7c28ffacae 
[INFO ] 2022-07-14 16:50:03,523 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51515/Og_IP2:14000] Connection is established. ID: abf4dea8-1aa2-41e7-ad3a-82362cb78e77 
[INFO ] 2022-07-14 16:50:03,587 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 36b2333d-027a-44c6-8a13-ad7c28ffacae 
[INFO ] 2022-07-14 16:50:03,650 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [50cd3aa6-5c0f-4cfc-8f8d-60d86c997085] Try to connect. IP: Og_IP1:14000 
[INFO ] 2022-07-14 16:50:03,686 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: abf4dea8-1aa2-41e7-ad3a-82362cb78e77 
[INFO ] 2022-07-14 16:50:03,753 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [b0d26b48-73a5-47d1-b656-4972b22d1607] Try to connect. IP: Og_IP2:14000 
[INFO ] 2022-07-14 16:50:03,811 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51516/Og_IP1:14000] Connection is established. ID: 50cd3aa6-5c0f-4cfc-8f8d-60d86c997085 
[INFO ] 2022-07-14 16:50:03,896 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51517/Og_IP2:14000] Connection is established. ID: b0d26b48-73a5-47d1-b656-4972b22d1607 
[INFO ] 2022-07-14 16:50:03,959 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 50cd3aa6-5c0f-4cfc-8f8d-60d86c997085 
[INFO ] 2022-07-14 16:50:04,021 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: b0d26b48-73a5-47d1-b656-4972b22d1607 
[INFO ] 2022-07-14 16:50:04,040 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [4ee03a0f-c94f-43a6-befe-5b37d0181ddb] Try to connect. IP: Og_IP1:14000 
[INFO ] 2022-07-14 16:50:04,089 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [32219db4-ec18-4f46-886c-1bcfb466fb5f] Try to connect. IP: Og_IP2:14000 
[INFO ] 2022-07-14 16:50:04,188 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51518/Og_IP1:14000] Connection is established. ID: 4ee03a0f-c94f-43a6-befe-5b37d0181ddb 
[INFO ] 2022-07-14 16:50:04,229 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51519/Og_IP2:14000] Connection is established. ID: 32219db4-ec18-4f46-886c-1bcfb466fb5f 
[INFO ] 2022-07-14 16:50:04,313 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 4ee03a0f-c94f-43a6-befe-5b37d0181ddb 
[INFO ] 2022-07-14 16:50:04,354 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 32219db4-ec18-4f46-886c-1bcfb466fb5f 
[INFO ] 2022-07-14 16:50:04,380 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [53104142-3ea5-487b-bd46-aa16bbcae22c] Try to connect. IP: Og_IP1:14000 
[INFO ] 2022-07-14 16:50:04,420 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [02c0a110-326a-4121-8292-2f3994cd7f50] Try to connect. IP: Og_IP2:14000 
[INFO ] 2022-07-14 16:50:04,524 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51520/Og_IP1:14000] Connection is established. ID: 53104142-3ea5-487b-bd46-aa16bbcae22c 
[INFO ] 2022-07-14 16:50:04,557 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51521/Og_IP2:14000] Connection is established. ID: 02c0a110-326a-4121-8292-2f3994cd7f50 
[INFO ] 2022-07-14 16:50:04,652 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 53104142-3ea5-487b-bd46-aa16bbcae22c 
[INFO ] 2022-07-14 16:50:04,681 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 02c0a110-326a-4121-8292-2f3994cd7f50 
[INFO ] 2022-07-14 16:50:04,747 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [8a46bb55-e579-4fc1-8762-eb519a63f84e] Try to connect. IP: Og_IP2:14000 
[INFO ] 2022-07-14 16:50:04,886 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51522/Og_IP2:14000] Connection is established. ID: 8a46bb55-e579-4fc1-8762-eb519a63f84e 
[INFO ] 2022-07-14 16:50:05,011 --HikariPool-2 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 8a46bb55-e579-4fc1-8762-eb519a63f84e 

[INFO ] 2022-07-14 16:50:28,001 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] Loaded jar:file:/D:/shardingsphere-test-master/ss-jdbcTest/lib/transactions-5.0.8.jar!/transactions-defaults.properties 
[INFO ] 2022-07-14 16:50:28,003 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] Loaded jar:file:/D:/shardingsphere-test-master/ss-jdbcTest/lib/shardingsphere-transaction-xa-atomikos-5.1.3-SNAPSHOT.jar!/transactions.properties 
[WARN ] 2022-07-14 16:50:28,024 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] Thanks for using Atomikos! This installation is not registered yet. 
REGISTER FOR FREE at http://www.atomikos.com/Main/RegisterYourDownload and receive:
- tips & advice 
- working demos 
- access to the full documentation 
- special exclusive bonus offers not available to others 
- everything you need to get the most out of using Atomikos! 
Thanks for using Atomikos! This installation is not registered yet. 
REGISTER FOR FREE at http://www.atomikos.com/Main/RegisterYourDownload and receive:
- tips & advice 
- working demos 
- access to the full documentation 
- special exclusive bonus offers not available to others 
- everything you need to get the most out of using Atomikos!
[INFO ] 2022-07-14 16:50:28,043 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING core version: 5.0.8 
[INFO ] 2022-07-14 16:50:28,043 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.default_max_wait_time_on_shutdown = 9223372036854775807 
[INFO ] 2022-07-14 16:50:28,043 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.allow_subtransactions = true 
[INFO ] 2022-07-14 16:50:28,043 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.recovery_delay = 300000 
[INFO ] 2022-07-14 16:50:28,043 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.automatic_resource_registration = false 
[INFO ] 2022-07-14 16:50:28,043 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.oltp_max_retries = 5 
[INFO ] 2022-07-14 16:50:28,043 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.throw_on_heuristic = false 
[INFO ] 2022-07-14 16:50:28,043 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.logcloud_datasource_name = logCloudDS 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.serial_jta_transactions = false 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.jvm_id = 21184@SIAY9Admin5328111 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.log_base_dir = ./logs 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.max_actives = 10000 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.checkpoint_interval = 50000 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.enable_logging = true 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.log_base_name = xa_tx 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.max_timeout = 300000 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.tm_unique_name = CS_IP.tm 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.forget_orphaned_log_entries_delay = 86400000 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.oltp_retry_interval = 10000 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.force_shutdown_on_vm_exit = false 
[INFO ] 2022-07-14 16:50:28,044 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] USING: com.atomikos.icatch.default_jta_timeout = 300000 
[INFO ] 2022-07-14 16:50:28,046 --main-- [com.atomikos.icatch.provider.imp.AssemblerImp] Using default (local) logging and recovery... 

[INFO ] 2022-07-14 16:50:33,550 --main-- [org.apache.curator.utils.Compatibility] Using org.apache.zookeeper.server.quorum.MultipleAddresses 
[WARN ] 2022-07-14 16:50:33,751 --main-- [com.zaxxer.hikari.pool.ProxyConnection] HikariPool-1 - Connection org.opengauss.jdbc.PgConnection@79980d8d marked as broken because of SQLSTATE(0A000), ErrorCode(0) 
java.sql.SQLFeatureNotSupportedException: 这个 org.opengauss.jdbc.PgDatabaseMetaData.getRowIdLifetime() 方法尚未被实作。
    at org.opengauss.Driver.notImplemented(Driver.java:907)
    at org.opengauss.jdbc.PgDatabaseMetaData.getRowIdLifetime(PgDatabaseMetaData.java:2587)
    at com.zaxxer.hikari.pool.HikariProxyDatabaseMetaData.getRowIdLifetime(HikariProxyDatabaseMetaData.java)
    at org.apache.shardingsphere.driver.jdbc.context.CachedDatabaseMetaData.getRowIdLifetimeFromOriginMetaData(CachedDatabaseMetaData.java:437)
    at org.apache.shardingsphere.driver.jdbc.context.CachedDatabaseMetaData.<init>(CachedDatabaseMetaData.java:431)
    at org.apache.shardingsphere.driver.jdbc.context.JDBCContext.createCachedDatabaseMetaData(JDBCContext.java:59)
    at org.apache.shardingsphere.driver.jdbc.context.JDBCContext.<init>(JDBCContext.java:40)
    at org.apache.shardingsphere.driver.jdbc.core.datasource.ShardingSphereDataSource.<init>(ShardingSphereDataSource.java:67)
    at org.apache.shardingsphere.driver.api.ShardingSphereDataSourceFactory.createDataSource(ShardingSphereDataSourceFactory.java:77)
    at org.apache.shardingsphere.driver.api.yaml.YamlShardingSphereDataSourceFactory.createDataSource(YamlShardingSphereDataSourceFactory.java:133)
    at org.apache.shardingsphere.driver.api.yaml.YamlShardingSphereDataSourceFactory.createDataSource(YamlShardingSphereDataSourceFactory.java:62)
    at com.strongduanmu.datasource.jdbc.YamlDataSourceFactory.newInstance(YamlDataSourceFactory.java:25)
    at com.strongduanmu.feature.traffic.AbstractTrafficTest.setUp(AbstractTrafficTest.java:25)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:309)
    at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:86)
    at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:459)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:675)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:382)
    at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:192)
[INFO ] 2022-07-14 16:50:33,759 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [45068f19-68a8-4619-ac99-bf34d75b7ecd] Try to connect. IP: Og_IP1:14000 
[INFO ] 2022-07-14 16:50:33,891 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] [CS_IP:51525/Og_IP1:14000] Connection is established. ID: 45068f19-68a8-4619-ac99-bf34d75b7ecd 
[INFO ] 2022-07-14 16:50:33,996 --HikariPool-1 connection adder-- [org.opengauss.core.v3.ConnectionFactoryImpl] Connect complete. ID: 45068f19-68a8-4619-ac99-bf34d75b7ecd 
[INFO ] 2022-07-14 16:50:36,328 --main-- [ShardingSphere-SQL] Logic SQL: SELECT * FROM t_order WHERE content IN ('test1', 'test10') 
[INFO ] 2022-07-14 16:50:36,328 --main-- [ShardingSphere-SQL] SQLStatement: OpenGaussSelectStatement(limit=Optional.empty, lock=Optional.empty, window=Optional.empty) 
[INFO ] 2022-07-14 16:50:36,328 --main-- [ShardingSphere-SQL] Actual SQL: ds_0 ::: SELECT * FROM t_order_0 WHERE content IN ('test1', 'test10') UNION ALL SELECT * FROM t_order_1 WHERE content IN ('test1', 'test10') 
[INFO ] 2022-07-14 16:50:36,329 --main-- [ShardingSphere-SQL] Actual SQL: ds_1 ::: SELECT * FROM t_order_0 WHERE content IN ('test1', 'test10') UNION ALL SELECT * FROM t_order_1 WHERE content IN ('test1', 'test10') 
[INFO ] 2022-07-14 16:50:36,520 --main-- [org.apache.curator.framework.imps.CuratorFrameworkImpl] Starting 
[INFO ] 2022-07-14 16:50:36,520 --main-- [org.apache.zookeeper.ZooKeeper] Initiating client connection, connectString=7.212.123.28:2181 sessionTimeout=60000000 watcher=org.apache.curator.ConnectionState@11015ca0 
[INFO ] 2022-07-14 16:50:36,522 --main-- [org.apache.zookeeper.ClientCnxnSocket] jute.maxbuffer value is 1048575 Bytes 
[INFO ] 2022-07-14 16:50:36,522 --main-- [org.apache.zookeeper.ClientCnxn] zookeeper.request.timeout value is 0. feature enabled=false 
[INFO ] 2022-07-14 16:50:36,522 --main-- [org.apache.curator.framework.imps.CuratorFrameworkImpl] Default schema 
[INFO ] 2022-07-14 16:50:36,524 --main-SendThread(7.212.123.28:2181)-- [org.apache.zookeeper.ClientCnxn] Opening socket connection to server kwemhisprc10431/7.212.123.28:2181. 
[INFO ] 2022-07-14 16:50:36,524 --main-SendThread(7.212.123.28:2181)-- [org.apache.zookeeper.ClientCnxn] SASL config status: Will not attempt to authenticate using SASL (unknown error) 
[INFO ] 2022-07-14 16:50:36,560 --main-SendThread(7.212.123.28:2181)-- [org.apache.zookeeper.ClientCnxn] Socket connection established, initiating session, client: /CS_IP:51533, server: kwemhisprc10431/7.212.123.28:2181 
[INFO ] 2022-07-14 16:50:36,598 --main-SendThread(7.212.123.28:2181)-- [org.apache.zookeeper.ClientCnxn] Session establishment complete on server kwemhisprc10431/7.212.123.28:2181, session id = 0x1001acd34aa0120, negotiated timeout = 40000 
[INFO ] 2022-07-14 16:50:36,598 --main-EventThread-- [org.apache.curator.framework.state.ConnectionStateManager] State change: CONNECTED 
[INFO ] 2022-07-14 16:50:36,636 --main-EventThread-- [org.apache.curator.framework.imps.EnsembleTracker] New config event received: {} 
[INFO ] 2022-07-14 16:50:36,636 --main-EventThread-- [org.apache.curator.framework.imps.EnsembleTracker] New config event received: {}

Example codes for reproduce this issue (such as a github link).

package com.strongduanmu.feature.traffic.sql;

import com.google.common.collect.Sets;
import com.strongduanmu.feature.traffic.AbstractTrafficTest;
import org.junit.Test;

import java.sql.PreparedStatement;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.util.Arrays;

import static org.hamcrest.CoreMatchers.is;
import static org.hamcrest.MatcherAssert.assertThat;
import static org.junit.Assert.assertTrue;

/**
 * SQL match traffic test.
 */
public class SQLMatchTrafficTest2 extends AbstractTrafficTest {

    @Test
    public void testSQLMatchTrafficWhenUsePreparedStatementAlgorithmMatch() throws SQLException {
        String sql = "SELECT * FROM t_order WHERE content IN (?, ?)";
        PreparedStatement statement = getPreparedStatement(sql, Arrays.asList("test1", "test10"));
        statement.executeQuery();
        ResultSet resultSet = statement.getResultSet();
        int count = 0;
        while (resultSet.next()) {
            count++;
            for (int index = 0; index < resultSet.getMetaData().getColumnCount(); index++) {
                System.out.print(resultSet.getObject(index + 1) + " ");
            }
            assertTrue(Sets.newHashSet("test1", "test10").contains(resultSet.getString(3)));
            System.out.println();
        }
        assertThat(count, is(2));
    }

    @Test
    public void testSQLMatchTrafficWhenUseStatementAlgorithmMatch() throws SQLException {
        String sql = "SELECT * FROM t_order WHERE content IN ('test1', 'test10')";
        getStatement().execute(sql);
    }

    @Test
    public void testSQLMatchTrafficWhenUsePreparedStatementAlgorithmNotMatch() throws SQLException {
        String sql = "SELECT * FROM t_order WHERE content IN (?, ?) AND user_id = 1";
        PreparedStatement statement = getPreparedStatement(sql, Arrays.asList("test1", "test10"));
        statement.executeQuery();
        ResultSet resultSet = statement.getResultSet();
        int count = 0;
        while (resultSet.next()) {
            count++;
            for (int index = 0; index < resultSet.getMetaData().getColumnCount(); index++) {
                System.out.print(resultSet.getObject(index + 1) + " ");
            }
            assertTrue(Sets.newHashSet("test1").contains(resultSet.getString(3)));
            System.out.println();
        }
        assertThat(count, is(1));
    }
}
jingshanglu commented 2 years ago

The Datasource is initialized for each case, leading to multiple XA TM initializations. Even if the initialization of XA TM is removed, the RT does not decrease significantly, and a flame graph needs to be provided for further analysis.

justbk2015 commented 2 years ago

this only a warn log. not problem

TeslaCN commented 2 years ago

please modify CachedDatabaseMetaData.java:getRowIdLifetimeFromOriginMetaData , catch SQLFeatureNotSupportedException to SQLException, because getRowIdLifetime in hikari will throw SQLException!

I don't think the Hikari will change the cause.

image image image
github-actions[bot] commented 2 years ago

Hello , this issue has not received a reply for several days. This issue is supposed to be closed.