search

apache / apisix-java-plugin-runner

APISIX Plugin Runner in Java
https://apisix.apache.org/
Apache License 2.0
128 stars 95 forks source link

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

Open beginnerWJC opened 1 year ago

beginnerWJC commented 1 year ago

Issue description

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

Environment

Minimal test code / Steps to reproduce the issue

1.通过apisix-dashboard创建路由使用ext-plugin-post-resp插件 image 2.写一个简单的java测试插件，并且设置requiredRespBody()和requiredBody()都为true image 3.多次调用会发现很大概率会报错503 image 4.查看日志发现是getUpstreamHeaders()方法报错java.lang.IndexOutOfBoundsException: null image

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

What's the expected result?

Yindazz commented 1 year ago

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 commented 1 year ago

I've got the same problem.

Cheol-Soon-Choi commented 1 year ago

@tzssangglass can u check this issue progress?

beginnerWJC commented 1 year ago

when can solve this problem