bug: 在PluginFilter类中通过requiredRespBody()方法设置为true后，在插件中调用PostRequest..getUpstreamHeaders()方法会偶现(概率很高)报错java.lang.IndexOutOfBoundsException: null

[beginnerWJC]

Issue description

在PluginFilter类中通过requiredRespBody()方法设置为true后，在插件中调用PostRequest..getUpstreamHeaders()方法会偶现(概率很高)报错java.lang.IndexOutOfBoundsException: null

Environment

• apisix-java-plugin-runner 0.4.0
• apisix 3.2.0
• apisix-dashboard 3.0.0

Minimal test code / Steps to reproduce the issue

1.通过apisix-dashboard创建路由使用ext-plugin-post-resp插件

2.写一个简单的java测试插件，并且设置requiredRespBody()和requiredBody()都为true

3.多次调用会发现很大概率会报错503

4.查看日志发现是getUpstreamHeaders()方法报错java.lang.IndexOutOfBoundsException: null

What's the actual result? (including assertion message & call stack if applicable)

What's the expected result?

[EdaZhang]

I met the same problem . PostRequest.getConfig() PostRequest.getBody() works normally. But PostRequest.getUpstreamHeaders() Json.toString(PostRequest) occurred the same error.

Environment

apisix-java-plugin-runner 0.4.0
apisix version (cmd: apisix version): 3.2.0
OS (cmd: uname -a): docker
etcd version: 3.4.15
apisix-dashboard version: 3.0.0-alpine

Steps to reproduce

I remove some business code , the error was occured while request.getUpstreamHeaders()

@Slf4j
@Component
@RequiredArgsConstructor
public class JwtAuthFilter implements PluginFilter {

    @Override
    public void filter(HttpRequest request, HttpResponse response, PluginFilterChain chain) {
        String config = request.getConfig(this);
        JwtAuthConfig config = JsonUtil.getInstance().parseObject(config, JwtAuthConfig.class);
		
        chain.filter(request, response);

    }

    @Override
    public void postFilter(PostRequest request, PostResponse response, PluginFilterChain chain) {

        request.getUpstreamStatusCode();
        request.getUpstreamHeaders();

	String requestBody = request.getBody();
        String config = request.getConfig(this);
		
        JwtAuthConfig config = JsonUtil.getInstance().parseObject(config, JwtAuthConfig.class);
        log.error("###########jwt-auth.postFilter.requestConfig{}", JsonUtil.getInstance().toString(config));

        chain.postFilter(request, response);

    }

    @Override
    public Boolean requiredBody() {
        return true;
    }

    @Override
    public Boolean requiredRespBody() {
        return true;
    }


    @Override
    public String name() {
        return "jwt-gm-auth";
    }

}

{
  "uri": "/query",
  "name": "query",
  "methods": [
    "GET",
    "POST"
  ],
  "plugins": {
    "ext-plugin-post-resp": {
      "conf": [
        {
          "name": "jwt-auth",
          "value": "{}"
        }
      ]
    },
    "proxy-rewrite": {
      "uri": "/mock"
    }
  },
  "upstream": {
    "nodes": [
      {
        "host": "localhost",
        "port": 9080,
        "weight": 1
      }
    ],
    "type": "roundrobin",
    "hash_on": "vars",
    "scheme": "http",
    "pass_host": "pass"
  },
  "status": 1
}

error log

"log":"2023/04/26 09:32:27 [warn] 54#54: *81 [lua] init.lua:953: 2023-04-26T09:32:27.821Z ERROR 89 --- [ntLoopGroup-2-2] o.a.a.p.runner.handler.RpcCallHandler    : handle request error: \n","stream":"stderr","time":"2023-04-26T09:32:27.823625263Z"}
{"log":"\n","stream":"stderr","time":"2023-04-26T09:32:27.823678284Z"}
{"log":"java.lang.IndexOutOfBoundsException: null\n","stream":"stderr","time":"2023-04-26T09:32:27.823685967Z"}
{"log":"\u0009at java.base/java.nio.Buffer.checkIndex(Buffer.java:749) ~[na:na]\n","stream":"stderr","time":"2023-04-26T09:32:27.823692374Z"}
{"log":"\u0009at java.base/java.nio.DirectByteBuffer.getInt(DirectByteBuffer.java:692) ~[na:na]\n","stream":"stderr","time":"2023-04-26T09:32:27.823698643Z"}
{"log":"\u0009at com.google.flatbuffers.Table.__vector_len(Table.java:125) ~[flatbuffers-java-2.0.0.jar!/:na]\n","stream":"stderr","time":"2023-04-26T09:32:27.823704476Z"}
{"log":"\u0009at io.github.api7.A6.HTTPRespCall.Req.headersLength(Req.java:22) ~[A6-0.6.0-RELEASE.jar!/:na]\n","stream":"stderr","time":"2023-04-26T09:32:27.823710362Z"}
{"log":"\u0009at org.apache.apisix.plugin.runner.PostRequest.getUpstreamHeaders(PostRequest.java:81) ~[apisix-runner-plugin-sdk-0.4.0.jar!/:0.4.0]\n","stream":"stderr","time":"2023-04-26T09:32:27.82371614Z"}
{"log":"\u0009at com.jlpay.apisix.plugins.auth.JwtGmAuthFilter.postFilter(JwtGmAuthFilter.java:80) ~[classes!/:1.0.0]\n","stream":"stderr","time":"2023-04-26T09:32:27.823722186Z"}
{"log":"\u0009at org.apache.apisix.plugin.runner.filter.PluginFilterChain.postFilter(PluginFilterChain.java:64) ~[apisix-runner-plugin-sdk-0.4.0.jar!/:0.4.0]\n","stream":"stderr","time":"2023-04-26T09:32:27.823728131Z"}
{"log":"\u0009at org.apache.apisix.plugin.runner.handler.RpcCallHandler.doPostFilter(RpcCallHandler.java:211) ~[apisix-runner-core-0.4.0.jar!/:0.4.0]\n","stream":"stderr","time":"2023-04-26T09:32:27.823733953Z"}
{"log":"\u0009at org.apache.apisix.plugin.runner.handler.RpcCallHandler.handleExtraInfo(RpcCallHandler.java:243) ~[apisix-runner-core-0.4.0.jar!/:0.4.0]\n","stream":"stderr","time":"2023-04-26T09:32:27.823739735Z"}
{"log":"\u0009at org.apache.apisix.plugin.runner.handler.RpcCallHandler.channelRead0(RpcCallHandler.java:92) ~[apisix-runner-core-0.4.0.jar!/:0.4.0]\n","stream":"stderr","time":"2023-04-26T09:32:27.823745537Z"}
{"log":"\u0009at org.apache.apisix.plugin.runner.handler.RpcCallHandler.channelRead0(RpcCallHandler.java:54) ~[apisix-runner-core-0.4.0.jar!/:0.4.0]\n","stream":"stderr","time":"2023-04-26T09:32:27.823751339Z"}
{"log":"\u0009at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823756722Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823762307Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823768287Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823787786Z"}
{"log":"\u0009at org.apache.apisix.plugin.runner.handler.PrepareConfHandler.channelRead0(PrepareConfHandler.java:57) ~[apisix-runner-core-0.4.0.jar!/:0.4.0]\n","stream":"stderr","time":"2023-04-26T09:32:27.823793888Z"}
{"log":"\u0009at org.apache.apisix.plugin.runner.handler.PrepareConfHandler.channelRead0(PrepareConfHandler.java:45) ~[apisix-runner-core-0.4.0.jar!/:0.4.0]\n","stream":"stderr","time":"2023-04-26T09:32:27.823799462Z"}
{"log":"\u0009at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823804767Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823810341Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823815729Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823821242Z"}
{"log":"\u0009at org.apache.apisix.plugin.runner.handler.PayloadDecoder.channelRead0(PayloadDecoder.java:45) ~[apisix-runner-core-0.4.0.jar!/:0.4.0]\n","stream":"stderr","time":"2023-04-26T09:32:27.823826553Z"}
{"log":"\u0009at org.apache.apisix.plugin.runner.handler.PayloadDecoder.channelRead0(PayloadDecoder.java:38) ~[apisix-runner-core-0.4.0.jar!/:0.4.0]\n","stream":"stderr","time":"2023-04-26T09:32:27.82383218Z"}
{"log":"\u0009at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823837561Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823842931Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823848188Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractCh, context: ngx.timer\n","stream":"stderr","time":"2023-04-26T09:32:27.823853531Z"}
{"log":"2023/04/26 09:32:27 [warn] 54#54: *81 [lua] init.lua:953: annelHandlerContext.java:412) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823858826Z"}
{"log":"\u0009at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346) ~[netty-codec-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823867077Z"}
{"log":"\u0009at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessage, context: ngx.timer\n","stream":"stderr","time":"2023-04-26T09:32:27.823872716Z"}
{"log":"2023/04/26 09:32:27 [warn] 54#54: *81 [lua] init.lua:953: Decoder.java:318) ~[netty-codec-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823877867Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823883092Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823888788Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823899555Z"}
{"log":"\u0009at io.netty.handler.logging.LoggingHandler.channelRead(LoggingHandler.java:280) ~[netty-handler-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823905183Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823910685Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823916185Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823921705Z"}
{"log":"\u0009at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823927131Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823932324Z"}
{"log":"\u0009at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823937705Z"}
{"log":"\u0009at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) ~[netty-transport-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823942922Z"}
{"log":"\u0009at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:800) ~[netty-transport-classes-epoll-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823948907Z"}
{"log":"\u0009at io.netty.channel.epoll.EpollDomainSocketChannel$EpollDomainUnsafe.epollInReady(EpollDomainSocketChannel.java:138) ~[netty-transport-classes-epoll-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823963459Z"}
{"log":"\u0009at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:499) ~[netty-transport-classes-epoll-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.82396928Z"}
{"log":"\u0009at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:397) ~[netty-transport-classes-epoll-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.82397483Z"}
{"log":"\u0009at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) ~[netty-common-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823980242Z"}
{"log":"\u0009at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823985538Z"}
{"log":"\u0009at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.87.Final.jar!/:4.1.87.Final]\n","stream":"stderr","time":"2023-04-26T09:32:27.823990967Z"}
{"log":"\u0009at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]\n","stream":"stderr","time":"2023-04-26T09:32:27.823996301Z"}
{"log":"\n","stream":"stderr","time":"2023-04-26T09:32:27.824001328Z"}
{"log":", context: ngx.timer\n","stream":"stderr","time":"2023-04-26T09:32:27.824006101Z"}
{"log":"2023/04/26 09:32:27 [error] 51#51: *828 [lua] init.lua:881: communicate(): failed to receive RPC_HTTP_REQ_CALL: service unavailable, client: 183.239.144.66, server: _, request: \"GET /query HTTP/1.1\", host: \"43.142.95.244:9080\"\n","stream":"stderr","time":"2023-04-26T09:32:27.825772344Z"}
{"log":"127.0.0.1 - - [26/Apr/2023:09:32:27 +0000] 43.142.95.244:9080 \"GET /mock HTTP/1.1\" 200 38 0.000 \"-\" \"PostmanRuntime/7.32.2\" - - - \"http://43.142.95.244:9080\"\n","stream":"stdout","time":"2023-04-26T09:32:30.8163443Z"}
{"log":"183.239.144.66 - - [26/Apr/2023:09:32:27 +0000] 43.142.95.244:9080 \"GET /query HTTP/1.1\" 503 38 0.009 \"-\" \"PostmanRuntime/7.32.2\" - - - \"http://43.142.95.244:9080/mock\"\n","stream":"stdout","time":"2023-04-26T09:32:30.816391598Z"}

Actual result

Error orccured when i try to get the headers of postReqeust, the plugin was skipped for the error.

Expected result

The headers of the postRequest could be gotten normally, no error should be occured.

[joyyir]

I've got the same problem.

[Cheol-Soon-Choi]

@tzssangglass can u check this issue progress?

[beginnerWJC]

when can solve this problem