一条慢查询引发的MYSQL索引思考

logger日志报错 插入数据时违反主键唯一约束

一条慢查询日志

org.springframework.dao.DuplicateKeyException: 
### Error updating database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '189378605' for key 'PRIMARY'
### The error may involve com.ccf.springboot.mapper.middle.MiddleMapper.insertSyncBatch-Inline
### The error occurred while setting parameters
### SQL: INSERT INTO sync_batch ( uniqueId, erpId, manufactureDate, effectivityDate, batchNumber, createdDate, modifyDate )     VALUE    (?,?,?,?,?,NOW( ),NOW( ) )

mysql的索引是一把双刃剑,如果使用得当,会给系统带来极大的性能提升;相反的如果使用不当,则可能会带来灾难性的后果。最可怕的是前期很难发现,随着数据量的增加以及业务高峰期的临近,问题才会突然暴露出来。

初步分析

本周我所负责的一个系统就出来了类似的问题,庆幸的是处理及时,没有造成灾难性的后果。今天抽时间把事情的经过记录下来,在未来的时间里鞭策自己:对新成员必须进行sql语句基础规范的学习,并对每个人每次上线的sql语句必须进行code review。

  在这个表中主键uniqueId 不是自增长 而是由erpId和batchNumber合并组成主键id

这个系统是一个新业务,并且也已经上线正常运行了一段时间。随着618大促的临近业务量增加,问题才暴露出来。本周三晚上加班,突然收到DBA信息说我们mysql所在的服务器cpu利用率在近20分钟内急剧攀升,快到90%,让我们排查是不是我们的应用导致的(该mysql服务器上有多个应用对应的多个数据库)。事发突然,立即向DBA索要慢查询日志进行分析,日志如下(已屏蔽业务信息):

   当有重复的主键id插入时报了这个异常 即插入的数据可能存在数据重复的问题 ok 那么接下来排查下sql 看看原始数据

金沙官网线上 1

SELECT DISTINCT
            goodsid,
            proddate,
            v.INVALIDDATE,
            lotno 
        FROM
            BMS_ST_qty_LST_GAOXING_V v 
        WHERE
            storageid = 10

从慢查询日志中可以看到,最消耗性能的语句是“SELECT xxx_pc_act_profile”,该语句在26分钟内(Time range: 2017-05-31 20:20:02 to 20:46:04),执行7618次,平均每次大约113ms,已经到了无法容忍的地步。并且不幸的是,这张表确实是属于我们系统。

在sql中使用了关键字DISTINCT 正常来说不应有重复数据产生 为了排查原因 将报错的erpId 带入本条sql查询(图一中的erpId 对应上图的goodsid) 

解决问题步骤

金沙官网线上 2

第一步:停服务

发现查到数据有2条

由于该mysql服务器中还有其他应用数据库,为了防止影响其他业务,第一步就是立即决定停掉我们这个子系统服务(权衡影响范围)。再次观察msyql服务器情况,cpu使用率恢复正常,进一步说明确实是由于该业务引起。

接下来去除关键字再试下

第二步:初步确定索引问题

金沙官网线上 3

分析这个出问题的语句,是一个select语句:

发现查到有3条一模一样的数据  这就说明去重关键字实际上有起作用的 但是为什么有一条数据没有去重呢 

SELECT

一番排查后 找到了原因

xxx,xxx,xxx,xxx

金沙官网线上 4

FROM xxx_pc_act_profile

 

where

 LOTNO中有一条数据后面存在空串导致 去重关键字没办法去重 

and start_time <= '2017-05-31 20:30:00'

解决方案

and end_time >= '2017-05-31 20:30:00'

  经上面查证 证实是数据维护的原因 脑海里第一个想法是修改数据 但是考虑到数据有关联的原因 修改并不合适

and valid_flag = 1

  但假如不修改 将查询到的数据直接插入到sync_batch 还是会报异常

and status = 1

    尝试将异常抓起 不予解决 然后记录日志   问题解决

and brandIds = '94924'

   

order by weight desc desc

for (SyncBatch erpSyncBatch : erpListSyncBatch) {
            if (erpSyncBatch.getFlag() == null) {
                try {
                    middleService.insertSyncBatch(erpSyncBatch);
                } catch (DuplicateKeyException e) {
                    LOGGER.error("违反唯一约束"+erpSyncBatch.getErpId());
                }catch (Exception e) {
                    LOGGER.error(ERROR_SYNC_BATCH,e);
                    throw new RuntimeException(e);
                }
            }
        }

可以看到这里的where语句里有很多查询条件,还有order by语句,由于select语句导致的性能问题,可以99%的确定是索引设置不当引起的。

 

第三步:分析执行计划,以及索引命中情况

  

查看执行计划:explain select xxx from xxx_pc_act_profile where xxx;

发现查询命中索引'idx_status',看起来像是在一个状态字段上建了索引。进一步确认,证实status字段是一个状态字段(0-正常,1-下线)。

至此定位到问题原因:错误的在“低基数列创建索引”。

第四步:查看表索引的创建明细

CREATE TABLE `xxx_pc_act_profile` (

--省略字段

PRIMARY KEY (`id`),

KEY `idx_url`金沙官网线上, (`url`),

KEY `idx_third_cate` (`third_cate`),

KEY `idx_start_time` (`start_time`),

KEY `idx_end_time` (`end_time`),

KEY `idx_status` (`status`),

KEY `idx_valid_flag` (`valid_flag`),

KEY `idx_pre_cate_level` (`pre_cate_level`),

KEY `idx_confirm_flag` (`confirm_flag`),

KEY `idx_last_publish_date` (`last_publish_date`),

KEY `idx_valid_query` (`start_time`,`end_time`,`status`,`valid_flag`)

) ENGINE=InnoDB COMMENT='xxx活动画像表'

看到这里惊呆了,这都创建了些什么索引。初步列举问题:

1、索引创建太多(普通索引是B-TREE,需要单独的存储空间)。

2、对低基数列创建索引,如:status、valid_flag 等。

3、对字符串类型创建索引,如:third_cate等。

4、对无用字段创建索引:url,这个索引根本就没用。

也行还会发现其他很多的问题。

到这里突然发现自己应该负很大的责任:对新同事的培养,平时都只是停留在java coding上,尤其是现在大部分业务都有redis缓存挡在上一层,对sql的基础规范没有组织学习,上线前的code review也没有覆盖到sql。

本文由金沙官网线上发布于数据库,转载请注明出处:一条慢查询引发的MYSQL索引思考

您可能还会对下面的文章感兴趣: