You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@dubbo.apache.org by al...@apache.org on 2022/07/19 11:54:28 UTC
[dubbo-website] branch 0719_add_doc4 created (now 7e9d257759)
This is an automated email from the ASF dual-hosted git repository.
albumenj pushed a change to branch 0719_add_doc4
in repository https://gitbox.apache.org/repos/asf/dubbo-website.git
at 7e9d257759 Merge branch 'master' into 0719_add_doc4
This branch includes the following new commits:
new 12422ce511 opt docs
new 8502a207ba opt docs
new 7e9d257759 Merge branch 'master' into 0719_add_doc4
The 3 revisions listed above as "new" are entirely new to this
repository and will be described in separate emails. The revisions
listed as "add" were already present in the repository and have only
been added to this reference.
[dubbo-website] 03/03: Merge branch 'master' into 0719_add_doc4
Posted by al...@apache.org.
This is an automated email from the ASF dual-hosted git repository.
albumenj pushed a commit to branch 0719_add_doc4
in repository https://gitbox.apache.org/repos/asf/dubbo-website.git
commit 7e9d257759d4b4ad84cf25bab482e87a9061a46b
Merge: 8502a207ba f397b2a1d8
Author: Albumen Kevin <jh...@gmail.com>
AuthorDate: Tue Jul 19 19:54:13 2022 +0800
Merge branch 'master' into 0719_add_doc4
# Conflicts:
# content/zh/docs3-building/java-sdk/advanced-features-and-usage/observability/profiler.md
# content/zh/docs3-building/java-sdk/advanced-features-and-usage/observability/router-snapshot.md
# content/zh/docs3-building/java-sdk/reference-manual/qos/router-snapshot.md
[dubbo-website] 02/03: opt docs
Posted by al...@apache.org.
This is an automated email from the ASF dual-hosted git repository.
albumenj pushed a commit to branch 0719_add_doc4
in repository https://gitbox.apache.org/repos/asf/dubbo-website.git
commit 8502a207baf89545542f84f9c8e45fac7692c479
Author: Albumen Kevin <jh...@gmail.com>
AuthorDate: Tue Jul 19 19:53:14 2022 +0800
opt docs
---
.../observability/router-snapshot.md | 71 +++++++++++++++++++++-
.../reference-manual/qos/router-snapshot.md | 6 +-
2 files changed, 75 insertions(+), 2 deletions(-)
diff --git a/content/zh/docs3-building/java-sdk/advanced-features-and-usage/observability/router-snapshot.md b/content/zh/docs3-building/java-sdk/advanced-features-and-usage/observability/router-snapshot.md
index 016fc4db88..971bf27366 100644
--- a/content/zh/docs3-building/java-sdk/advanced-features-and-usage/observability/router-snapshot.md
+++ b/content/zh/docs3-building/java-sdk/advanced-features-and-usage/observability/router-snapshot.md
@@ -6,4 +6,73 @@ weight: 2
description: "路由状态采集"
---
-TBD
+## 使用场景
+
+Dubbo 的很多流量治理能力是基于 Router 进行实现的，在生产环境中，如果出现流量结果不符合预期的情况，可以通过路由状态命令来查看路由的状态，以此来定位可能存在的问题。
+
+## 使用方式
+
+### 查看路由缓存状态
+
+Dubbo 在收到地址变更的时候，会将地址信息推送给所有的 `Router`，这些 `Router` 可以在此阶段提前计算路由的分组，缓存起来，以避免在调用时需要遍历所有的提供者计算分组参数。
+在 Dubbo 3 中引入的 `StateRouter` 提供了通过 qos 命令工具实时获取每个路由的状态的能力。
+
+运维人员可以通过 `getRouterSnapshot` 命令获取路由的状态。具体命令使用方式可以参考[getRouterSnapshot 命令](../../..//reference-manual/qos/router-snapshot/#getroutersnapshot-%E5%91%BD%E4%BB%A4)文档。
+
+注：此功能仅支持 `StateRoute`，且 `StateRouter` 需要基于 `AbstractStateRouter` 实现 `doBuildSnapshot` 接口。
+
+### 查看实际请求的路由计算结果
+
+Dubbo 3 中默认在路由筛选后为空的时候打印路由计算的节点状态。运维人员可以通过日志判断每个路由的计算结果是否符合预期。
+
+#### 日志格式
+
+```
+No provider available after route for the service 服务 from registry 注册中心地址 on the consumer 消费端IP using the dubbo version 3.0.7. Router snapshot is below:
+[ Parent (Input: 当前节点输入地址数) (Current Node Output: 当前节点计算结果数) (Chain Node Output: 当前节点和后级节点交集结果数) ] Input: 输入的地址示例（显示最多 5 个） -> Chain Node Output: 当前节点输出的地址示例（显示最多 5 个）
+ [ 路由名称 (Input: 当前节点输入地址数) (Current Node Output: 当前节点计算结果数) (Chain Node Output: 当前节点和后级节点交集结果数) Router message: 路由日志 ] Current Node Output: 当前节点输出的地址示例（显示最多 5 个）
+ [ 路由名称 (Input: 当前节点输入地址数) (Current Node Output: 当前节点计算结果数) (Chain Node Output: 当前节点和后级节点交集结果数) Router message: 路由日志 ] Current Node Output: 当前输入的地址示例（显示最多 5 个）
+```
+
+注：
+- 路由日志需要依赖路由实现判断 `needToPrintMessage` 参数，并在需要时写入 `messageHolder` 路由日志
+- 由于多级路由结果是结果取交集的，所以当前节点计算结果数可能和后级取交后为空
+
+#### 日志示例
+
+```
+[19/07/22 07:42:46:046 CST] main WARN cluster.RouterChain: [DUBBO] No provider available after route for the service org.apache.dubbo.samples.governance.api.DemoService from registry 30.227.64.173 on the consumer 30.227.64.173 using the dubbo version 3.0.7. Router snapshot is below:
+[ Parent (Input: 2) (Current Node Output: 2) (Chain Node Output: 0) ] Input: 30.227.64.173:20881,30.227.64.173:20880 -> Chain Node Output: Empty
+ [ MockInvokersSelector (Input: 2) (Current Node Output: 2) (Chain Node Output: 0) Router message: invocation.need.mock not set. Return normal Invokers. ] Current Node Output: 30.227.64.173:20881,30.227.64.173:20880
+ [ StandardMeshRuleRouter (Input: 2) (Current Node Output: 2) (Chain Node Output: 0) Router message: MeshRuleCache has not been built. Skip route. ] Current Node Output: 30.227.64.173:20881,30.227.64.173:20880
+ [ TagStateRouter (Input: 2) (Current Node Output: 0) (Chain Node Output: 0) Router message: FAILOVER: return all Providers without any tags ] Current Node Output: Empty, dubbo version: 3.0.7, current host: 30.227.64.173
+```
+
+#### 开启路由全采样
+
+在一些特殊情况下，请求可能调用到错误的服务端，但是因为选址非空，所以无法看到路由的过程信息，此时可以[通过 qos 开启路由全采样](../../..//reference-manual/qos/router-snapshot/)。通过 qos 的 `getRecentRouterSnapshot` 命令可以远程获取最近的路由快照。
+
+```
+dubbo>getRecentRouterSnapshot
+1658224330156 - Router snapshot service com.dubbo.dubbointegration.BackendService from registry 172.18.111.184 on the consumer 172.18.111.184 using the dubbo version 3.0.9 is below:
+[ Parent (Input: 2) (Current Node Output: 2) (Chain Node Output: 2) ] Input: 172.18.111.187:20880,172.18.111.183:20880 -> Chain Node Output: 172.18.111.187:20880,172.18.111.183:20880
+ [ MockInvokersSelector (Input: 2) (Current Node Output: 2) (Chain Node Output: 2) Router message: invocation.need.mock not set. Return normal Invokers. ] Current Node Output: 172.18.111.187:20880,172.18.111.183:20880
+ [ StandardMeshRuleRouter (Input: 2) (Current Node Output: 2) (Chain Node Output: 2) Router message: MeshRuleCache has not been built. Skip route. ] Current Node Output: 172.18.111.187:20880,172.18.111.183:20880
+ [ TagStateRouter (Input: 2) (Current Node Output: 2) (Chain Node Output: 2) Router message: Disable Tag Router. Reason: tagRouterRule is invalid or disabled ] Current Node Output: 172.18.111.187:20880,172.18.111.183:20880
+ [ ServiceStateRouter (Input: 2) (Current Node Output: 2) (Chain Node Output: 2) Router message: Directly return. Reason: Invokers from previous router is empty or conditionRouters is empty. ] Current Node Output: 172.18.111.187:20880,172.18.111.183:20880
+ [ AppStateRouter (Input: 2) (Current Node Output: 2) (Chain Node Output: 2) Router message: Directly return. Reason: Invokers from previous router is empty or conditionRouters is empty. ] Current Node Output: 172.18.111.187:20880,172.18.111.183:20880
+
+1658224330156 - Router snapshot service com.dubbo.dubbointegration.BackendService from registry 172.18.111.184 on the consumer 172.18.111.184 using the dubbo version 3.0.9 is below:
+[ Parent (Input: 2) (Current Node Output: 2) (Chain Node Output: 2) ] Input: 172.18.111.187:20880,172.18.111.183:20880 -> Chain Node Output: 172.18.111.187:20880,172.18.111.183:20880
+ [ MockInvokersSelector (Input: 2) (Current Node Output: 2) (Chain Node Output: 2) Router message: invocation.need.mock not set. Return normal Invokers. ] Current Node Output: 172.18.111.187:20880,172.18.111.183:20880
+ [ StandardMeshRuleRouter (Input: 2) (Current Node Output: 2) (Chain Node Output: 2) Router message: MeshRuleCache has not been built. Skip route. ] Current Node Output: 172.18.111.187:20880,172.18.111.183:20880
+ [ TagStateRouter (Input: 2) (Current Node Output: 2) (Chain Node Output: 2) Router message: Disable Tag Router. Reason: tagRouterRule is invalid or disabled ] Current Node Output: 172.18.111.187:20880,172.18.111.183:20880
+ [ ServiceStateRouter (Input: 2) (Current Node Output: 2) (Chain Node Output: 2) Router message: Directly return. Reason: Invokers from previous router is empty or conditionRouters is empty. ] Current Node Output: 172.18.111.187:20880,172.18.111.183:20880
+ [ AppStateRouter (Input: 2) (Current Node Output: 2) (Chain Node Output: 2) Router message: Directly return. Reason: Invokers from previous router is empty or conditionRouters is empty. ] Current Node Output: 172.18.111.187:20880,172.18.111.183:20880
+
+···
+
+dubbo>
+```
+
+注：由于日志框架不匹配导致的日志为空可以参考[日志框架适配及运行时管理](../../others/logger-management/)动态修改日志输出框架。
\ No newline at end of file
diff --git a/content/zh/docs3-building/java-sdk/reference-manual/qos/router-snapshot.md b/content/zh/docs3-building/java-sdk/reference-manual/qos/router-snapshot.md
index 1600b9e3c9..db8d8dc4fd 100644
--- a/content/zh/docs3-building/java-sdk/reference-manual/qos/router-snapshot.md
+++ b/content/zh/docs3-building/java-sdk/reference-manual/qos/router-snapshot.md
@@ -14,6 +14,10 @@ Dubbo 的很多流量治理能力是基于 Router 进行实现的，在生产环
获取当前的每层路由的分组状态。（仅支持 StateRouter）
+命令：`getRouterSnapshot {serviceName}`
+
+`serviceName` 为需要采集的服务名，支持匹配
+
```
dubbo>getRouterSnapshot com.dubbo.dubbointegration.BackendService
com.dubbo.dubbointegration.BackendService@2c2e824a
@@ -80,7 +84,7 @@ dubbo>
## getRecentRouterSnapshot 命令
-通过 qos 命令获取历史的路由状态。
+通过 qos 命令获取历史的路由状态。（最多存储 32 个结果）
```
dubbo>getRecentRouterSnapshot
[dubbo-website] 01/03: opt docs
Posted by al...@apache.org.
This is an automated email from the ASF dual-hosted git repository.
albumenj pushed a commit to branch 0719_add_doc4
in repository https://gitbox.apache.org/repos/asf/dubbo-website.git
commit 12422ce5110397a94984109116b41c9a2a781a66
Author: Albumen Kevin <jh...@gmail.com>
AuthorDate: Tue Jul 19 19:27:07 2022 +0800
opt docs
---
.../observability/profiler.md | 184 ++++++++++++++++++++-
1 file changed, 182 insertions(+), 2 deletions(-)
diff --git a/content/zh/docs3-building/java-sdk/advanced-features-and-usage/observability/profiler.md b/content/zh/docs3-building/java-sdk/advanced-features-and-usage/observability/profiler.md
index 553e666b62..4cf0ab04ee 100644
--- a/content/zh/docs3-building/java-sdk/advanced-features-and-usage/observability/profiler.md
+++ b/content/zh/docs3-building/java-sdk/advanced-features-and-usage/observability/profiler.md
@@ -3,7 +3,187 @@ type: docs
title: "请求耗时采样"
linkTitle: "请求耗时采样"
weight: 1
-description: "请求耗时采样"
+description: "Dubbo 3 请求耗时采样"
---
-TBD
+## 功能说明
+
+性能采样功能可以对 Dubbo 处理链路上的各处耗时进行检测，在出现超时的时候 `( usageTime / timeout > profilerWarnPercent * 100 )` 通过日志记录调用的耗时。
+
+此功能分为 `simple profiler` 和 `detail profiler` 两个模式，其中 `simple profiler` 模式默认开启，`detail profiler` 模式默认关闭。
+`detail profiler` 相较 `simple profiler` 模式多采集了每个 filter 的处理耗时、协议上的具体耗时等。
+在 `simple profiler` 模式下如果发现 Dubbo 框架内部存在耗时长的情况，可以开启 `detail profiler` 模式，以便更好地排查问题。
+
+## 使用场景
+
+需要对 Dubbo 请求的精确耗时进行采集分析的场景，如服务不明原因的超时等
+
+## 使用方式
+
+`simple profiler` 默认自动开启，对于请求处理时间超过超时时间 3/4 的，都会通过日志打印出慢调用信息。如果需要开启 `detail profiler` 模式或者修改超时告警比例，可以参考[性能采样命令](../../../reference-manual/qos/profiler/)文档。
+
+### 输出示例
+
+#### 日志说明
+
+日志中各字段的含义如下：
+
+```
+[Dubbo-Consumer] execute service 接口#方法 cost 实际耗时, this invocation almost (maybe already) timeout. Timeout: 超时时间
+invocation context:
+请求上下文
+thread info:
+Start time: 开始请求时间（nano 时间）
++-[ Offset: 当前节点开始时间; Usage: 当前节点使用总耗时, 当前节点耗时比例 ] 当前节点描述
+ +-[ Offset: 当前节点开始时间; Usage: 当前节点使用总耗时, 当前节点耗时比例 ] 当前节点描述
+```
+
+对于请求耗时这里以两个例子进行介绍：
+
+```
+methodA() {
+ do something (1)
+ methodB (2)
+ do something (3)
+}
+
+methodB() {
+ do something (4)
+ methodC (5)
+ do something (6)
+}
+
+methodC() {
+ do something (7)
+}
+
++-[ Offset: 0 ms; Usage: (1) + (2) + (3) ms] execute methodA
+ +-[ Offset: (1) ms; Usage: (4) + (5) + (6) = (2) ms ] execute methodB
+ +-[ Offset: (1) + (4) ms; Usage: (7) = (5) ms ] execute methodC
+
+(1) (2) (3) ... 均为时间占位符
+```
+
+```
+methodA() {
+ do something (1)
+ methodB (2)
+ methodE (3)
+ do something (4)
+}
+
+methodB() {
+ do something (5)
+ methodC (6)
+ methodD (7)
+ do something (8)
+}
+
+methodC() {
+ do something (9)
+}
+
+methodD() {
+ do something (10)
+}
+
+methodE() {
+ do something (11)
+}
+
++-[ Offset: 0 ms; Usage: (1) + (2) + (3) + (4) ms] execute methodA
+ +-[ Offset: (1) ms; Usage: (5) + (6) + (7) + (8) = (2) ms ] execute methodB
+ +-[ Offset: (1) + (5) ms; Usage: (9) = (6) ms ] execute methodC
+ +-[ Offset: (1) + (5) + (6) ms; Usage: (10) = (7) ms ] execute methodD
+ +-[ Offset: (1) + (2) ms; Usage: (11) = (3) ms ] execute methodE
+
+(1) (2) (3) ... 均为时间占位符
+```
+
+#### simple profiler
+
+Consumer 侧：
+```
+[19/07/22 07:08:35:035 CST] main WARN proxy.InvokerInvocationHandler: [DUBBO] [Dubbo-Consumer] execute service org.apache.dubbo.samples.api.GreetingsService#sayHi cost 1003.015746 ms, this invocation almost (maybe already) timeout. Timeout: 1000ms
+invocation context:
+path=org.apache.dubbo.samples.api.GreetingsService;
+remote.application=first-dubbo-consumer;
+interface=org.apache.dubbo.samples.api.GreetingsService;
+version=0.0.0;
+timeout=1000;
+thread info:
+Start time: 285821581299853
++-[ Offset: 0.000000ms; Usage: 1003.015746ms, 100% ] Receive request. Client invoke begin. ServiceKey: org.apache.dubbo.samples.api.GreetingsService MethodName:sayHi
+ +-[ Offset: 7.987015ms; Usage: 994.207928ms, 99% ] Invoker invoke. Target Address: xx.xx.xx.xx:20880, dubbo version: 3.0.10-SNAPSHOT, current host: xx.xx.xx.xx
+```
+
+Provider 侧：
+```
+[19/07/22 07:08:35:035 CST] DubboServerHandler-30.227.64.173:20880-thread-2 WARN filter.ProfilerServerFilter: [DUBBO] [Dubbo-Provider] execute service org.apache.dubbo.samples.api.GreetingsService:0.0.0#sayHi cost 808.494672 ms, this invocation almost (maybe already) timeout. Timeout: 1000ms
+client: xx.xx.xx.xx:51604
+invocation context:
+input=281;
+path=org.apache.dubbo.samples.api.GreetingsService;
+remote.application=first-dubbo-consumer;
+dubbo=2.0.2;
+interface=org.apache.dubbo.samples.api.GreetingsService;
+version=0.0.0;
+timeout=1000;
+thread info:
+Start time: 285821754461125
++-[ Offset: 0.000000ms; Usage: 808.494672ms, 100% ] Receive request. Server invoke begin.
+ +-[ Offset: 1.030912ms; Usage: 804.236342ms, 99% ] Receive request. Server biz impl invoke begin., dubbo version: 3.0.10-SNAPSHOT, current host: xx.xx.xx.xx
+```
+
+#### detail profiler
+
+Consumer 侧：
+```
+[19/07/22 07:10:59:059 CST] main WARN proxy.InvokerInvocationHandler: [DUBBO] [Dubbo-Consumer] execute service org.apache.dubbo.samples.api.GreetingsService#sayHi cost 990.828336 ms, this invocation almost (maybe already) timeout. Timeout: 1000ms
+invocation context:
+path=org.apache.dubbo.samples.api.GreetingsService;
+remote.application=first-dubbo-consumer;
+interface=org.apache.dubbo.samples.api.GreetingsService;
+version=0.0.0;
+timeout=1000;
+thread info:
+Start time: 285965458479241
++-[ Offset: 0.000000ms; Usage: 990.828336ms, 100% ] Receive request. Client invoke begin. ServiceKey: org.apache.dubbo.samples.api.GreetingsService MethodName:sayHi
+ +-[ Offset: 0.852044ms; Usage: 989.899439ms, 99% ] Filter org.apache.dubbo.rpc.cluster.filter.support.ConsumerContextFilter invoke.
+ +-[ Offset: 1.814858ms; Usage: 988.924876ms, 99% ] Filter org.apache.dubbo.rpc.protocol.dubbo.filter.FutureFilter invoke.
+ +-[ Offset: 1.853211ms; Usage: 988.877928ms, 99% ] Filter org.apache.dubbo.monitor.support.MonitorClusterFilter invoke.
+ +-[ Offset: 1.873243ms; Usage: 988.661708ms, 99% ] Filter org.apache.dubbo.rpc.cluster.router.RouterSnapshotFilter invoke.
+ +-[ Offset: 2.159140ms; Usage: 0.504939ms, 0% ] Router route.
+ +-[ Offset: 8.125823ms; Usage: 981.748366ms, 99% ] Cluster org.apache.dubbo.rpc.cluster.support.FailoverClusterInvoker invoke.
+ +-[ Offset: 8.258359ms; Usage: 981.612033ms, 99% ] Invoker invoke. Target Address: xx.xx.xx.xx:20880, dubbo version: 3.0.10-SNAPSHOT, current host: xx.xx.xx.xx
+```
+
+Provider 侧：
+```
+[19/07/22 07:10:59:059 CST] DubboServerHandler-30.227.64.173:20880-thread-2 WARN filter.ProfilerServerFilter: [DUBBO] [Dubbo-Provider] execute service org.apache.dubbo.samples.api.GreetingsService:0.0.0#sayHi cost 811.017347 ms, this invocation almost (maybe already) timeout. Timeout: 1000ms
+client: xx.xx.xx.xx:52019
+invocation context:
+input=281;
+path=org.apache.dubbo.samples.api.GreetingsService;
+remote.application=first-dubbo-consumer;
+dubbo=2.0.2;
+interface=org.apache.dubbo.samples.api.GreetingsService;
+version=0.0.0;
+timeout=1000;
+thread info:
+Start time: 285965612316294
++-[ Offset: 0.000000ms; Usage: 811.017347ms, 100% ] Receive request. Server invoke begin.
+ +-[ Offset: 1.096880ms; Usage: 809.916668ms, 99% ] Filter org.apache.dubbo.rpc.filter.EchoFilter invoke.
+ +-[ Offset: 1.133478ms; Usage: 809.866204ms, 99% ] Filter org.apache.dubbo.rpc.filter.ClassLoaderFilter invoke.
+ +-[ Offset: 1.157563ms; Usage: 809.838572ms, 99% ] Filter org.apache.dubbo.rpc.filter.GenericFilter invoke.
+ +-[ Offset: 1.202075ms; Usage: 809.736843ms, 99% ] Filter org.apache.dubbo.rpc.filter.ContextFilter invoke.
+ +-[ Offset: 1.433193ms; Usage: 809.504401ms, 99% ] Filter org.apache.dubbo.auth.filter.ProviderAuthFilter invoke.
+ +-[ Offset: 1.470760ms; Usage: 809.464291ms, 99% ] Filter org.apache.dubbo.rpc.filter.ExceptionFilter invoke.
+ +-[ Offset: 1.489103ms; Usage: 809.440183ms, 99% ] Filter org.apache.dubbo.monitor.support.MonitorFilter invoke.
+ +-[ Offset: 1.515757ms; Usage: 809.381893ms, 99% ] Filter org.apache.dubbo.rpc.filter.TimeoutFilter invoke.
+ +-[ Offset: 1.526632ms; Usage: 809.366553ms, 99% ] Filter org.apache.dubbo.rpc.protocol.dubbo.filter.TraceFilter invoke.
+ +-[ Offset: 1.536964ms; Usage: 809.335907ms, 99% ] Filter org.apache.dubbo.rpc.filter.ClassLoaderCallbackFilter invoke.
+ +-[ Offset: 1.558545ms; Usage: 804.276436ms, 99% ] Receive request. Server biz impl invoke begin., dubbo version: 3.0.10-SNAPSHOT, current host: xx.xx.xx.xx
+```
+
+注：由于日志框架不匹配导致的日志为空可以参考[日志框架适配及运行时管理](../../others/logger-management/)动态修改日志输出框架。
\ No newline at end of file