问题描述
线上环境中代码无故停顿16分钟左右。就像执行了Thread.sleep(16min)
一样。很多地方都出现过。并不固定一个方法。
之前怀疑是redis的问题。后来发现没有使用redis的地方也有这种情况。之前也发过一个提问。
问题出现的环境背景及自己尝试过哪些方法
一开始以为是redis的原因,然后修改过redis部分操作代码。修改过redis配置,然后没有效果。
又修改过tomcat配置如下:
<Service name="Catalina"> <Executor name="tomcatThreadPool" namePrefix="catalina-exec-" maxThreads="500" minSpareThreads="10" maxSpareThreads="50" maxIdleTime="60000" prestartminSpareThreads = "true" maxQueueSize = "100" /> <Connector executor="tomcatThreadPool" port="8080" protocol="org.apache.coyote.http11.Http11Nio2Protocol" connectionTimeout="20000" maxConnections="1000" enableLookups="false" acceptCount="100" maxPostSize="10485760" compression="on" disableUploadTimeout="true" acceptorThreadCount="2" redirectPort="8443" URIEncoding="utf-8" />
使用线程池,依然没有效果。
最后修改JVM配置:JAVA_OPTS="-server -Xms1024m -Xmx1024m -XX:PermSize=128M -XX:MaxPermSize=256m -XX:NewRatio=3"
依然没有效果。不知道问题出在哪。
相关代码
// 请把代码文本粘贴到下方(请勿用图片代替代码)
/**
* API统一入口
*
* @Description: TODO
* @author lxlong
* @Time:2017年11月10日 上午11:55:03
* @version 1.0
*/
@Controller
@RequestMapping("/xxx")
public class UnifiedController {
@RequestMapping(value = "/xxx", method = RequestMethod.POST, headers = "Accept=application/json", produces = "application/json;charset=utf-8")
@ResponseBody
public String unifiedEntrance(@RequestBody String param) {
return UnifiedAPIUtil.procAPI(param);
}
}
public class UnifiedAPIUtil {
private static Logger log = Logger.getLogger(UnifiedAPIUtil.class);
/**
* api统一入口
*
* @Description
* @author lxlong
* @param param
* @return
*/
public static String procAPI(String param) {
Result result = new Result();
RedisLock redisLock = new RedisLock();
/** 获取请求数据 */
HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes())
.getRequest();
String token = StringUtil.toString(request.getHeader("token"));//token
String targetPar = StringUtil.toString(request.getHeader("target"));//类
String methodPar = StringUtil.toString(request.getHeader("method"));//方法名
//设置请求头实体
Header header = new Header();
header.setTarget(targetPar);
header.setMethod(methodPar);
try {
/* 获取请求报文数据 */
log.info(targetPar + "." + methodPar + ":请求参数=" + param);
//获取方法和对象
String key = header.getTarget() + "_" + header.getMethod();
Method lyzMethod = serverMethods.get(key);
if (lyzMethod == null) {
throw new NoSuchMethodException();
}
java.lang.reflect.Method method = lyzMethod.getMethod();
CommonControl ctrl = (CommonControl) lyzMethod.getTarget();
//加锁
if (!redisLock.lockKey(userId)) {
throw new LockOccupiedException();
}
//执行逻辑
method.invoke(ctrl, result, header, param);
} catch (Exception e) {
log.error("系统异常", e);
result.setCodeForFail(CodeEum.Code.ERROR);
//兼容旧版本
result.setReturnsResult(ReturnMsg.ERROR.key(), ReturnMsg.ERROR.value());
} finally {
//释放锁
log.info(targetPar + "." + methodPar + ":准备释放资源锁");
if (StringUtil.isNotEmpty(token)) {
redisLock.unLock(token);
}
}
log.info(targetPar + "." + methodPar + ":响应参数=" + result.getResult());
return result.getResult();
}
}
Controller;
public class ApiOrderControl implements CommonControl {
@Resource
private IOrderService orderService;
public void createNewOrder(Result result, Header header, String jsonString) throws NotDataException, Exception {
log.info("=====================提交订单接口=====================");
//doSomeThing();
Order order = new Order();
order.set(xxx);
order.set(xxx);
order.set(xxx);
order.set(xxx);
orderService.save(order);
}
public void recallOrder(Result result, Header header, String jsonString) throws Exception {
log.info("=====================取消订单接口=====================");
//doSomeThing()
order.setStatus(0);
orderService.update(order);
}
}
Service
public class orderService implements IOrderService {
@Reousece
private IOrderDao orderDao;
@Override
@Transactional
public void save(Order order) throws NotDataException, Exception {
orderDao.save(order);
}
@Override
@Transactional
public void update(Order order) throws NotDataException, Exception {
order.setUpdateTime(DateUtil.getTime());
orderDao.update(order);
}
}
你期待的结果是什么?实际看到的错误信息又是什么?
然后后台日志是这样的
[INFO] 2019-05-10 02:01:45,280 com.leyizhu.api.util.UnifiedAPIUtil - 请求头数据 >>>>> Header [token=083e19b0251c44458e9d729cf535bd86 target=apiOrderControl, method=createNewOrder]
[INFO] 2019-05-10 02:01:45,280 com.leyizhu.api.util.UnifiedAPIUtil - apiOrderControl.createNewOrder:请求参数={"aaaa":"aaaa"}
[INFO] 2019-05-10 02:01:45,294 com.leyizhu.plugin.RedisLockUtil.RedisLock - ---------------LOCK_PREFIX_083e19b0251c44458e9d729cf535bd86加锁成功-------------------
[INFO] 2019-05-10 02:01:45,294 com.leyizhu.api.control.order.ApiOrderControl - =====================提交订单接口=====================
[INFO] 2019-05-10 02:01:45,830 com.leyizhu.api.util.UnifiedAPIUtil - apiOrderControl.createNewOrder:准备释放资源锁
[INFO] 2019-05-10 02:17:49,001 com.leyizhu.plugin.RedisLockUtil.RedisLock - ---------------LOCK_PREFIX_083e19b0251c44458e9d729cf535bd86释放成功-------------------
[INFO] 2019-05-10 02:17:49,001 com.leyizhu.api.util.UnifiedAPIUtil - apiOrderControl.createNewOrder:响应参数={"code":"100","codemsg":"成功""data":{"createTime":"2019-05-10 02:01:45","orderNO":"04440300031905100567635","orderType":1}}
这里在 准备释放资源 和 成功释放资源之间相差了16分钟左右。资源锁是采用redis实现的。
然后还有一次
[INFO] 2019-05-10 02:02:55,924 com.leyizhu.api.util.UnifiedAPIUtil - 请求头数据 >>>>> Header [token=083e19b0251c44458e9d729cf535bd86, method=recallOrder, platform=3]
[INFO] 2019-05-10 02:02:55,924 com.leyizhu.api.util.UnifiedAPIUtil - apiOrderControl.recallOrder:请求参数={"orderNO":"04440300031905100567635","orderType":"1"}
[INFO] 2019-05-10 02:02:55,935 com.leyizhu.plugin.RedisLockUtil.RedisLock - ===================前一锁已超时========================
[INFO] 2019-05-10 02:02:55,937 com.leyizhu.plugin.RedisLockUtil.RedisLock - ---------------LOCK_PREFIX_083e19b0251c44458e9d729cf535bd86加锁成功-------------------
[INFO] 2019-05-10 02:02:55,937 com.leyizhu.api.control.order.ApiOrderControl - =====================取消订单接口=====================
[INFO] 2019-05-10 02:19:01,497 com.leyizhu.api.util.UnifiedAPIUtil - apiOrderControl.recallOrder:准备释放资源锁
[INFO] 2019-05-10 02:19:01,499 com.leyizhu.plugin.RedisLockUtil.RedisLock - ---------------LOCK_PREFIX_083e19b0251c44458e9d729cf535bd86已被其他线程获取/未获取到锁-------------------
[INFO] 2019-05-10 02:19:01,499 com.leyizhu.api.util.UnifiedAPIUtil - apiOrderControl.recallOrder:响应参数={"code":"100","codemsg":"成功","data":{}}
这一次是在 执行逻辑 和 准备释放资源的 时间上相差 16分钟左右
然后查看mysql的binlog发现 取消订单的时候当方法执行到orderService.update()方法里的时候时间确实是2019-05-10 02:02:55
,但是update提交事务的时间是2019-05-10 02:19:01
这中间不知道是为什么。而且这也可以看出不是redis的问题。因为两次停顿发生的时间点不一样。取消订单时还未执行到 释放锁 的逻辑。
一开始我以为是redis卡住的提问地址:redis连接拥塞。我不知道这样说对不对?
请求大神解答。
怎么锁没有超时时间?