[seata]交易抛异常后,postgresql 回滚事务,出现json decode错误

2024-05-10 310 views
8
Ⅰ. Issue Description

AT模式下交易抛异常后,postgresql 回滚事务,出现json decode错误

Ⅱ. Describe what happened

使用如下脚本创建undo_tbl数据库(修改mysql的undo_tbl适配pg数据库) CREATE TABLE undo_log ( id bigserial NOT NULL, branch_id bigint NOT NULL, xid varchar(100) NOT NULL, context varchar(128) NOT NULL, rollback_info text NOT NULL, log_status integer NOT NULL, log_created TIMESTAMP NOT NULL, log_modified TIMESTAMP NOT NULL, ext varchar(100) DEFAULT NULL, PRIMARY KEY (id) );

一个transaction branch抛异常后,发现undo_tbl的rollback_info字段json解析错误

If there is an exception, please attach the exception trace:

2023-03-24 11:01:33.228  INFO [storage-service,,,] 30628 --- [h_RMROLE_1_7_16] i.seata.rm.datasource.DataSourceManager  : branchRollback failed. branchType:[AT], xid:[10.132.102.141:9092:1018187032987861006], branchId:[1018187032987861009], resourceId:[jdbc:postgresql://10.132.102.187:5432/paas_base_seata_tx1_db?currentSchema=public], applicationData:[null]. reason:[Branch session rollback failed and try again later xid = 10.132.102.141:9092:1018187032987861006 branchId = 1018187032987861009 com.fasterxml.jackson.core.JsonParseException: Unexpected character ('\' (code 92)): expected a valid value (JSON String, Number, Array, Object or token 'null', 'true' or 'false')
 at [Source: (byte[])"\x7b2240636c617373223a22696f2e73656174612e726d2e64617461736f757263652e756e646f2e4272616e6368556e646f4c6f67222c22786964223a2231302e3133322e3130322e3134313a393039323a31303138313837303332393837383631303036222c226272616e63684964223a313031383138373033323938373836313030392c2273716c556e646f4c6f6773223a5b226a6176612e7574696c2e41727261794c697374222c5b7b2240636c617373223a22696f2e73656174612e726d2e64617461736f757263652e756e646f2e53514c556e646f4c6f67222c2273716c54797065223a22555044415445222c227461626c654e61"[truncated 1816 bytes]; line: 1, column: 2]]
2023-03-24 11:01:33.228  INFO [storage-service,,,] 30628 --- [h_RMROLE_1_7_16] io.seata.rm.AbstractRMHandler            : Branch Rollbacked result: PhaseTwo_RollbackFailed_Retryable
2023-03-24 11:01:34.032  INFO [storage-service,,,] 30628 --- [h_RMROLE_1_8_16] i.s.c.r.p.c.RmBranchRollbackProcessor    : rm handle branch rollback process:xid=10.132.102.141:9092:1018187032987861006,branchId=1018187032987861009,branchType=AT,resourceId=jdbc:postgresql://10.132.102.187:5432/paas_base_seata_tx1_db?currentSchema=public,applicationData=null
2023-03-24 11:01:34.032  INFO [storage-service,,,] 30628 --- [h_RMROLE_1_8_16] io.seata.rm.AbstractRMHandler            : Branch Rollbacking: 10.132.102.141:9092:1018187032987861006 1018187032987861009 jdbc:postgresql://10.132.102.187:5432/paas_base_seata_tx1_db?currentSchema=public
2023-03-24 11:01:34.155 ERROR [storage-service,,,] 30628 --- [h_RMROLE_1_8_16] i.s.r.d.u.parser.JacksonUndoLogParser    : json decode exception, Unexpected character ('\' (code 92)): expected a valid value (JSON String, Number, Array, Object or token 'null', 'true' or 'false')
 at [Source: (byte[])"\x7b2240636c617373223a22696f2e73656174612e726d2e64617461736f757263652e756e646f2e4272616e6368556e646f4c6f67222c22786964223a2231302e3133322e3130322e3134313a393039323a31303138313837303332393837383631303036222c226272616e63684964223a313031383138373033323938373836313030392c2273716c556e646f4c6f6773223a5b226a6176612e7574696c2e41727261794c697374222c5b7b2240636c617373223a22696f2e73656174612e726d2e64617461736f757263652e756e646f2e53514c556e646f4c6f67222c2273716c54797065223a22555044415445222c227461626c654e61"[truncated 1816 bytes]; line: 1, column: 2]

com.fasterxml.jackson.core.JsonParseException: Unexpected character ('\' (code 92)): expected a valid value (JSON String, Number, Array, Object or token 'null', 'true' or 'false')
 at [Source: (byte[])"\x7b2240636c617373223a22696f2e73656174612e726d2e64617461736f757263652e756e646f2e4272616e6368556e646f4c6f67222c22786964223a2231302e3133322e3130322e3134313a393039323a31303138313837303332393837383631303036222c226272616e63684964223a313031383138373033323938373836313030392c2273716c556e646f4c6f6773223a5b226a6176612e7574696c2e41727261794c697374222c5b7b2240636c617373223a22696f2e73656174612e726d2e64617461736f757263652e756e646f2e53514c556e646f4c6f67222c2273716c54797065223a22555044415445222c227461626c654e61"[truncated 1816 bytes]; line: 1, column: 2]
    at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:2337) ~[jackson-core-2.12.6.jar:2.12.6]
    at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:710) ~[jackson-core-2.12.6.jar:2.12.6]
    at com.fasterxml.jackson.core.base.ParserMinimalBase._reportUnexpectedChar(ParserMinimalBase.java:635) ~[jackson-core-2.12.6.jar:2.12.6]
    at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._handleUnexpectedValue(UTF8StreamJsonParser.java:2691) ~[jackson-core-2.12.6.jar:2.12.6]
    at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._nextTokenNotInObject(UTF8StreamJsonParser.java:870) ~[jackson-core-2.12.6.jar:2.12.6]
    at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.nextToken(UTF8StreamJsonParser.java:762) ~[jackson-core-2.12.6.jar:2.12.6]
    at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:4684) ~[jackson-databind-2.12.6.1.jar:2.12.6.1]
    at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:4586) ~[jackson-databind-2.12.6.1.jar:2.12.6.1]
    at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:3609) ~[jackson-databind-2.12.6.1.jar:2.12.6.1]
    at io.seata.rm.datasource.undo.parser.JacksonUndoLogParser.decode(JacksonUndoLogParser.java:188) ~[seata-all-1.6.1.jar:1.6.1]
    at io.seata.rm.datasource.undo.AbstractUndoLogManager.undo(AbstractUndoLogManager.java:300) [seata-all-1.6.1.jar:1.6.1]
    at io.seata.rm.datasource.DataSourceManager.branchRollback(DataSourceManager.java:122) [seata-all-1.6.1.jar:1.6.1]
    at io.seata.rm.AbstractRMHandler.doBranchRollback(AbstractRMHandler.java:125) [seata-all-1.6.1.jar:1.6.1]
    at io.seata.rm.AbstractRMHandler$2.execute(AbstractRMHandler.java:67) [seata-all-1.6.1.jar:1.6.1]
    at io.seata.rm.AbstractRMHandler$2.execute(AbstractRMHandler.java:63) [seata-all-1.6.1.jar:1.6.1]
    at io.seata.core.exception.AbstractExceptionHandler.exceptionHandleTemplate(AbstractExceptionHandler.java:131) [seata-all-1.6.1.jar:1.6.1]
    at io.seata.rm.AbstractRMHandler.handle(AbstractRMHandler.java:63) [seata-all-1.6.1.jar:1.6.1]
    at io.seata.rm.DefaultRMHandler.handle(DefaultRMHandler.java:68) [seata-all-1.6.1.jar:1.6.1]
    at io.seata.core.protocol.transaction.BranchRollbackRequest.handle(BranchRollbackRequest.java:35) [seata-all-1.6.1.jar:1.6.1]
    at io.seata.rm.AbstractRMHandler.onRequest(AbstractRMHandler.java:150) [seata-all-1.6.1.jar:1.6.1]
    at io.seata.core.rpc.processor.client.RmBranchRollbackProcessor.handleBranchRollback(RmBranchRollbackProcessor.java:63) [seata-all-1.6.1.jar:1.6.1]
    at io.seata.core.rpc.processor.client.RmBranchRollbackProcessor.process(RmBranchRollbackProcessor.java:58) [seata-all-1.6.1.jar:1.6.1]
    at io.seata.core.rpc.netty.AbstractNettyRemoting.lambda$processMessage$2(AbstractNettyRemoting.java:281) [seata-all-1.6.1.jar:1.6.1]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_191]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_191]
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.76.Final.jar:4.1.76.Final]
    at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_191]

2023-03-24 11:01:34.216  INFO [storage-service,,,] 30628 --- [h_RMROLE_1_8_16] i.seata.rm.datasource.DataSourceManager  : branchRollback failed. branchType:[AT], xid:[10.132.102.141:9092:1018187032987861006], branchId:[1018187032987861009], resourceId:[jdbc:postgresql://10.132.102.187:5432/paas_base_seata_tx1_db?currentSchema=public], applicationData:[null]. reason:[Branch session rollback failed and try again later xid = 10.132.102.141:9092:1018187032987861006 branchId = 1018187032987861009 com.fasterxml.jackson.core.JsonParseException: Unexpected character ('\' (code 92)): expected a valid value (JSON String, Number, Array, Object or token 'null', 'true' or 'false')
 at [Source: (byte[])"\x7b2240636c617373223a22696f2e73656174612e726d2e64617461736f757263652e756e646f2e4272616e6368556e646f4c6f67222c22786964223a2231302e3133322e3130322e3134313a393039323a31303138313837303332393837383631303036222c226272616e63684964223a313031383138373033323938373836313030392c2273716c556e646f4c6f6773223a5b226a6176612e7574696c2e41727261794c697374222c5b7b2240636c617373223a22696f2e73656174612e726d2e64617461736f757263652e756e646f2e53514c556e646f4c6f67222c2273716c54797065223a22555044415445222c227461626c654e61"[truncated 1816 bytes]; line: 1, column: 2]]
2023-03-24 11:01:34.217  INFO [storage-service,,,] 30628 --- [h_RMROLE_1_8_16] io.seata.rm.AbstractRMHandler            : Branch Rollbacked result: PhaseTwo_RollbackFailed_Retryable

Process finished with exit code -1
Ⅲ. Describe what you expected to happen

交易正常回滚,而不是抛异常

Ⅳ. How to reproduce it (as minimally and precisely as possible) Ⅴ. Anything else we need to know? Ⅵ. Environment:
  • JDK version : 1.8
  • Seata version: 1.6.1, 客户端 使用如下版本 io.seata seata-spring-boot-starter 1.6.1
    <dependency>
        <groupId>com.alibaba.cloud</groupId>
        <artifactId>spring-cloud-starter-alibaba-seata</artifactId>
        <version>2.2.9.RELEASE</version>
        <exclusions>
            <exclusion>
                <artifactId>seata-spring-boot-starter</artifactId>
                <groupId>io.seata</groupId>
            </exclusion>
        </exclusions>
    </dependency>
  • OS :
  • Others:

回答

0

@chenhong231 Please list the database field types corresponding to the original SQL.


请列举一下原始SQL涉及到的数据库字段的类型。

0

@chenhong231 Please list the database field types corresponding to the original SQL.

请列举一下原始SQL涉及到的数据库字段的类型。

我是基于spring-cloud-alibaba-2.2.9.RELEASE里面的seata-example的样例修改的。里面的undo_log表的rollback_info字段为mysql的longblob类型。该类型貌似pg不支持,我改成了text字段类型。

根据trace,貌似在PG,rollback_info存储为16进制,导致json反序列化出错。我把数据库换成MYSQL,把下面的mysql原始脚本导入,回滚能正常完成,不会抛异常。

我不确定是下面的那个原因导致的:

  1. seata 对pg数据库兼容性不好,不能正确反序列化rollback_info的信息。
  2. rollback_info这个字段类型 text定义的的不对。

麻烦指导一下,谢谢。

====================================================== 原始MYSQL脚本。修改后的pg脚本见最上面,我已经贴出来了。

CREATE TABLE undo_log ( id bigint(20) NOT NULL AUTO_INCREMENT, branch_id bigint(20) NOT NULL, xid varchar(100) NOT NULL, context varchar(128) NOT NULL, rollback_info longblob NOT NULL, log_status int(11) NOT NULL, log_created datetime NOT NULL, log_modified datetime NOT NULL, ext varchar(100) DEFAULT NULL, PRIMARY KEY (id), UNIQUE KEY ux_undo_log (xid,branch_id) ) ENGINE=InnoDB AUTO_INCREMENT=1 DEFAULT CHARSET=utf8;