[Bug] 开启wisp2，导致okhttp3.internal.http2.Http2Stream获取不到锁 #311

RainAndPearBlossom · 2022-04-07T02:48:00Z

开启wisp2后，使用七牛sdk上传文件，发现接口一直没响应。
查看jstack发现线程一直在等待获取锁：
- Coroutine [0x7f4c14039600] "http-nio-9022-exec-1" #19 active=11 steal=0 steal_fail=0 preempt=2 park=-1/0 containerId=0 cg=0/0 ttr=0 at java.dyn.CoroutineSupport.unsafeSymmetricYieldTo(CoroutineSupport.java:140) at com.alibaba.wisp.engine.WispTask.switchTo(WispTask.java:325) at com.alibaba.wisp.engine.WispCarrier.yieldTo(WispCarrier.java:436) at com.alibaba.wisp.engine.WispCarrier.schedule(WispCarrier.java:274) at com.alibaba.wisp.engine.WispTask.parkInternal(WispTask.java:417) at com.alibaba.wisp.engine.WispTask.park(WispTask.java:480) at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:502) at okhttp3.internal.http2.Http2Stream.waitForIo(Http2Stream.java:660) at okhttp3.internal.http2.Http2Stream$FramingSink.emitFrame(Http2Stream.java:569) - waiting to lock <0x00000000d06578c8> (a okhttp3.internal.http2.Http2Stream) at okhttp3.internal.http2.Http2Stream$FramingSink.write(Http2Stream.java:555) at okio.ForwardingSink.write(ForwardingSink.java:35) at okhttp3.internal.connection.Exchange$RequestBodySink.write(Exchange.java:231) at okio.RealBufferedSink.emitCompleteSegments(RealBufferedSink.java:179) at okio.RealBufferedSink.write(RealBufferedSink.java:92) at okhttp3.RequestBody$2.writeTo(RequestBody.java:151) at okhttp3.MultipartBody.writeOrCountBytes(MultipartBody.java:173) at okhttp3.MultipartBody.writeTo(MultipartBody.java:114) at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:69) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117) at com.qiniu.http.Client$2.intercept(Client.java:86) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142) at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:43) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117) at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:94) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117) at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142) at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:88) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117) at com.qiniu.http.Client$3.intercept(Client.java:103) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142) at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117) at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:229) at okhttp3.RealCall.execute(RealCall.java:81) at com.qiniu.http.Client.send(Client.java:401) at com.qiniu.http.Client.multipartPost(Client.java:332) at com.qiniu.http.Client.multipartPost(Client.java:300) at com.qiniu.storage.FormUploader.uploadFlows(FormUploader.java:63) at com.qiniu.storage.BaseUploader.uploadWithRegionRetry(BaseUploader.java:38) at com.qiniu.storage.BaseUploader.upload(BaseUploader.java:31) at com.qiniu.storage.UploadManager.put(UploadManager.java:175) at com.qiniu.storage.UploadManager.put(UploadManager.java:150) at com.zjh.znwz.controller.TestController.upload(TestController.java:106) at com.zjh.znwz.controller.TestController.test(TestController.java:58) at com.zjh.znwz.controller.TestController$$FastClassBySpringCGLIB$$3f07156c.invoke(<generated>) at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:779) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750) at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89) at com.zjh.znwz.aspect.StatisticsAspect.saveApiLog(StatisticsAspect.java:36) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:634) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:624) at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:72) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:692) at com.zjh.znwz.controller.TestController$$EnhancerBySpringCGLIB$$bc6a311f.test(<generated>) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:197) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:141) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:895) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1064) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:963) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) at javax.servlet.http.HttpServlet.service(HttpServlet.java:655) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) at javax.servlet.http.HttpServlet.service(HttpServlet.java:764) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at com.alibaba.druid.support.http.WebStatFilter.doFilter(WebStatFilter.java:123) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:382) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1726) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) - locked <0x00000000d1d9e5c8> (a org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper) at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:853) at com.alibaba.wisp.engine.WispTask.runOutsideWisp(WispTask.java:295) at com.alibaba.wisp.engine.WispTask.runCommand(WispTask.java:270) at com.alibaba.wisp.engine.WispTask.access$100(WispTask.java:53) at com.alibaba.wisp.engine.WispTask$CacheableCoroutine.run(WispTask.java:241) at java.dyn.CoroutineBase.startInternal(CoroutineBase.java:62)

jvm参数：-XX:+UnlockExperimentalVMOptions -XX:+UseWisp2 -Dio.netty.transport.noNative=true
jdk：Alibaba_Dragonwell_8.8.9_x64
七牛sdk版本：
<dependency> <groupId>com.qiniu</groupId> <artifactId>qiniu-java-sdk</artifactId> <version>7.7.0</version> </dependency>

The text was updated successfully, but these errors were encountered:

yuleil · 2022-04-07T02:52:28Z

您好，这个并不是在等锁，而是在等待okhttp3的IO线程。

具体原因要等我测试下七牛SDK在Wisp2下的运行状况。

yuleil · 2022-04-07T03:43:22Z

您好，经测试以下代码:

public class A {

    public static void main(String[] args) throws Exception {
        Configuration cfg = new Configuration(Region.region0());
        UploadManager uploadManager = new UploadManager(cfg);

        String accessKey = 
        String secretKey = 
        String bucket = 
        Auth auth = Auth.create(accessKey, secretKey);
        String upToken = auth.uploadToken(bucket);

        Response res = Executors.newCachedThreadPool().submit(() ->
                uploadManager.put("test".getBytes(), "test", upToken)).get();
        System.out.println(res.statusCode);
        System.out.println(res.bodyString());
    }
}

在Alibaba Draognwell 8.10.11以及qiniu-java-sdk:7.7.0下开启Wisp2后可以执行完成并获得200的状态码。请您考虑：

提供一个可以复现问题的测试用例
检查是否是网络问题

RainAndPearBlossom · 2022-04-07T03:51:11Z

完整代码：
@RequestMapping("/test")
public Long test() throws Exception {
long a = System.currentTimeMillis();
byte[] bytes = generateImage("ceshi", 1, "/mnt/线上A营.png");
upload(bytes);
return System.currentTimeMillis() - a;
}

private byte[] generateImage(String pressText, Integer phase, String certPath) throws Exception {
    File file = new File(certPath);
    ByteArrayOutputStream outputStream = new ByteArrayOutputStream();
    try {
        BufferedImage image = ImageIO.read(file);
        Graphics2D graphics = image.createGraphics();
        graphics.setColor(Color.BLACK);
        graphics.setRenderingHint(RenderingHints.KEY_TEXT_ANTIALIASING, RenderingHints.VALUE_TEXT_ANTIALIAS_ON);
        graphics.setFont(new Font(Font.SERIF, Font.BOLD, 30));
        // 在指定坐标绘制水印文字
        graphics.drawString(pressText, 200, 200);
        graphics.drawString("一", 200, 200);
        graphics.dispose();
        ImageIO.write(image, "png", outputStream);

        byte[] bytes = outputStream.toByteArray();
        outputStream.close();
        return bytes;
    } catch (Exception e) {
        throw e;
    } finally {
        outputStream.close();
    }

}

public void upload(byte[] bytes) throws Exception {
    Auth auth = Auth.create("xxxx", "xxxxx");
    Configuration cfg = new Configuration(Region.autoRegion());
    UploadManager uploadManager = new UploadManager(cfg);
    String bucket = "xxxx";
    String upToken = auth.uploadToken(bucket, "test/test.png");
    log.info("测试测试测试测试==================上传前====================测试测试测试测试");
    Response response = uploadManager.put(bytes, "test/test.png", upToken);
    log.info("测试测试测试测试==================上传后====================测试测试测试测试");
    DefaultPutRet putRet = JSON.parseObject(response.bodyString(), DefaultPutRet.class);
    System.out.println(JSON.toJSONString(putRet));
    System.out.println("结束");
}

日志截图：

确认网络没有问题，去掉-XX:+UnlockExperimentalVMOptions -XX:+UseWisp2 -Dio.netty.transport.noNative=true这几个参数是可以成功上传的。

RainAndPearBlossom · 2022-04-07T06:44:14Z

您好，经测试以下代码:

public class A {

    public static void main(String[] args) throws Exception {
        Configuration cfg = new Configuration(Region.region0());
        UploadManager uploadManager = new UploadManager(cfg);

        String accessKey = 
        String secretKey = 
        String bucket = 
        Auth auth = Auth.create(accessKey, secretKey);
        String upToken = auth.uploadToken(bucket);

        Response res = Executors.newCachedThreadPool().submit(() ->
                uploadManager.put("test".getBytes(), "test", upToken)).get();
        System.out.println(res.statusCode);
        System.out.println(res.bodyString());
    }
}

在Alibaba Draognwell 8.10.11以及qiniu-java-sdk:7.7.0下开启Wisp2后可以执行完成并获得200的状态码。请您考虑：

提供一个可以复现问题的测试用例
检查是否是网络问题

我刚才试了一下您的测试用例，的确无法复现
麻烦使用我给的这个再次重试，这个我可以复现：

 public static void main(String[] args) throws Exception {
        upload111();
    }

    public static void upload111() throws Exception{
        Configuration cfg = new Configuration(Region.autoRegion());
        UploadManager uploadManager = new UploadManager(cfg);

        String accessKey = "xxxxx";
        String secretKey = "xxxxxxxx";
        String bucket = "xxxxxx";
        Auth auth = Auth.create(accessKey, secretKey);
        String upToken = auth.uploadToken(bucket);
        System.out.println("11111111111");
        Response res = Executors.newCachedThreadPool().submit(() ->
                uploadManager.put(new File("/mnt/test.png"), "test", upToken)).get();
        System.out.println(res.statusCode);
        System.out.println(res.bodyString());
    }

yuleil · 2022-04-07T07:21:20Z

两个测试的主要差异在：

Region.autoRegion()
"test".getBytes()换成了new File("/mnt/test.png")。

我替换成您的测试后依旧无法复现问题

RainAndPearBlossom · 2022-04-07T09:19:17Z

两个测试的主要差异在：

Region.autoRegion()

"test".getBytes()换成了new File("/mnt/test.png")。

我替换成您的测试后依旧无法复现问题

不清楚为什么你那里复现不出来，这是我在centos上的操作过程，大佬帮忙看一下（图中的accessKey、secretKey已被禁用）。
为了解决这个问题，我们生产环境不得不停用了wisp2，所以很希望搞清楚原因

yuleil · 2022-04-08T02:34:19Z

您好，File这个文件需要到达一定的大小才能复现问题。多次尝试后我们能够复现出来了。
感谢您提供的测试，我们很快会解决问题。

yuleil · 2022-04-08T03:42:54Z

分析heapdump，"OkHttp up.qiniup.com" 这个协程已经epoll_ctl注册事件，等待socket返回数据

lsof -Pan -p 576317 -i：

COMMAND    PID  USER   FD   TYPE   DEVICE SIZE/OFF NODE NAME
java    576400 yulei   20u  IPv6 34428854      0t0  TCP 192.168.100.224:46070->115.231.97.60:443 (ESTABLISHED)
java    576400 yulei   22u  IPv6 34428861      0t0  TCP 192.168.100.224:55542->115.238.101.34:443 (ESTABLISHED)

对照netstat -ntp

Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp6       0      0 192.168.100.224:46070   115.231.97.60:443       ESTABLISHED 576400/java
tcp6     469      0 192.168.100.224:55542   115.238.101.34:443      ESTABLISHED 576400/java

本地端口为55542的fd22 的Recv-Q不为空，但是事件循环未能唤醒协程。

Summary: Supports different coroutines waiting on the same socket's read and write events. Solve a wisp bug triggered by okhttp. Test Plan: TestIssue311 Reviewed-by: zhengxiaolinX, D-D-H Issue: dragonwell-project/dragonwell8#311

Summary: Supports different coroutines waiting on the same socket's read and write events. Solve a wisp bug triggered by okhttp. Test Plan: TestIssue311 Reviewers: zhengxiaolinX, D-D-H Issue: dragonwell-project#311 CR: <full URL of AOne code review task>

Summary: Supports different coroutines waiting on the same socket's read and write events. Solve a wisp bug triggered by okhttp. Test Plan: TestIssue311 Reviewed-by: zhengxiaolinX, D-D-H Issue: dragonwell-project#311

Summary: Supports different coroutines waiting on the same socket's read and write events. Solve a wisp bug triggered by okhttp. Test Plan: TestIssue311 Reviewed-by: zhengxiaolinX, D-D-H Issue: #311

yuleil self-assigned this Apr 8, 2022

yuleil added the bug Something isn't working label Apr 8, 2022

yuleil mentioned this issue Jan 31, 2023

[Wisp] Separate IO poller dragonwell-project/dragonwell11#388

Merged

This was referenced Mar 31, 2023

fix issue 311 #531

Closed

[Wisp] Separate IO poller #532

Closed

jia-wei-tang mentioned this issue Mar 31, 2023

[Wisp] Separate IO poller #533

Closed

jia-wei-tang mentioned this issue Mar 31, 2023

[Wisp] Separate IO poller #534

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Bug] 开启wisp2，导致okhttp3.internal.http2.Http2Stream获取不到锁 #311

[Bug] 开启wisp2，导致okhttp3.internal.http2.Http2Stream获取不到锁 #311

RainAndPearBlossom commented Apr 7, 2022

yuleil commented Apr 7, 2022

yuleil commented Apr 7, 2022

RainAndPearBlossom commented Apr 7, 2022

RainAndPearBlossom commented Apr 7, 2022 •

edited

Loading

yuleil commented Apr 7, 2022

RainAndPearBlossom commented Apr 7, 2022

yuleil commented Apr 8, 2022 •

edited

Loading

yuleil commented Apr 8, 2022

[Bug] 开启wisp2，导致okhttp3.internal.http2.Http2Stream获取不到锁 #311

[Bug] 开启wisp2，导致okhttp3.internal.http2.Http2Stream获取不到锁 #311

Comments

RainAndPearBlossom commented Apr 7, 2022

yuleil commented Apr 7, 2022

yuleil commented Apr 7, 2022

RainAndPearBlossom commented Apr 7, 2022

RainAndPearBlossom commented Apr 7, 2022 • edited Loading

yuleil commented Apr 7, 2022

RainAndPearBlossom commented Apr 7, 2022

yuleil commented Apr 8, 2022 • edited Loading

yuleil commented Apr 8, 2022

RainAndPearBlossom commented Apr 7, 2022 •

edited

Loading

yuleil commented Apr 8, 2022 •

edited

Loading