search

envoyproxy / envoy

Cloud-native high-performance edge/middle/service proxy
https://www.envoyproxy.io
Apache License 2.0
24.85k stars 4.77k forks source link

Envoy Dubbo Proxy Bad response: hessian type is not int 83 #9307

Closed swift1911 closed 4 years ago

swift1911 commented 4 years ago

Title: Envoy Dubbo Proxy Bad response: hessian type is not int 83

Version: Envoy 1.12.1 Dubbo 2.7.3(Both client and server)

Description: I have tested use Envoy as a front proxy for Dubbo Service, but i meet a problem.It seems related to the decoder.

Config:

admin:
  access_log_path: /tmp/admin_access.log
  address:
    socket_address: { address: 0.0.0.0, port_value: 9901 }

static_resources:
  listeners:
  - name: dubbo_listener
    address:
      socket_address: { address: 0.0.0.0, port_value: 12345 }
    filter_chains:
      filters:
      - name: envoy.filters.network.dubbo_proxy
        config:
          stat_prefix: ingress_dubbo
          route_config:
          - name: local_route
            interface: com.fangdd.infrastructure.gateway.api.WebSocketService
            routes:
            - match:
                method:
                  name:
                    exact: PushNotification
              route:
                cluster: test_dubbo_cluster
          dubbo_filters:
          - name: envoy.filters.dubbo.router

  clusters:
  - name: test_dubbo_cluster
    connect_timeout: 5s
    type: STRICT_DNS
    lb_policy: MAGLEV
    hosts:
    - socket_address:
        address: 10.50.240.7
        port_value: 20880

Logs:

[2019-12-11 03:38:03.450][15][debug][conn_handler] [source/server/connection_handler_impl.cc:335] [C0] new connection
[2019-12-11 03:38:03.620][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/decoder.cc:95] dubbo decoder: 349 bytes available
[2019-12-11 03:38:03.620][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/decoder.cc:105] dubbo decoder: protocol dubbo, state OnDecodeStreamHeader, 349 bytes available
[2019-12-11 03:38:03.620][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/conn_manager.cc:82] dubbo: create the new decoder event handler
[2019-12-11 03:38:03.622][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/router/route_matcher.cc:37] dubbo route matcher: weighted_clusters_size 0
[2019-12-11 03:38:03.622][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/router/router_impl.cc:56] [C0][S4062955328210981298] dubbo router: cluster 'test_dubbo_cluster' match for interface 'com.fangdd.infrastructure.gateway.api.WebSocketService'
[2019-12-11 03:38:03.622][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/router/router_impl.cc:78] [C0][S4062955328210981298] dubbo router: decoding request
[2019-12-11 03:38:03.622][15][debug][pool] [source/common/tcp/conn_pool.cc:83] creating a new connection
[2019-12-11 03:38:03.622][15][debug][pool] [source/common/tcp/conn_pool.cc:364] [C1] connecting
[2019-12-11 03:38:03.622][15][debug][connection] [source/common/network/connection_impl.cc:711] [C1] connecting to 10.50.240.7:20880
[2019-12-11 03:38:03.622][15][debug][connection] [source/common/network/connection_impl.cc:720] [C1] connection in progress
[2019-12-11 03:38:03.622][15][debug][pool] [source/common/tcp/conn_pool.cc:109] queueing request due to no available connections
[2019-12-11 03:38:03.622][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/active_message.cc:259] dubbo request: stop calling decoder filter, id is 0
[2019-12-11 03:38:03.622][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/decoder.cc:57] dubbo decoder: ends the deserialization of the message
[2019-12-11 03:38:03.622][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/decoder.cc:121] dubbo decoder: data length 0
[2019-12-11 03:38:03.660][15][debug][connection] [source/common/network/connection_impl.cc:559] [C1] connected
[2019-12-11 03:38:03.660][15][debug][pool] [source/common/tcp/conn_pool.cc:285] [C1] assigning connection
[2019-12-11 03:38:03.660][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/router/router_impl.cc:232] dubbo upstream request: tcp connection has ready
[2019-12-11 03:38:03.660][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/router/router_impl.cc:264] dubbo upstream request: selected upstream 10.50.240.7:20880
[2019-12-11 03:38:03.660][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/router/router_impl.cc:248] dubbo upstream request: start sending data to the server 10.50.240.7:20880
[2019-12-11 03:38:03.660][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/active_message.cc:139] dubbo response: start upstream
[2019-12-11 03:38:03.660][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/conn_manager.cc:171] [C0] dubbo filter continued
[2019-12-11 03:38:03.660][15][warning][dubbo] [source/extensions/filters/network/dubbo_proxy/conn_manager.cc:110] dubbo: it's empty data
[2019-12-11 03:38:03.729][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/active_message.cc:366] dubbo response: start upstream
[2019-12-11 03:38:03.729][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/active_message.cc:23] dubbo response: the received reply data length is 1460
[2019-12-11 03:38:03.729][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/decoder.cc:95] dubbo decoder: 1460 bytes available
[2019-12-11 03:38:03.729][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/decoder.cc:105] dubbo decoder: protocol dubbo, state OnDecodeStreamHeader, 1460 bytes available
[2019-12-11 03:38:03.729][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/decoder.cc:48] dubbo decoder: need more data for dubbo.hessian2 serialization, current size 1444
[2019-12-11 03:38:03.729][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/decoder.cc:110] dubbo decoder: wait for data
[2019-12-11 03:38:03.731][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/active_message.cc:23] dubbo response: the received reply data length is 2241
[2019-12-11 03:38:03.731][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/decoder.cc:95] dubbo decoder: 2241 bytes available
[2019-12-11 03:38:03.731][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/decoder.cc:105] dubbo decoder: protocol dubbo, state OnDecodeStreamData, 2241 bytes available
[2019-12-11 03:38:03.734][15][error][dubbo] [source/extensions/filters/network/dubbo_proxy/active_message.cc:402] [C0] dubbo response: exception (hessian type is not int 83)
[2019-12-11 03:38:03.734][15][error][dubbo] [source/extensions/filters/network/dubbo_proxy/active_message.cc:474] Bad response: hessian type is not int 83
[2019-12-11 03:38:03.734][15][debug][dubbo] [bazel-out/k8-opt/bin/source/extensions/filters/network/dubbo_proxy/_virtual_includes/app_exception_lib/extensions/filters/network/dubbo_proxy/app_exception.h:30] Exception information: hessian type is not int 83
[2019-12-11 03:38:03.734][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/router/router_impl.cc:104] [C0][S4062955328210981298] dubbo router: upstream reset
[2019-12-11 03:38:03.734][15][debug][connection] [source/common/network/connection_impl.cc:104] [C1] closing data_to_write=0 type=1
[2019-12-11 03:38:03.734][15][debug][connection] [source/common/network/connection_impl.cc:193] [C1] closing socket: 1
[2019-12-11 03:38:03.734][15][debug][pool] [source/common/tcp/conn_pool.cc:124] [C1] client disconnected
[2019-12-11 03:38:03.734][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/router/router_impl.cc:131] dubbo upstream request: the stream reset
[2019-12-11 03:38:03.734][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/router/router_impl.cc:197] dubbo upstream request: reset connection data
[2019-12-11 03:38:03.734][15][debug][dubbo] [source/extensions/filters/network/dubbo_proxy/active_message.cc:201] destroy decoder filter
[2019-12-11 03:38:03.734][15][debug][pool] [source/common/tcp/conn_pool.cc:238] [C1] connection destroyed
[2019-12-11 03:38:04.921][9][debug][upstream] [source/common/upstream/upstream_impl.cc:250] transport socket match, socket default selected for host with address 10.50.240.7:20880

Dubbo Call Stack:

org.apache.dubbo.rpc.RpcException: Invoke remote method timeout. method: PushNotification, provider: dubbo://127.0.0.1:12345/com.fangdd.infrastructure.gateway.api.WebSocketService?application=push.gateway.ip.fdd&interface=com.fangdd.infrastructure.gateway.api.WebSocketService&lazy=false&pid=21077&qos.enable=false&register.ip=10.12.18.68&remote.application=&revision=1.0.3&side=consumer&sticky=false&timeout=5000, cause: org.apache.dubbo.remoting.TimeoutException: Waiting server-side response timeout by scan timer. start time: 2019-12-11 11:58:59.804, end time: 2019-12-11 11:59:04.821, client elapsed: 58 ms, server elapsed: 4958 ms, timeout: 5000 ms, request: Request [id=0, version=2.0.2, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=PushNotification, parameterTypes=[class java.lang.String, class java.lang.String, class java.lang.String, class java.lang.String], arguments=[a.esf.fdd, 123, ff, null], attachments={path=com.fangdd.infrastructure.gateway.api.WebSocketService, interface=com.fangdd.infrastructure.gateway.api.WebSocketService, version=0.0.0, timeout=5000}]], channel: /10.12.18.68:50322 -> /10.12.18.68:12345
    at org.apache.dubbo.rpc.protocol.AsyncToSyncInvoker.invoke(AsyncToSyncInvoker.java:63)
    at org.apache.dubbo.rpc.listener.ListenerInvokerWrapper.invoke(ListenerInvokerWrapper.java:78)
    at org.apache.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:92)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:82)
    at com.alibaba.dubbo.rpc.Invoker$CompatibleInvoker.invoke(Invoker.java:55)
    at com.fangdd.starter.cat.dubbo.filter.ConsumerCatFilter.invoke(ConsumerCatFilter.java:37)
    at com.alibaba.dubbo.rpc.Filter.invoke(Filter.java:29)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:82)
    at org.apache.dubbo.rpc.protocol.dubbo.filter.FutureFilter.invoke(FutureFilter.java:54)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:82)
    at org.apache.dubbo.rpc.filter.ConsumerContextFilter.invoke(ConsumerContextFilter.java:58)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:82)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$CallbackRegistrationInvoker.invoke(ProtocolFilterWrapper.java:157)
    at org.apache.dubbo.rpc.proxy.InvokerInvocationHandler.invoke(InvokerInvocationHandler.java:55)
    at org.apache.dubbo.common.bytecode.proxy0.PushNotification(proxy0.java)
    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.apache.dubbo.config.spring.beans.factory.annotation.ReferenceAnnotationBeanPostProcessor$ReferenceBeanInvocationHandler.invoke(ReferenceAnnotationBeanPostProcessor.java:260)
    at com.sun.proxy.$Proxy91.PushNotification(Unknown Source)
    at DubboTest.testDubboMesh(DubboTest.java:18)
    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.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
    at org.springframework.test.context.junit4.statements.RunBeforeTestExecutionCallbacks.evaluate(RunBeforeTestExecutionCallbacks.java:74)
    at org.springframework.test.context.junit4.statements.RunAfterTestExecutionCallbacks.evaluate(RunAfterTestExecutionCallbacks.java:84)
    at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75)
    at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86)
    at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
    at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:251)
    at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:97)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
    at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61)
    at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
    at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:190)
    at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
    at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:68)
    at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:33)
    at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:230)
    at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:58)
Caused by: java.util.concurrent.ExecutionException: org.apache.dubbo.remoting.TimeoutException: Waiting server-side response timeout by scan timer. start time: 2019-12-11 11:58:59.804, end time: 2019-12-11 11:59:04.821, client elapsed: 58 ms, server elapsed: 4958 ms, timeout: 5000 ms, request: Request [id=0, version=2.0.2, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=PushNotification, parameterTypes=[class java.lang.String, class java.lang.String, class java.lang.String, class java.lang.String], arguments=[a.esf.fdd, 123, ff, null], attachments={path=com.fangdd.infrastructure.gateway.api.WebSocketService, interface=com.fangdd.infrastructure.gateway.api.WebSocketService, version=0.0.0, timeout=5000}]], channel: /10.12.18.68:50322 -> /10.12.18.68:12345
    at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357)
    at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
    at org.apache.dubbo.rpc.protocol.AsyncToSyncInvoker.invoke(AsyncToSyncInvoker.java:56)
    ... 51 more
Caused by: org.apache.dubbo.remoting.TimeoutException: Waiting server-side response timeout by scan timer. start time: 2019-12-11 11:58:59.804, end time: 2019-12-11 11:59:04.821, client elapsed: 58 ms, server elapsed: 4958 ms, timeout: 5000 ms, request: Request [id=0, version=2.0.2, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=PushNotification, parameterTypes=[class java.lang.String, class java.lang.String, class java.lang.String, class java.lang.String], arguments=[a.esf.fdd, 123, ff, null], attachments={path=com.fangdd.infrastructure.gateway.api.WebSocketService, interface=com.fangdd.infrastructure.gateway.api.WebSocketService, version=0.0.0, timeout=5000}]], channel: /10.12.18.68:50322 -> /10.12.18.68:12345
    at org.apache.dubbo.remoting.exchange.support.DefaultFuture.doReceived(DefaultFuture.java:189)
    at org.apache.dubbo.remoting.exchange.support.DefaultFuture.received(DefaultFuture.java:153)
    at org.apache.dubbo.remoting.exchange.support.DefaultFuture$TimeoutCheckTask.run(DefaultFuture.java:252)
    at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:648)
    at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:727)
    at org.apache.dubbo.common.timer.HashedWheelTimer$Worker.run(HashedWheelTimer.java:449)
    at java.lang.Thread.run(Thread.java:748)

org.apache.dubbo.rpc.RpcException: Invoke remote method timeout. method: PushNotification, provider: dubbo://127.0.0.1:12345/com.fangdd.infrastructure.gateway.api.WebSocketService?application=push.gateway.ip.fdd&interface=com.fangdd.infrastructure.gateway.api.WebSocketService&lazy=false&pid=21077&qos.enable=false&register.ip=10.12.18.68&remote.application=&revision=1.0.3&side=consumer&sticky=false&timeout=5000, cause: org.apache.dubbo.remoting.TimeoutException: Waiting server-side response timeout by scan timer. start time: 2019-12-11 11:58:59.804, end time: 2019-12-11 11:59:04.821, client elapsed: 58 ms, server elapsed: 4958 ms, timeout: 5000 ms, request: Request [id=0, version=2.0.2, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=PushNotification, parameterTypes=[class java.lang.String, class java.lang.String, class java.lang.String, class java.lang.String], arguments=[a.esf.fdd, 123, ff, null], attachments={path=com.fangdd.infrastructure.gateway.api.WebSocketService, interface=com.fangdd.infrastructure.gateway.api.WebSocketService, version=0.0.0, timeout=5000}]], channel: /10.12.18.68:50322 -> /10.12.18.68:12345

    at org.apache.dubbo.rpc.protocol.AsyncToSyncInvoker.invoke(AsyncToSyncInvoker.java:63)
    at org.apache.dubbo.rpc.listener.ListenerInvokerWrapper.invoke(ListenerInvokerWrapper.java:78)
    at org.apache.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:92)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:82)
    at com.alibaba.dubbo.rpc.Invoker$CompatibleInvoker.invoke(Invoker.java:55)
    at com.fangdd.starter.cat.dubbo.filter.ConsumerCatFilter.invoke(ConsumerCatFilter.java:37)
    at com.alibaba.dubbo.rpc.Filter.invoke(Filter.java:29)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:82)
    at org.apache.dubbo.rpc.protocol.dubbo.filter.FutureFilter.invoke(FutureFilter.java:54)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:82)
    at org.apache.dubbo.rpc.filter.ConsumerContextFilter.invoke(ConsumerContextFilter.java:58)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:82)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$CallbackRegistrationInvoker.invoke(ProtocolFilterWrapper.java:157)
    at org.apache.dubbo.rpc.proxy.InvokerInvocationHandler.invoke(InvokerInvocationHandler.java:55)
    at org.apache.dubbo.common.bytecode.proxy0.PushNotification(proxy0.java)
    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.apache.dubbo.config.spring.beans.factory.annotation.ReferenceAnnotationBeanPostProcessor$ReferenceBeanInvocationHandler.invoke(ReferenceAnnotationBeanPostProcessor.java:260)
    at com.sun.proxy.$Proxy91.PushNotification(Unknown Source)
    at DubboTest.testDubboMesh(DubboTest.java:18)
    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.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
    at org.springframework.test.context.junit4.statements.RunBeforeTestExecutionCallbacks.evaluate(RunBeforeTestExecutionCallbacks.java:74)
    at org.springframework.test.context.junit4.statements.RunAfterTestExecutionCallbacks.evaluate(RunAfterTestExecutionCallbacks.java:84)
    at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75)
    at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86)
    at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
    at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:251)
    at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:97)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
    at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61)
    at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
    at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:190)
    at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
    at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:68)
    at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:33)
    at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:230)
    at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:58)
Caused by: java.util.concurrent.ExecutionException: org.apache.dubbo.remoting.TimeoutException: Waiting server-side response timeout by scan timer. start time: 2019-12-11 11:58:59.804, end time: 2019-12-11 11:59:04.821, client elapsed: 58 ms, server elapsed: 4958 ms, timeout: 5000 ms, request: Request [id=0, version=2.0.2, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=PushNotification, parameterTypes=[class java.lang.String, class java.lang.String, class java.lang.String, class java.lang.String], arguments=[a.esf.fdd, 123, ff, null], attachments={path=com.fangdd.infrastructure.gateway.api.WebSocketService, interface=com.fangdd.infrastructure.gateway.api.WebSocketService, version=0.0.0, timeout=5000}]], channel: /10.12.18.68:50322 -> /10.12.18.68:12345
    at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357)
    at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
    at org.apache.dubbo.rpc.protocol.AsyncToSyncInvoker.invoke(AsyncToSyncInvoker.java:56)
    ... 51 more
Caused by: org.apache.dubbo.remoting.TimeoutException: Waiting server-side response timeout by scan timer. start time: 2019-12-11 11:58:59.804, end time: 2019-12-11 11:59:04.821, client elapsed: 58 ms, server elapsed: 4958 ms, timeout: 5000 ms, request: Request [id=0, version=2.0.2, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=PushNotification, parameterTypes=[class java.lang.String, class java.lang.String, class java.lang.String, class java.lang.String], arguments=[a.esf.fdd, 123, ff, null], attachments={path=com.fangdd.infrastructure.gateway.api.WebSocketService, interface=com.fangdd.infrastructure.gateway.api.WebSocketService, version=0.0.0, timeout=5000}]], channel: /10.12.18.68:50322 -> /10.12.18.68:12345
    at org.apache.dubbo.remoting.exchange.support.DefaultFuture.doReceived(DefaultFuture.java:189)
    at org.apache.dubbo.remoting.exchange.support.DefaultFuture.received(DefaultFuture.java:153)
    at org.apache.dubbo.remoting.exchange.support.DefaultFuture$TimeoutCheckTask.run(DefaultFuture.java:252)
    at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:648)
    at org.apache.dubbo.common.timer.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:727)
    at org.apache.dubbo.common.timer.HashedWheelTimer$Worker.run(HashedWheelTimer.java:449)
    at java.lang.Thread.run(Thread.java:748)
zyfjeff commented 4 years ago

@swift1911 Is the serialization protocol used on the provider side hessian2?

swift1911 commented 4 years ago

@zyfjeff Yes , it should be hessian2. I have used the Dubbo default configuration. From Dubbo document, the default serialization protocol is hessian2. https://dubbo.apache.org/en-us/docs/user/references/protocol/dubbo.html

zyfjeff commented 4 years ago

@swift1911 Can you post the results of the packet capture?

swift1911 commented 4 years ago

@zyfjeff I have uploaded my tcpdump result. dump.pcap.zip

It looks like an issue in dubbo-spring-boot-project.The version parameter of Reference is 0.0.0 https://github.com/apache/dubbo-spring-boot-project/issues/613

By the way, is it possible for Envoy to return or report the original error message of the Dubbo interface? The message "hessian type is not int 83" is not good for troubleshooting

stale[bot] commented 4 years ago

This issue has been automatically marked as stale because it has not had activity in the last 30 days. It will be closed in the next 7 days unless it is tagged "help wanted" or other activity occurs. Thank you for your contributions.

stale[bot] commented 4 years ago

This issue has been automatically closed because it has not had activity in the last 37 days. If this issue is still valid, please ping a maintainer and ask them to label it as "help wanted". Thank you for your contributions.