From bf81ed678c5a8be5ad014fbc216cf937d7f38923 Mon Sep 17 00:00:00 2001 From: jimin Date: Wed, 5 Jul 2023 10:40:59 +0800 Subject: [PATCH] optimize: optimize distributed lock log Signed-off-by: slievrly --- changes/en-us/2.0.0.md | 1 + changes/zh-cn/2.0.0.md | 1 + .../db/lock/DataBaseDistributedLocker.java | 50 ++++++++++++++++--- 3 files changed, 44 insertions(+), 8 deletions(-) diff --git a/changes/en-us/2.0.0.md b/changes/en-us/2.0.0.md index b9d5bd4a44d..1485bfcc230 100644 --- a/changes/en-us/2.0.0.md +++ b/changes/en-us/2.0.0.md @@ -101,6 +101,7 @@ The version is updated as follows: - [[#5553](https://github.com/seata/seata/pull/5553)] support case-sensitive attributes for table and column metadata - [[#5644](https://github.com/seata/seata/pull/5644)] optimize server logs print - [[#5680](https://github.com/seata/seata/pull/5680)] optimize escape character for case of columnNames +- [[#5714](https://github.com/seata/seata/pull/5714)] optimize distributed lock log ### security: - [[#5642](https://github.com/seata/seata/pull/5642)] add Hessian Serializer WhiteDenyList diff --git a/changes/zh-cn/2.0.0.md b/changes/zh-cn/2.0.0.md index 241ce71bf51..9313458e583 100644 --- a/changes/zh-cn/2.0.0.md +++ b/changes/zh-cn/2.0.0.md @@ -101,6 +101,7 @@ Seata 是一款开源的分布式事务解决方案，提供高性能和简单 - [[#5553](https://github.com/seata/seata/pull/5553)] 支持表和列元数据大小写敏感设置 - [[#5644](https://github.com/seata/seata/pull/5644)] 优化Server日志输出 - [[#5680](https://github.com/seata/seata/pull/5680)] 优化大小写转义符 +- [[#5714](https://github.com/seata/seata/pull/5714)] 优化分布式锁竞争日志 ### security: - [[#5642](https://github.com/seata/seata/pull/5642)] 增加Hessian 序列化黑白名单 diff --git a/server/src/main/java/io/seata/server/storage/db/lock/DataBaseDistributedLocker.java b/server/src/main/java/io/seata/server/storage/db/lock/DataBaseDistributedLocker.java index 0b39a0126c7..70f101edf63 100644 --- a/server/src/main/java/io/seata/server/storage/db/lock/DataBaseDistributedLocker.java +++ b/server/src/main/java/io/seata/server/storage/db/lock/DataBaseDistributedLocker.java @@ -15,13 +15,16 @@ */ package io.seata.server.storage.db.lock; - import java.sql.Connection; import java.sql.PreparedStatement; import java.sql.ResultSet; import java.sql.SQLException; +import java.util.HashSet; import java.util.Objects; +import java.util.Set; + import javax.sql.DataSource; + import io.seata.common.exception.ShouldNeverHappenException; import io.seata.common.loader.EnhancedServiceLoader; import io.seata.common.loader.LoadLevel; @@ -59,6 +62,19 @@ public class DataBaseDistributedLocker implements DistributedLocker { private DataSource distributedLockDataSource; + private static final String LOCK_WAIT_TIMEOUT_MYSQL_MESSAGE = "try restarting transaction"; + + private static final int LOCK_WAIT_TIMEOUT_MYSQL_CODE = 1205; + + private static final Set IGNORE_MYSQL_CODE = new HashSet<>(); + + private static final Set IGNORE_MYSQL_MESSAGE = new HashSet<>(); + + static { + IGNORE_MYSQL_CODE.add(LOCK_WAIT_TIMEOUT_MYSQL_CODE); + IGNORE_MYSQL_MESSAGE.add(LOCK_WAIT_TIMEOUT_MYSQL_MESSAGE); + } + /** * whether the distribute lock demotion * using for 1.5.0 only and will remove in 1.6.0 @@ -112,16 +128,16 @@ public boolean acquireLock(DistributedLockDO distributedLockDO) { originalAutoCommit = connection.getAutoCommit(); connection.setAutoCommit(false); - DistributedLockDO distributedLockDOFromDB = getDistributedLockDO(connection, distributedLockDO.getLockKey()); - if (null == distributedLockDOFromDB) { + DistributedLockDO lockFromDB = getDistributedLockDO(connection, distributedLockDO.getLockKey()); + if (null == lockFromDB) { boolean ret = insertDistribute(connection, distributedLockDO); connection.commit(); return ret; } - if (distributedLockDOFromDB.getExpireTime() >= System.currentTimeMillis()) { + if (lockFromDB.getExpireTime() >= System.currentTimeMillis()) { LOGGER.debug("the distribute lock for key :{} is holding by :{}, acquire lock failure.", - distributedLockDO.getLockKey(), distributedLockDOFromDB.getLockValue()); + distributedLockDO.getLockKey(), lockFromDB.getLockValue()); connection.commit(); return false; } @@ -131,7 +147,11 @@ public boolean acquireLock(DistributedLockDO distributedLockDO) { return ret; } catch (SQLException ex) { - LOGGER.error("execute acquire lock failure, key is: {}", distributedLockDO.getLockKey(), ex); + // ignore "Lock wait timeout exceeded; try restarting transaction" + // TODO: need nowait adaptation + if (!ignoreSQLException(ex)) { + LOGGER.error("execute acquire lock failure, key is: {}", distributedLockDO.getLockKey(), ex); + } try { if (connection != null) { connection.rollback(); @@ -170,8 +190,10 @@ public boolean releaseLock(DistributedLockDO distributedLockDO) { if (distributedLockDOFromDB.getExpireTime() >= System.currentTimeMillis() && !Objects.equals(distributedLockDOFromDB.getLockValue(), distributedLockDO.getLockValue())) { - LOGGER.debug("the distribute lock for key :{} is holding by :{}, skip the release lock.", + if (LOGGER.isDebugEnabled()) { + LOGGER.debug("the distribute lock for key :{} is holding by :{}, skip the release lock.", distributedLockDO.getLockKey(), distributedLockDOFromDB.getLockValue()); + } connection.commit(); return true; } @@ -183,7 +205,9 @@ public boolean releaseLock(DistributedLockDO distributedLockDO) { connection.commit(); return ret; } catch (SQLException ex) { - LOGGER.error("execute release lock failure, key is: {}", distributedLockDO.getLockKey(), ex); + if (!ignoreSQLException(ex)) { + LOGGER.error("execute release lock failure, key is: {}", distributedLockDO.getLockKey(), ex); + } try { if (connection != null) { @@ -251,4 +275,14 @@ private void init() { this.distributedLockDataSource = EnhancedServiceLoader.load(DataSourceProvider.class, datasourceType).provide(); } + private boolean ignoreSQLException(SQLException exception) { + if (IGNORE_MYSQL_CODE.contains(exception.getErrorCode())) { + return true; + } + if (StringUtils.isNotBlank(exception.getMessage())) { + return IGNORE_MYSQL_MESSAGE.stream().anyMatch(message -> exception.getMessage().contains(message)); + } + return false; + } + }