seata事务回滚引起的skywalking数据库存储空间剧增的问题排查-CSDN博客

阿里云国内75折回扣微信号：monov8

阿里云国际，腾讯云国际，低至75折。AWS 93折免费开户实名账号代冲值优惠多多微信号：monov8 飞机：@monov6

基本信息

产品名称ATS3.0

问题分类编码问题

环境类型环境无关

问题现象
11月1日上午华润DBA收到数据库磁盘空间告警检查后发现skywalking连接的mysql数据库占用空间从之前一直是比较稳定的但是10月31日开始激增一天左右原来剩250G+的磁盘空间只剩下了50G左右。进一步排查发现数据主要集中在skywalking的segment表中。
问题原因
seata回滚一个数据库操作较多的事务由于seata客户端的问题没有正常关闭PrepareStatement最终触发了ORA-01000-超出打开游标的最大数问题生产库游标单个session最大300导致回滚失败。然后seata每秒都会再次触发重试又因为是一个大事务导致每秒都有大量的事务回滚的sql操作。因为我们安装了skywalking的oracle插件程序调用oracle的请求也会被记录最终导致大量的链路信息被记录到segment表中造成了skywalking的存储数据库空间暴增。
排查过程

4.1 紧急处置

1.先让客户删除了mysql库今天之前的binlog释放出部分空间否正剩余50G很可能几个小时候就会耗尽释放后剩余空间回到了250G左右有了比较充足的排查时间。

2.预案如果空间持续上升且还没找到原因的话可以尝试临时删除部分skywalking的数据因为只是用于监控不影响业务。或者暂时停止下skywalking。

4.2 定位skywalking的空间是被什么请求占用

1.segment表里的endpoint_id表示请求服务及地址的信息根据这个字段分类排序可以判断一段时间主要是哪个请求占用了空间。

sql: select count(*) as total , endpoint_id from segment s where start_time > 1667286000000 group by endpoint_id order by total desc;

start_time要根据查询的时间调整这个毫秒数

2. 发现主要是有两个请求触发的频率比较高

3. endponit_id下划线左边是服务名最后的.1也要去掉才是服务名右边是请求URL查看skywalking源码确定这串字符的编码规则写了一个转换的逻辑new String(Base64.getDecoder().decode(待转换内容), StandardCharsets.UTF_8);

4. 转换后发现这两个请求分别是ntms-financing的Oracle/JDBI/PreparedStatement/executeQuery和Oracle/JDBI/PreparedStatement/executeUpdate

5. 发现都是数据库操作后去ELK查了下financing服务的日志发现有大量的数据库操作日志都是seata回滚线程操作的此时基本可以判断是seata不断尝试回滚事务产生的日志接下来就需要具体是哪些事务回滚失败不停重试以及回滚失败的原因。

4.3 确认为什么会触发大量的问题请求

触发大量请求的原因

seata事务失败如果能回滚成功则会直接释放掉如果回滚失败则会一直尝试重试回滚每1s重试一次我们没有配置停止时间所以会一直重试。回滚的时候会去做undo_log表的查询、根据undo_log表的数据做业务表的查询等操作如果一个事务操作的数据量很大那么每次回滚都会打印很多sql语句也就会对skywalking记录的数据有影响了。

假设一个全局事务是插入1000条数据到表中那么回滚的时候会执行一次查询undo_log对于每行数据执行一次select for update执行一次delete共2001条sql。一次回滚正常要执行这么多sql如果回滚失败了过1s后还要再执行可以看到数据量是很大的。一天之内回滚日志就有五千多万条

查找回滚失败原因

通过查看日志找到每次执行一堆回滚sql后都会有一个报错

报错日志为”ORA-01000: maximum open cursors exceeded“也就是说seata很可能因为这个问题导致数据无法回滚。

对这个异常的解释oracle ORA-01000: maximum open cursors exceeded问题的解决方法-CSDN博客

简单地说就是conn.prepareStatement()会打开一个游标如果循环里调用这段代码并且没调用close方法的话就有可能造成上面的问题。

一些命令oracle怎么查询游标-Oracle-PHP中文网

# 查看当前打开的游标总数
select count(*) from v$open_cursor;
# 每个连接能打开的最大游标数
select value from v$parameter where name = 'open_cursors';
# 更改连接能开启的最大游标数改成1000
 alter system set open_cursors=1000 scope=both;

定位问题

通过条件"100.100.3.253:8091:4602887063828890271" and "error" 可以看到有一个异常日志通过调用栈可以大概找到报错的地方

再结合上面的”branchRollback failed. branchType:“可以大概定位到报错位置。

在io.seata.rm.datasource.undo.AbstractUndoLogManager#undo这段代码的位置是对当前事务分支做回滚的操作。先获取undo_log的中该分支的数据做反序列化后可以得到执行的每条sql的undo_log。一个本地事务每次执行sql都会生成一个SQLUndoLog在连接最后提交时会把该本地事务操作的所有SQLUndoLog封装为BranchUndoLog序列化到undo_log表中

再遍历该BranchUndoLog的SQLUndoLog的list对每一条SQLUndoLog执行io.seata.rm.datasource.undo.AbstractUndoExecutor#executeOn回滚操作。问题就出在这个方法

public void executeOn(Connection conn) throws SQLException {
    //dataValidationAndGoOn执行一下select xxx for update对该数据加锁。
    if (IS_UNDO_DATA_VALIDATION_ENABLE && !dataValidationAndGoOn(conn)) {
        return;
    }
    PreparedStatement undoPST = null;
    try {
        String undoSQL = buildUndoSQL();
        //在这里开启一个游标
        undoPST = conn.prepareStatement(undoSQL);
        TableRecords undoRows = getUndoRows();
        for (Row undoRow : undoRows.getRows()) {
            ArrayList<Field> undoValues = new ArrayList<>();
            List<Field> pkValueList = getOrderedPkList(undoRows, undoRow, getDbType(conn));
            for (Field field : undoRow.getFields()) {
                if (field.getKeyType() != KeyType.PRIMARY_KEY) {
                    undoValues.add(field);
                }
            }
 
            undoPrepare(undoPST, undoValues, pkValueList);
            //做undolog的回滚
            undoPST.executeUpdate();
        }
 
    } catch (Exception ex) {
        if (ex instanceof SQLException) {
            throw (SQLException) ex;
        } else {
            throw new SQLException(ex);
        }
    }
    //处理完并没有关闭游标
}

看到该方法只开启了游标并没有关闭。外面还有一个undo_log的循环当BranchUndoLog的list过多时会超过游标数量。

代码模拟

  public void add() {
        for (int i1 = 0; i1 < 10000; i1++) {
            TestPO testPO = new TestPO();
            testPO.setUrid("" + i1);
            testPO.setName("name" + i1);
            testPO.setAge(i1);
            testMapper.insert(testPO);
        }
    }
 
    @GlobalTransactional
    public void update() {
        ((TestService)AopContext.currentProxy()).doupdate();
        int i = 1/0;
 
    }
 
    @Transactional
    public void doupdate(){
        for (int i1 = 0; i1 < 10000; i1++) {
            TestPO testPO = new TestPO();
            testPO.setUrid("" + i1);
            testPO.setName("name2" + i1);
            testPO.setAge(i1);
            testMapper.updateById(testPO);
        }
    }
 
 
create table TSYS_TEST
(
    URID VARCHAR2(64) not null
        constraint TSYS_TEST_PK
            primary key,
    NAME VARCHAR2(64),
    AGE  NUMBER(38)
)
/

执行完add后再执行update会报上面超过游标数量的问题。

该问题seata新版本已经更改。就是在上面的方法后面把statement关闭了。