题目描述
正常的日志应该是
19-04-26 12:26:42.203 [http-nio-39087-exec-9] DEBUG c.w.s.m.c.m.C.updateByPrimaryKeySelective - ==> Preparing: UPDATE tbc_consumer_card SET money = ?,spend_money = ? WHERE consumer_card_id = ?
19-04-26 12:26:42.203 [http-nio-39087-exec-9] DEBUG c.w.s.m.c.m.C.updateByPrimaryKeySelective - ==> Parameters: 431.28(BigDecimal), 68.72(BigDecimal), 9724fe63fd6941e1b9b5532bafd14773(String)
19-04-26 12:26:42.205 [http-nio-39087-exec-9] DEBUG c.w.s.m.c.m.C.updateByPrimaryKeySelective - <== Updates: 1
19-04-26 12:26:42.207 [http-nio-39087-exec-9] DEBUG c.w.s.m.c.m.C.insert - ==> Preparing: INSERT INTO tbc_consumer_card_detail ( consumer_detail_id,order_code,consumer_card_id,card_no,operate_type,original_money,money,now_money,actual_money,remark,store_id,creator,create_time,cashier_info_id ) VALUES( ?,?,?,?,?,?,?,?,?,?,?,?,?,? )
19-04-26 12:26:42.207 [http-nio-39087-exec-9] DEBUG c.w.s.m.c.m.C.insert - ==> Parameters: dbe3478df1524de7bc631c6c72a5a8d5(String), 0025201904260077(String), 9724fe63fd6941e1b9b5532bafd14773(String), 88008622(String), 3(String), 459.00(BigDecimal), 27.72(BigDecimal), 431.28(BigDecimal), null, null, ebf928b4999e4d67ac3ce14415a8f795(String), null, 2019-04-26 12:26:42.205(Timestamp), b049e7d03b8c475b97043a3add9a2bdc(String)
19-04-26 12:26:42.208 [http-nio-39087-exec-9] DEBUG c.w.s.m.c.m.C.insert - <== Updates: 1
执行完更新后,插入一条日志记录。
但是在应用中经常出现执行到更新的时候应用卡主,很长时间之后才有结果。
19-04-26 18:00:47.230 [http-nio-39087-exec-9] DEBUG c.w.s.m.c.m.C.updateByPrimaryKeySelective - ==> Preparing: UPDATE tbc_consumer_card SET money = ?,spend_money = ? WHERE consumer_card_id = ?
19-04-26 18:00:47.230 [http-nio-39087-exec-9] DEBUG c.w.s.m.c.m.C.updateByPrimaryKeySelective - ==> Parameters: 227.34(BigDecimal), 272.66(BigDecimal), ab65db079bef4be8a34258afc0f0d9ae(String)
.........
19-04-26 18:01:19.787 [http-nio-39087-exec-3] DEBUG c.w.s.m.c.m.C.queryCardByBarCode - <== Total: 1
19-04-26 18:01:19.787 [http-nio-39087-exec-3] DEBUG c.w.s.m.c.m.C.updateByPrimaryKeySelective - ==> Preparing: UPDATE tbc_consumer_card SET money = ?,spend_money = ? WHERE consumer_card_id = ?
19-04-26 18:01:19.787 [http-nio-39087-exec-3] DEBUG c.w.s.m.c.m.C.updateByPrimaryKeySelective - ==> Parameters: 227.34(BigDecimal), 272.66(BigDecimal), ab65db079bef4be8a34258afc0f0d9ae(String)
19-04-26 18:01:19.935 [http-nio-39087-exec-9] DEBUG c.w.s.m.c.m.C.updateByPrimaryKeySelective - <== Updates: 1
19-04-26 18:01:19.935 [http-nio-39087-exec-9] DEBUG c.w.s.m.c.m.C.insert - ==> Preparing: INSERT INTO tbc_consumer_card_detail ( consumer_detail_id,order_code,consumer_card_id,card_no,operate_type,original_money,money,now_money,actual_money,remark,store_id,creator,create_time,cashier_info_id ) VALUES( ?,?,?,?,?,?,?,?,?,?,?,?,?,? )
19-04-26 18:01:19.935 [http-nio-39087-exec-9] DEBUG c.w.s.m.c.m.C.insert - ==> Parameters: 58a3c6159d6448ea8fff1ee5d5613139(String), 0024201904260097(String), ab65db079bef4be8a34258afc0f0d9ae(String), 88001686(String), 3(String), 500.00(BigDecimal), 272.66(BigDecimal), 227.34(BigDecimal), null, null, ebf928b4999e4d67ac3ce14415a8f795(String), null, 2019-04-26 18:01:19.935(Timestamp), 558b511bdb1948fe8223bde0e757d804(String)
19-04-26 18:01:19.937 [http-nio-39087-exec-9] DEBUG c.w.s.m.c.m.C.insert - <== Updates: 1
从日志上可以看到,线程http-nio-39087-exec-9
在阻塞结束之前,线程http-nio-39087-exec-3
提交了一个一样的更新请求。
在线程http-nio-39087-exec-9
提交更新请求之前,并没有任何应用或人对这条记录有过更新(也就是说没有人锁表)。但是看这情况好像是表被锁了。
MySQL的版本是5.7,事务是用Spring控制的。方法上有@Transactional
注解。
题目来源及自己的思路
业务中就是很简单的更新和插入操作。没有其他操作。现在不清楚被阻塞的原因,会不会是MySQL的BUG呢,或者磁盘的问题?求大神指点。
业务代码
@Override
@Transactional
public void saveFeeCard(String orderCode, String barCode, BigDecimal money, String shopId, String cashierInfoId, Integer operateType) {
ShopInfo shopInfo = shopInfoMapper.selectByPrimaryKey(shopId);
List<ConsumerCard> consumerCards = consumerCardMapper.queryCardByBarCode(barCode,shopInfo.findBranchShopId());
ConsumerCard consumerCard = this.checkCard(consumerCards);
// 验证消费卡余额
if (consumerCard.getMoney() == null || consumerCard.getMoney().subtract(money).compareTo(BigDecimal.ZERO) < 0)
throw new ServiceException(ErrorInfo.CONSUMERCARD_FEE_0001);
BigDecimal originlMoney = consumerCard.getMoney();
ConsumerCard card = new ConsumerCard();
card.setConsumerCardId(consumerCard.getConsumerCardId());
card.setMoney(originlMoney.subtract(money));
card.setSpendMoney(consumerCard.getSpendMoney().add(money));
consumerCardMapper.updateByPrimaryKeySelective(card);
ConsumerCardDetail consumerCardDetail = new ConsumerCardDetail();
consumerCardDetail.setConsumerDetailId(UUIDGenerator.genertate());
consumerCardDetail.setOrderCode(orderCode);
consumerCardDetail.setConsumerCardId(consumerCard.getConsumerCardId());
consumerCardDetail.setCardNo(consumerCard.getCardNo());
consumerCardDetail.setOperateType(String.valueOf(operateType));
consumerCardDetail.setOriginalMoney(originlMoney);
consumerCardDetail.setMoney(money);
consumerCardDetail.setNowMoney(originlMoney.subtract(money));
consumerCardDetail.setStoreId(shopId);
consumerCardDetail.setCashierInfoId(cashierInfoId);
consumerCardDetail.setCreateTime(new Date());
consumerCardDetailMapper.insert(consumerCardDetail);
}
问题已经找到了,是因为整点备份的时候IO过高导致的。目前是把备份时间调到了夜里12点以后,每天备份一次,不再每小时备份。暂时没有找到更好的解决办法。