This is an automated email from the ASF dual-hosted git repository.
albumenj pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/dubbo-website.git
The following commit(s) were added to refs/heads/master by this push:
new 98df9dfff0 Enhance profiler and router docs (#1260)
98df9dfff0 is described below
commit 98df9dfff052302c5b78cd80ac52e55b5bf31a04
Author: Albumen Kevin <[email protected]>
AuthorDate: Tue Jul 19 19:57:07 2022 +0800
Enhance profiler and router docs (#1260)
* opt docs
* opt docs
---
.../observability/profiler.md | 184 ++++++++++++++++++++-
.../observability/router-snapshot.md | 71 +++++++-
.../reference-manual/qos/router-snapshot.md | 6 +-
3 files changed, 257 insertions(+), 4 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
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
