注，原文来自 https://blog.mygraphql.com/zh/posts/low-tec/trace/trace-istio/trace-istio-part3/ 。如你看到的转载图片不清，请回到原文。

承上

在上一篇 逆向工程与云原生现场分析 Part2 —— eBPF 跟踪 Istio/Envoy 之启动、监听与线程负载均衡 中，介绍了 如何用 bpftrace 去跟踪分析 Envoy Listener 的 socket 监听，和监听是如何分配到 worker 线程的。

逆向工程与云原生现场分析 系列介绍

开始前先做个预告，逆向工程与云原生现场分析 系列（将）包括：

• Part 1: eBPF 跟踪 Istio/Envoy 之学步
• Part 2: eBPF 跟踪 Istio/Envoy 之启动、监听与线程负载均衡
• Part 3: eBPF 跟踪 Istio/Envoy 之 downstream TCP 连接 accept、TLS 握手 与 filter_chain 的选择(本文)
• Part 4: eBPF 跟踪 Istio/Envoy 之 L3/4 Network Fitler 互动机制
• Part 5: eBPF 跟踪 Istio/Envoy 之 http filter
• Part 7: eBPF 跟踪 Istio/Envoy 之 http router
• Part 8: eBPF 跟踪 Istio/Envoy 之 cluster、 connection pool 与 outbound load balance

在系列中，我将演示如何让 bpftrace “读” 懂运行期的由 C++ 11 编写成的 envoy 进程中的对象数据。我花了一个月的时间去补上几个技术债:

• LLVM (clang++) 下 C++ 对象的内存结构，包括为 virtual 函数而生的 vtable
• gdb 小恶魔的入坑，分析 C++ 对象结构

坐稳，扶好。为免吓跑人，还是老套路，多图少代码，不过有的图有点点复杂。程序员大叔开始讲故事了。🚜

为何

为何要了解 Envoy 的事件驱动实现

事件驱动，多路复用和 10k problem 已经是老套故事了。哪有开口就 Cloud Native， 闭口就 Service Mesh 来得抢眼球。但不要以为成熟的东西就无趣，或者没故事。如果你是个 Performance Engineer。只停在这堆大词上，不去深究和实践求证，那么是不会有多少技术上的进步的。深藏于实现的性能问题，也不会被发现。

如，这前的观点是，事件驱动的线程，只有在等待事件时，才会变为非 Runnable 的状态。即在处理事件时，是不会有 block 线程的情况。 所以 Evnoy 的 99% 百分位的 Latency，是其它原因。但当我用 BCC 工具去查看这些线程的离开 cpu 的 stack 时，惊讶地发现：
https://github.com/labilezhu/pub-diy/blob/6042b9f89f5aa3bb199ff3ad7227fd1f9399eee7/low-tec/trace/trace-istio/trace-istio-part3/offcputime.log

这也是为何，Envoy 还是要多个 worker 线程的原因之一吧？

为何要了解 TCP 连接建立过程

作为一个业务应用开发者，的确不必要了解。作为一个 DevOps/SRE/Performance Engineer ，不了解是不合格的。以下变数，足以大大影响应用性能：

1. Client 是长连接，还是短连接。连接建立是高频的吗？建立一个新连接的应用层成本真是那么低吗？
2. 应用的线程和连接是什么关系？如何分派连接到线程？这个关系会影响应用的延迟和吞吐吗？

如果你不清楚这几个问题的答案，那么可能需要了解一下。

为何要了解 TLS 握手过程

可以不夸张地说，没有一家互联网公司不需要做 TLS 会话优化的。特别是对于短连接的接入。TLS 握手的优化空间，绝对比 TCP 握手大。如果我们可以用 trace 等手段拿到握手的延迟统计，就可以为优化指明方向。

为何要了解 filter_chain 的选择逻辑

Istio 控制下的 envoy 配置，是相当复杂的。可以这么说， Envoy 是一个执行 Envoy 配置的引擎，配置是指导 Envoy 代理行为的编程语言。而编程语言最关键的是控制流。filter_chain 就是控制流的 if/else。trace 过 filter_chain 的选择，我们才真实确认了 Envoy 的行为。才可以做相应的配置变更或优化。

相关的架构

逻辑架构

这里只谈本文相关的 Envoy 架构了。整体架构还是去其它大师的文章中了解比较好。

先看看 Listener 的逻辑架构：

图：Listener 的逻辑架构

一般，Listener Filter 和 Network Filter 两个概念比较容易混淆。简单说一下：

• Listener Filter ： 在连接建立之初，收集连接上的首几个信息，为选择 Network Filter Chain 做数据准备。
  • 可以是收集 TCP 基本数据， 如 src IP/port，dst IP/port, 和在 ip table 转发前的原 dst IP/port 。
  • 可以是 TLS 握手数据，SNI/APLN。
• Network Filter ：
  • TCP/TLS 握手后，进行更上层协议的处理，如 HTTP

概念说完了，如不好理解，那么看一个 Istio 的例子：

图：Istio-Proxy Listener 逻辑架构举例 - virtualInbound Listener

相应的 evnoy yaml 配置在这里。

代码架构

图：Envoy Listener 代码架构

听说一图胜千言，所以，不上说明了。

事件驱动与线程模型

不出意外，Envoy 使用了 libevent 这个 C 事件 library， libevent 使用了 Linux Kernel 的 epoll 事件驱动 API。

说明一下图中的流程：

1. Envoy worker 线程挂起在 epoll_wait() 方法中，在内核中注册等待 epoll 关注的 socket 发生事件。线程被移出 kernel 的 runnable queue。线程睡眠。
2. 内核收到 TCP 网络包，触发事件
3. 操作系统把 Envoy worker 线程被移入 kernel 的 runnable queue。Envoy worker 线程被唤醒，变成 runnable。操作系统发现可用 cpu 资源，把 runnable 的 envoy worker 线程调度上 cpu。（注意，runnable 和 调度上 cpu 不是一次完成的）
4. Envoy 分析事件列表，按事件列表的 fd 调度到不同的 FilerEventImpl 类的回调函数（实现见：FilerEventImpl::assignEvents）
5. FilerEventImpl 类的回调函数调用实际的业务回调函数
6. 执行 Envoy 的实际代理行为
7. 完事后，回到步骤 1 。

TCP 连接建立

现在看看，事件驱动和连接的建立的过程和关系：

1. Envoy worker 线程挂起在 epoll_wait() 方法中。线程被移出 kernel 的 runnable queue。线程睡眠。
2. client 建立连接，server 内核完成3次握手，触发 listen socket 事件。
   • 操作系统把 Envoy worker 线程被移入 kernel 的 runnable queue。Envoy worker 线程被唤醒，变成 runnable。操作系统发现可用 cpu 资源，把 runnable 的 envoy worker 线程调度上 cpu。（注意，runnable 和 调度上 cpu 不是一次完成的）
3. Envoy 分析事件列表，按事件列表的 fd 调度到不同的 FilerEventImpl 类的回调函数（实现见：FilerEventImpl::assignEvents）
4. FilerEventImpl 类的回调函数调用实际的业务回调函数，进行 syscall accept，完成 socket 连接。得到新 socket 的 FD: $new_socket_fd。
5. 业务回调函数把 调用 epoll_ctl 把 $new_socket_fd 加到 epoll 监听中。
6. 回到步骤 1 。

关于 listen socket fd

Part2 中，我们看到 socket 监听的情况如下：

1
2
3
4
5
6

$ sudo nsenter -t $POD_PID -n

$ ss -lnp | egrep '15001|15006'

tcp   LISTEN   0   4096   0.0.0.0:15001   0.0.0.0:*    users:(("envoy",pid=2062496,fd=37),("envoy",pid=2062496,fd=38),("envoy",pid=2062496,fd=31))
tcp   LISTEN   0   4096   0.0.0.0:15006   0.0.0.0:*    users:(("envoy",pid=2062496,fd=39),("envoy",pid=2062496,fd=40),("envoy",pid=2062496,fd=32))

可以看到，3 个 fd 都绑定到同一 listen socket 上。1 个 fd 用于主线程，其它 2 个对应自己的 worker 线程。

可以看到 图：Istio-Proxy Listener 逻辑架构举例 - virtualInbound Listener 中 virtualInbound Listener 监听于 15006。

TCP 连接建立步骤

在 ebpf trace 之前，我们先看看代码，了解大概的连接建立过程和相关的实现。

步骤是：

1. epoll 收到连接请求，完成3次握手。最好回调到 TcpListenerImpl::onSocketEvent()。
2. 最终 syscall accept() 获得新 socket 的 FD。
3. 调用 ActiveTcpListener::onAccept()
4. 创建新连接专用的 ListenerFilterChain
5. 创建新连接专用的 ActiveTcpSocket，发起 ListenerFilterChain 流程
6. 执行 ListenerFilterChain 流程：
   1. 如：TlsInspector::Filter 注册监听新 socket 的事件，以便在后续新 socket 发生事件时，读 socket，抽取出 TLS SNI/ALPN。
   2. 当 ListenerFilterChain 中所有的 ListenerFilter 在新的事件和事件周期中完成其所有的数据交换和抽取的任务，本 fd 的控制权交到一环节。
7. 调用 核心函数 ActiveTcpListener：：newConnection()
8. 调用 findFilterChain() 基于之前 ListenerFilter 抽取到的数据，和各 network filter chain 配置 的 match 条件，找到最匹配的 network filter chain 配置 。
9. 创建 ServerConnection(ConnectionImpl的子类) 对象
   1. 注册 socket 事件回调到 Network::ConnectionImpl::onFileEvent(uint32_t events) 中。即以后的 socket 事件将由这个ServerConnection处理。
10. 用之前找到的 network filter chain 配置 对象，创建 transportSocket。
11. 用之前找到的 network filter chain 配置 对象，创建运行期的 NetworkFilterChain。

跟踪 TCP 连接建立

TL;DR.

照惯例，我们先看 bpftrace 跟踪程序的输出。

1. 执行 BPF 程序：

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22

git clone https://github.com/labilezhu/pub-diy
cd ./pub-diy/low-tec/trace/trace-istio/trace-istio-part3

export SCRIPT_HOME=`pwd`
export bpftrace_image=cndt-bcc-ub

export PID=4283

docker run -it --rm --init  --privileged --name bpftrace -h bpftrace \
    --pid host \
    --net host \
    -e SCRIPT_HOME=$SCRIPT_HOME \
    -e PID=$PID \
    -e ENVOY_PID=$PID \
    -e BT=trace-envoy-accept-flow.bt \
    -v /etc/localtime:/etc/localtime:ro \
    -v /sys:/sys:rw \
    -v /usr/src:/usr/src:rw \
    -v /lib/modules:/lib/modules:ro \
    -v ${SCRIPT_HOME}:${SCRIPT_HOME}:rw \
    $bpftrace_image \
    ${SCRIPT_HOME}/warp-bt.sh $PID

2. 发起测试连接和流量

然后发起测试连接和流量。我们将在另一个有 isto-proxy 的 pod 中（假设叫 downstream-pod），发起对目标 pod（假设叫 fortio-server:8080） 的请求。 downstream-pod 的 isto-proxy 会把 http 转为 https，再到达 fortio-server:8080 。

1
2
3
4

# 需要重启 downstream-pod 的 istio-proxy。因为它与 fortio-server 建立了长连接。而我们需要新连接才能观察到 accept 的过程。
k exec -it -c istio-proxy  downstream-pod  -- bash -c 'kill `pgrep envoy`'

k exec  downstream-pod -- curl -v "http://fortio-server:8080/fortio/"

3. 查看输出跟踪结果

原始的结果在：
https://github.com/labilezhu/pub-diy/blob/main/low-tec/trace/trace-istio/trace-istio-part3/trace-envoy-accept-flow.5.log

以下是我精简和加入注解的结果：

##### TCP socket accept 信息：
OS handshaked TCP:
11:13:55 4283   wrk:worker_0(线程名)   172.21.206.219(对端 ip)                          43926(对端 port) 172.21.206.214                          15006(本地 listen 的 port)    0/4096
sys_exit_accept4 fd=42(新连接的 FD)

        accept4+96
        Envoy::Network::IoSocketHandleImpl::accept(sockaddr*, unsigned int*)+82
        Envoy::Network::TcpListenerImpl::onSocketEvent(short)+216
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217
 
##### 构建 TlsInspector 
***** elapsed=-1017877702: tid=4568,comm=wrk:worker_0: TlsInspector*, probe=uprobe:/proc/4283/root/usr/local/bin/envoy:_ZNSt3__110__function6__funcIZN5Envoy10Extensions15ListenerFilters12TlsInspector25TlsInspectorConfigFactory36createListenerFilterFactoryFromProtoERKN6google8protobuf7MessageERKNS_10shared_ptrINS2_7Network21ListenerFilterMatcherEEERNS2_6Server13Configuration22ListenerFactoryContextEEUlRNSD_21ListenerFilterManagerEE_NS_9allocatorISO_EEFvSN_EEclESN_

...

##### 构建 TlsInspector 
***** elapsed=-1017866364: tid=4568,comm=wrk:worker_0: TlsInspector*, probe=uprobe:/proc/4283/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6FilterC1ENSt3__110shared_ptrINS2_6ConfigEEE

...

##### TlsInspector::Filter::onAccept()
***** elapsed=-1017822616: tid=4568,comm=wrk:worker_0: TlsInspector*, probe=uprobe:/proc/4283/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6Filter8onAcceptERNS_7Network23ListenerFilterCallbacksE

##### TlsInspector::Filter::onRead()
***** elapsed=-1017814524: tid=4568,comm=wrk:worker_0: TlsInspector*, probe=uprobe:/proc/4283/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6Filter6onReadEv

##### TlsInspector::Filter::parseClientHello()
***** elapsed=-1013081879: tid=4568,comm=wrk:worker_0: TlsInspector*, probe=uprobe:/proc/4283/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6Filter16parseClientHelloEPKvm

...

##### TlsInspector::Filter::onALPN()，从 TLS 数据中获取到 ALPN
***** elapsed=-1013042582: tid=4568,comm=wrk:worker_0: TlsInspector*, probe=uprobe:/proc/4283/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6Filter6onALPNEPKhj

***** elapsed=-1013030000: tid=4568,comm=wrk:worker_0: ConnectionSocketImpl::setRequestedApplicationProtocols

##### TlsInspector::Filter::onServername()，从 TLS 数据中获取到 SNI
***** elapsed=-1013010367: tid=4568,comm=wrk:worker_0: TlsInspector*, probe=uprobe:/proc/4283/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6Filter12onServernameEN4absl11string_viewE

...

##### 利用 ListnerFitler(包括 original_dst Filter、TlsInspector抽取到的数据)。最终匹配到的 Network Fitler Chain，名字为 0.0.0.0_8080
comm:wrk:worker_0,tid:4568: Got setFilterChainName=0.0.0.0_8080, lenght=12

        Envoy::StreamInfo::StreamInfoImpl::setFilterChainName(absl::string_view)+0
        Envoy::Server::ActiveTcpSocket::newConnection()+377
        Envoy::Server::ActiveTcpSocket::continueFilterChain(bool)+107

##### 注册 新 FD 相关的 epoll 事件回调
***** elapsed=-1012929361: tid=4568,comm=wrk:worker_0: sys_enter_epoll_ctl, epfd=10, op=1, fd=42, epoll_event*=0x7faddbda2c60

        epoll_ctl+14
        epoll_nochangelist_add+54
        evmap_io_add_+421
        event_add_nolock_+603
        event_add+54
        Envoy::Event::FileEventImpl::FileEventImpl(Envoy::Event::DispatcherImpl&, int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)+362
        Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)+284
        Envoy::Network::IoSocketHandleImpl::initializeFileEvent(Envoy::Event::Dispatcher&, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)+126
        Envoy::Network::ConnectionImpl::ConnectionImpl(Envoy::Event::Dispatcher&, std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, std::__1::unique_ptr<Envoy::Network::TransportSocket, std::__1::default_delete<Envoy::Network::TransportSocket> >&&, Envoy::StreamInfo::StreamInfo&, bool)+1026
        Envoy::Network::ServerConnectionImpl::ServerConnectionImpl(Envoy::Event::Dispatcher&, std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, std::__1::unique_ptr<Envoy::Network::TransportSocket, std::__1::default_delete<Envoy::Network::TransportSocket> >&&, Envoy::StreamInfo::StreamInfo&, bool)+107
        Envoy::Event::DispatcherImpl::createServerConnection(std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, std::__1::unique_ptr<Envoy::Network::TransportSocket, std::__1::default_delete<Envoy::Network::TransportSocket> >&&, Envoy::StreamInfo::StreamInfo&)+70
        Envoy::Server::ActiveTcpListener::newConnection(std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, std::__1::unique_ptr<Envoy::StreamInfo::StreamInfo, std::__1::default_delete<Envoy::StreamInfo::StreamInfo> >)+307

##### 配置新 socket 的 sockopt
comm:wrk:worker_0    : setsockopt: level=6, fd=42, optname=1, optval=1, optlen=4. 

##### 本轮新 FD 事件处理完成
***** elapsed=-1012820877: tid=4568,comm=wrk:worker_0: END:EventFired

##### 本轮 epoll 唤醒的所有事件处理完毕
******* WAKE-ROUND:END Summary *******
***** elapsed=-1012807848: tid=4568,comm=wrk:worker_0: sys_enter_epoll_wait, runableDuaration=5158482, tid2epollNrFdReady=1
*** last_epoll_wait_args: epfd=10, events=2052059648, maxevents=32, timeout=100 
***************************




##### FD 相关的 epoll 事件回调
***** elapsed=-1012792293: tid=4568,comm=wrk:worker_0: BEGIN:EventFired:FileEventImpl::assignEvents()::Lambda1()
FileEventImpl*=0x56367a951500, fd=42, events=0x26

##### FD 相关的 epoll 事件处理完毕
***** elapsed=-1011476865: tid=4568,comm=wrk:worker_0: END:EventFired

##### 本轮 epoll 唤醒的所有事件处理完毕
******* WAKE-ROUND:END Summary *******
***** elapsed=-1011446745: tid=4568,comm=wrk:worker_0: sys_enter_epoll_wait, runableDuaration=1346699, tid2epollNrFdReady=1
*** last_epoll_wait_args: epfd=10, events=2052059648, maxevents=32, timeout=16 
***************************




##### FD 相关的 epoll 事件回调
***** elapsed=-976027033: tid=4568,comm=wrk:worker_0: BEGIN:EventFired:FileEventImpl::assignEvents()::Lambda1()
FileEventImpl*=0x56367a951500, fd=42, events=0x26

##### 删除 FD 相关的 epoll 事件回调
***** elapsed=-974127057: tid=4568,comm=wrk:worker_0: sys_enter_epoll_ctl, epfd=10, op=2, fd=42, epoll_event*=0x7faddbda29e0
##### 注册 FD 相关的 epoll 事件回调
***** elapsed=-974087535: tid=4568,comm=wrk:worker_0: sys_enter_epoll_ctl, epfd=10, op=1, fd=42, epoll_event*=0x7faddbda29d0

        epoll_ctl+14
        epoll_nochangelist_add+54
        evmap_io_add_+421
        event_add_nolock_+603
        event_add+54
        Envoy::Network::ConnectionImpl::readDisable(bool)+1077
        Envoy::Http::Http1::ServerConnectionImpl::onMessageCompleteBase()+86
        Envoy::Http::Http1::ConnectionImpl::onMessageComplete()+637
        Envoy::Http::Http1::LegacyHttpParserImpl::Impl::Impl(http_parser_type, void*)::{lambda(http_parser*)#3}::__invoke(http_parser*)+31
        http_parser_execute+7959
        Envoy::Http::Http1::LegacyHttpParserImpl::execute(char const*, int)+31
        Envoy::Http::Http1::ConnectionImpl::dispatchSlice(char const*, unsigned long)+52

##### FD 相关的 epoll 事件处理完毕
***** elapsed=-973377160: tid=4568,comm=wrk:worker_0: END:EventFired

##### 本轮 epoll 唤醒的所有事件处理完毕
******* WAKE-ROUND:END Summary *******
***** elapsed=-973322877: tid=4568,comm=wrk:worker_0: sys_enter_epoll_wait, runableDuaration=2738098, tid2epollNrFdReady=1
*** last_epoll_wait_args: epfd=10, events=2052059648, maxevents=32, timeout=100 
***************************





***** elapsed=-973302083: tid=4568,comm=wrk:worker_0: BEGIN:EventFired:FileEventImpl::assignEvents()::Lambda1()
FileEventImpl*=0x56367a951500, fd=42, events=0x24


***** elapsed=-973210034: tid=4568,comm=wrk:worker_0: END:EventFired

******* WAKE-ROUND:END Summary *******
***** elapsed=-970967200: tid=4568,comm=wrk:worker_0: sys_enter_epoll_wait, runableDuaration=2329760, tid2epollNrFdReady=3
*** last_epoll_wait_args: epfd=10, events=2052059648, maxevents=32, timeout=88 
***************************




***** elapsed=-970216003: tid=4568,comm=wrk:worker_0: sys_enter_epoll_ctl, epfd=10, op=2, fd=42, epoll_event*=0x7faddbda24b0
***** elapsed=-970198884: tid=4568,comm=wrk:worker_0: sys_enter_epoll_ctl, epfd=10, op=1, fd=42, epoll_event*=0x7faddbda24a0

        epoll_ctl+14
        epoll_nochangelist_add+54
        evmap_io_add_+421
        event_add_nolock_+603
        event_add+54
        Envoy::Network::ConnectionImpl::readDisable(bool)+938
        Envoy::Http::Http1::StreamEncoderImpl::~StreamEncoderImpl()+112
        non-virtual thunk to Envoy::Http::Http1::ServerConnectionImpl::onEncodeComplete()+54
        Envoy::Http::Http1::StreamEncoderImpl::endEncode()+166
        Envoy::Http::Http1::StreamEncoderImpl::encodeData(Envoy::Buffer::Instance&, bool)+340
        Envoy::Http::ConnectionManagerImpl::ActiveStream::encodeData(Envoy::Buffer::Instance&, bool)+679
        Envoy::Http::FilterManager::encodeData(Envoy::Http::ActiveStreamEncoderFilter*, Envoy::Buffer::Instance&, bool, Envoy::Http::FilterManager::FilterIterationStartState)+2138


***** elapsed=-969958893: tid=4568,comm=wrk:worker_0: BEGIN:EventFired:FileEventImpl::assignEvents()::Lambda1()
FileEventImpl*=0x56367a951500, fd=42, events=0x24


***** elapsed=-969845835: tid=4568,comm=wrk:worker_0: END:EventFired

******* WAKE-ROUND:END Summary *******
***** elapsed=-969831672: tid=4568,comm=wrk:worker_0: sys_enter_epoll_wait, runableDuaration=126155, tid2epollNrFdReady=1
*** last_epoll_wait_args: epfd=10, events=2052059648, maxevents=32, timeout=84 
***************************

回头看看 bpftrace 跟踪程序源代码：
https://github.com/labilezhu/pub-diy/blob/main/low-tec/trace/trace-istio/trace-istio-part3/trace-envoy-accept-flow.bt

  1
  2
  3
  4
  5
  6
  7
  8
  9
 10
 11
 12
 13
 14
 15
 16
 17
 18
 19
 20
 21
 22
 23
 24
 25
 26
 27
 28
 29
 30
 31
 32
 33
 34
 35
 36
 37
 38
 39
 40
 41
 42
 43
 44
 45
 46
 47
 48
 49
 50
 51
 52
 53
 54
 55
 56
 57
 58
 59
 60
 61
 62
 63
 64
 65
 66
 67
 68
 69
 70
 71
 72
 73
 74
 75
 76
 77
 78
 79
 80
 81
 82
 83
 84
 85
 86
 87
 88
 89
 90
 91
 92
 93
 94
 95
 96
 97
 98
 99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316

#!usr/bin/bpftrace
/*
IMPORT-ENV: $ENVOY_PID
args: $1=ENVOY_PID
*/

/*
1. BPF Map 说明:

1.1. range tid map
- @watchedWakeRound[tid]=tid
       - sys_exit_accept4
- @fdFired[tid]=1;
       - uprobe: *FileEventImpl*assignEvents*
       - uretprobe: *FileEventImpl*assignEvents*

1.2. fd map
- @fd2sockpair[$fd]=@sockpair[tid]
       - sys_exit_accept4
       - sys_enter_close
- @fd2sockopt[$fd, $level, $optname, $optval_int] = 1
       - sys_enter_setsockopt

1.3. temp tid map
- @sockpair[tid]=($sk->__sk_common.skc_daddr, $dport, $sk->__sk_common.skc_rcv_saddr, $lport);
- @sockpair_exist[tid]=1

*/

#include <linux/in.h>
#include <linux/in6.h>
#include <linux/socket.h>
#include <net/sock.h>

BEGIN
{
	printf("Tracing Envoy. Hit Ctrl-C to end.\n");
       printf("#define EPOLL_CTL_ADD 1\n #define EPOLL_CTL_DEL 2\n #define EPOLL_CTL_MOD 3\n")
}

/*
获取 accept 连接时的本地和对端地址。并标记本轮 wakeup 需要监控
 */
kretprobe:inet_csk_accept
/pid==$1 /
{
	$sk = (struct sock *)retval;
	$inet_family = $sk->__sk_common.skc_family;

	if ($inet_family == AF_INET || $inet_family == AF_INET6) {
		// initialize variable type:
		$daddr = ntop(0);
		$saddr = ntop(0);
		if ($inet_family == AF_INET) {
			$daddr = ntop($sk->__sk_common.skc_daddr);
			$saddr = ntop($sk->__sk_common.skc_rcv_saddr);
		} else {
			printf("not support IPv6.\n");
			return;
		}
		
		$lport = $sk->__sk_common.skc_num;

              // printf("accept(), port=%d\n", $lport);

              //only watch listen port 15006
		if( 15006 != $lport ) { 
			return;
		}

		$dport = $sk->__sk_common.skc_dport;
		$qlen  = $sk->sk_ack_backlog;
		$qmax  = $sk->sk_max_ack_backlog;

		// Destination port is big endian, it must be flipped
		$dport = ($dport >> 8) | (($dport << 8) & 0x00FF00);

              printf("OS handshaked TCP:\n");
		time("%H:%M:%S ");
		printf("%-6d %-14s ", pid, comm);
		printf("%-39s %-5d %-39s %-5d ", $daddr, $dport, $saddr,
		    $lport);
		printf("%d/%d\n", $qlen, $qmax);

		@sockpair[tid]=($sk->__sk_common.skc_daddr, $dport, $sk->__sk_common.skc_rcv_saddr, $lport);
		@sockpair_exist[tid]=1;

              @watchedWakeRound[tid]=tid;
	}
}

/**
 * 获取新连接的 FD 。并标记本轮 libevent 回调需要监控
 */
tracepoint:syscalls:sys_exit_accept4
/pid==$1 && @sockpair_exist[tid] /
{
	$fd = args->ret;
	if( $fd < 0 ) {
		return;
	}
	printf("sys_exit_accept4 fd=%d\n", $fd);
	@fd2sockpair[$fd]=@sockpair[tid];

       @fdFired[tid]=1;

	delete(@sockpair[tid]);
	delete(@sockpair_exist[tid]);
       printf("%s \n", ustack());
}

/**
 * 记录 FD 的 sockopt
 */
tracepoint:syscalls:sys_enter_setsockopt
/pid==$1/
{
       // socket opts: https://elixir.bootlin.com/linux/v5.16.3/source/include/uapi/linux/tcp.h#L92     
       $level = args->level;
       $fd = args->fd;

       if( @fd2sockpair[$fd].0 ) {
              $optname = args->optname;
              $optval = args->optval;
              $optval_int = *$optval;
              $optlen = args->optlen;
              // printf("\n########## setsockopt() ##########\n");
              printf("comm:%-16s: setsockopt: level=%d, fd=%d, optname=%d, optval=%d, optlen=%d. \n", comm, $level, $fd, $optname, $optval_int, $optlen);
              @fd2sockopt[$fd, $level, $optname, $optval_int] = 1;
       }
}

/*
记录 epoll 监听的 FD

cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_epoll_ctl/format
 */
tracepoint:syscalls:sys_enter_epoll_ctl
/pid==$1/
{
       $fd=args->fd;
       if( @fd2sockpair[$fd].0 ) {
              printf("***** elapsed=%d: tid=%d,comm=%s: sys_enter_epoll_ctl, epfd=%d, op=%d, fd=%d, epoll_event*=%p\n", 
                     elapsed, tid, comm, args->epfd, args->op, $fd, args->event);

              if( args->op == 1 ) { //add watch epoll event
                     printf("%s\n", ustack(12));
              }
              
       }
}

/*
结束本轮的 wakeRound/runnableRound，并等待下一轮
cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_epoll_wait/format
 */
tracepoint:syscalls:sys_enter_epoll_wait
/pid==$1/
{

       if( @watchedWakeRound[tid] ) {
              $runnableStartTime=@tid2Waketime[tid];
              if( $runnableStartTime ) {
                     $runableDuaration = elapsed - $runnableStartTime;
                     printf("\n******* WAKE-ROUND:END Summary *******\n");
                     printf("***** elapsed=%d: tid=%d,comm=%s: sys_enter_epoll_wait, runableDuaration=%d, tid2epollNrFdReady=%d\n", 
                            elapsed, tid, comm, $runableDuaration, @tid2epollNrFdReady[tid]);
                     $tid_last_epoll_wait_args = @last_epoll_wait_args[tid];
                     if( $tid_last_epoll_wait_args.0  ) {
                            printf("*** last_epoll_wait_args: epfd=%d, events=%d, maxevents=%d, timeout=%d \n", 
                                   $tid_last_epoll_wait_args.0, $tid_last_epoll_wait_args.1, $tid_last_epoll_wait_args.2, $tid_last_epoll_wait_args.3);
                     }
                     printf("***************************\n\n");
              }
       }

       delete(@tid2Waketime[tid]);
       delete(@watchedWakeRound[tid]);
       delete(@tid2epollNrFdReady[tid]);

       //read in next sys_enter_epoll_wait
       @last_epoll_wait_args[tid]=(args->epfd, args->events, args->maxevents, args->timeout);
}

/*
开始本轮 wakeRound/runnableRound
cat /sys/kernel/debug/tracing/events/syscalls/sys_exit_epoll_wait/format
 */
tracepoint:syscalls:sys_exit_epoll_wait
/pid==$1/
{
       // printf("\n***** elapsed=%d: tid=%d,comm=%s: sys_enter_epoll_wait\n", elapsed, tid, comm);

       // printf("epfd: 0x%08lx, events: 0x%08lx, maxevents: 0x%08lx, timeout: 0x%08lx \n", 
       //        ((args->epfd)), ((args->events)), ((args->maxevents)), ((args->timeout)) );

       @tid2Waketime[tid]=elapsed;
       @tid2epollNrFdReady[tid]=args->ret;
}

/*
记录本轮 epoll 事件触发的 FD 级回调开始

Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int fd, short events, void* fileEventImplThis)  !!!NOT!!: FileEventImpl::assignEvents()
C++11 Lambda expressions:
event_assign( &raw_event_, base, fd_, xxx, [](evutil_socket_t, short what, void* arg)-> void {}, this );

event_assign(): https://libevent.org/doc/event_8h.html#a3e49a8172e00ae82959dfe64684eda11
       event_assign	(	struct event * 	ev,
              struct event_base * 	base,
              evutil_socket_t 	fd,
              short 	events,
              event_callback_fn 	callback,
              void * 	callback_arg 
       )	

       https://libevent.org/doc/event_8h.html#aed2307f3d9b38e07cc10c2607322d758
       typedef void(* event_callback_fn) (evutil_socket_t, short, void *)
              fd	An fd or signal
              events	One or more EV_* flags
              arg	A user-supplied argument.
*/
uprobe:/proc/${ENVOY_PID}/root/usr/local/bin/envoy:*FileEventImpl*assignEvents*
/pid == $1/ 
{
       $fd = arg0;
       if( @fd2sockpair[$fd].0 ) {
              printf("\n***** elapsed=%d: tid=%d,comm=%s: BEGIN:EventFired:FileEventImpl::assignEvents()::Lambda1()\n", elapsed, tid, comm);
              printf("FileEventImpl*=%p, fd=%d, events=0x%x\n",arg2, $fd, arg1);
              printf("%s\n", kstack);
              @fdFired[tid]=1;
              @watchedWakeRound[tid]=tid;
       }
}

/*
记录本轮 epoll 事件触发的 FD 级回调结束
*/
uretprobe:/proc/${ENVOY_PID}/root/usr/local/bin/envoy:*FileEventImpl*assignEvents*
/pid == $1 && @fdFired[tid]/ 
{
       printf("\n***** elapsed=%d: tid=%d,comm=%s: END:EventFired\n", elapsed, tid, comm);
       delete(@fdFired[tid]);
}

/*
打印 TlsInspector 的所有函数调用
*/
uprobe:/proc/${ENVOY_PID}/root/usr/local/bin/envoy:*TlsInspector*
/pid == $1 && @fdFired[tid]/ 
{
       printf("\n***** elapsed=%d: tid=%d,comm=%s: TlsInspector*, probe=%s\n", elapsed, tid, comm, probe);
}

/*
打印连接确认协后的函数调用
*/
uprobe:/proc/${ENVOY_PID}/root/usr/local/bin/envoy:*ConnectionSocketImpl*setRequestedApplicationProtocols*
/pid == $1 && @fdFired[tid]/ 
{
       printf("\n***** elapsed=%d: tid=%d,comm=%s: ConnectionSocketImpl::setRequestedApplicationProtocols\n", elapsed, tid, comm);
       // printf("%s", ustack);
}

/*
打印匹配到的 Network Fitler Chain 名字
void setFilterChainName(absl::string_view filter_chain_name)
*/
uprobe:/proc/${ENVOY_PID}/root/usr/local/bin/envoy:_ZN5Envoy10StreamInfo14StreamInfoImpl18setFilterChainNameEN4absl11string_viewE 
/pid == $1 && @fdFired[tid]/ 
{ 
/**
[Assembly 2: Calling convention](https://cs61.seas.harvard.edu/site/2018/Asm2/)

1. A structure argument that fits in a single machine word (64 bits/8 bytes) is passed in a single register.
   
    Example: `struct small { char a1, a2; }`

2. A structure that fits in two to four machine words (16–32 bytes) is passed in sequential registers, as if it were multiple arguments.
   
    Example: `struct medium { long a1, a2; }`
*/
    $filterName = str(reg("si"));
    $filterNameLength = reg("dx");

    // printf("tid:%d: Got setFilterChainName=%s, lenght=%d\n %s \n", tid, $filterName, $filterNameLength, ustack ); 
    printf("comm:%s,tid:%d: Got setFilterChainName=%s, lenght=%d\n", comm, tid, $filterName, $filterNameLength ); 

    if( $filterNameLength > 0 ) {
        printf("%s\n", ustack(3));
    }
}

/*
清理关闭的 FD 相关的 Map
cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_close/format
*/
tracepoint:syscalls:sys_enter_close
/pid==$1/
{
	$fd = args->fd;
	if( $fd < 0 ) {
		return;
	}
       if( @fd2sockpair[$fd].0 ) {
              printf("sys_enter_close fd=%d\n", $fd);
       }
	delete(@fd2sockpair[$fd]);
}

END
{
       clear(@last_epoll_wait_args);
       clear(@tid2Waketime);
       clear(@tid2epollNrFdReady);
}

跟踪 Istio mTLS 握手过程

这部分的类图未整理。同样地，我们先看看跟踪的输出。可以认为是上面一个的加强信息量版本：
https://github.com/labilezhu/pub-diy/blob/main/low-tec/trace/trace-istio/trace-istio-part3/trace-envoy-accept-flow-ssl.6.log

Attaching 116 probes...
Tracing Envoy. Hit Ctrl-C to end.

### 建立连接
OS handshaked TCP:
12:48:54 3620   wrk:worker_1   172.21.206.237                          58394 172.21.206.227                          15006 0/4096
sys_exit_accept4 fd=42

        accept4+96
        Envoy::Network::IoSocketHandleImpl::accept(sockaddr*, unsigned int*)+82
        Envoy::Network::TcpListenerImpl::onSocketEvent(short)+216
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217
 
***** elapsed=1026569139: tid=4293,comm=wrk:worker_1: TlsInspector*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZNSt3__110__function6__funcIZN5Envoy10Extensions15ListenerFilters12TlsInspector25TlsInspectorConfigFactory36createListenerFilterFactoryFromProtoERKN6google8protobuf7MessageERKNS_10shared_ptrINS2_7Network21ListenerFilterMatcherEEERNS2_6Server13Configuration22ListenerFactoryContextEEUlRNSD_21ListenerFilterManagerEE_NS_9allocatorISO_EEFvSN_EEclESN_

***** elapsed=1026610269: tid=4293,comm=wrk:worker_1: TlsInspector*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZNSt3__128__invoke_void_return_wrapperIvE6__callIJRZN5Envoy10Extensions15ListenerFilters12TlsInspector25TlsInspectorConfigFactory36createListenerFilterFactoryFromProtoERKN6google8protobuf7MessageERKNS_10shared_ptrINS3_7Network21ListenerFilterMatcherEEERNS3_6Server13Configuration22ListenerFactoryContextEEUlRNSE_21ListenerFilterManagerEE_SO_EEEvDpOT_

***** elapsed=1026620829: tid=4293,comm=wrk:worker_1: TlsInspector*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6FilterC1ENSt3__110shared_ptrINS2_6ConfigEEE

***** elapsed=1026625163: tid=4293,comm=wrk:worker_1: TlsInspector*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6FilterC2ENSt3__110shared_ptrINS2_6ConfigEEE

***** elapsed=1026653428: tid=4293,comm=wrk:worker_1: TlsInspector*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6Filter8onAcceptERNS_7Network23ListenerFilterCallbacksE

***** elapsed=1026663985: tid=4293,comm=wrk:worker_1: TlsInspector*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6Filter6onReadEv

### TlsInspector(LisenerFilter) 偷看(MSG_PEEK)了 218 bytes 的 TLS clientHello 数据
***** elapsed=1026702268: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_recvfrom, fd=42, ret=218

        recv+108

***** elapsed=1026717298: tid=4293,comm=wrk:worker_1: TlsInspector*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6Filter16parseClientHelloEPKvm

***** elapsed=1026739275: tid=4293,comm=wrk:worker_1: TlsInspector*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZZN5Envoy10Extensions15ListenerFilters12TlsInspector6ConfigC1ERNS_5Stats5ScopeEjEN3$_08__invokeEPK22ssl_early_callback_ctx

***** elapsed=1026745766: tid=4293,comm=wrk:worker_1: TlsInspector*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6Filter6onALPNEPKhj

### TlsInspector(LisenerFilter) 识别出了 TLS clientHello 中的 ALPN（Client自述支持的协议，如 HTTP1.1） 部分，把它记录在连接属性中，供后面 FitlerChain 选择时使用。
***** elapsed=1026761220: tid=4293,comm=wrk:worker_1: ConnectionSocketImpl::setRequestedApplicationProtocols

***** elapsed=1026774127: tid=4293,comm=wrk:worker_1: ConnectionSocketImpl::setRequestedApplicationProtocols

***** elapsed=1026786011: tid=4293,comm=wrk:worker_1: TlsInspector*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZZN5Envoy10Extensions15ListenerFilters12TlsInspector6ConfigC1ERNS_5Stats5ScopeEjEN3$_18__invokeEP6ssl_stPiPv

### TlsInspector(LisenerFilter) 识别出了 TLS clientHello 中的SNI，即服务端的域名，把它记录在连接属性中，供后面 FitlerChain 选择时使用。
***** elapsed=1026792676: tid=4293,comm=wrk:worker_1: TlsInspector*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6Filter12onServernameEN4absl11string_viewE

### TlsInspector(LisenerFilter) 完成任务, 被销毁。TlsInspector::Filter::~Filter()
***** elapsed=1026806259: tid=4293,comm=wrk:worker_1: TlsInspector*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions15ListenerFilters12TlsInspector6FilterD0Ev

### FilterChain 选择的结果：
comm:wrk:worker_1,tid:4293: Got setFilterChainName=0.0.0.0_8080, lenght=12

        Envoy::StreamInfo::StreamInfoImpl::setFilterChainName(absl::string_view)+0
        Envoy::Server::ActiveTcpSocket::newConnection()+377
        Envoy::Server::ActiveTcpSocket::continueFilterChain(bool)+107

### 1. 构建 SslSocket
***** elapsed=1026857348: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions16TransportSockets3Tls9SslSocketC2ENSt3__110shared_ptrINS_3Ssl7ContextEEENS2_12InitialStateERKNS5_IKNS_7Network22TransportSocketOptionsEEENS4_8functionIFNS5_INS6_10HandshakerEEENS4_10unique_ptrI6ssl_stN4bssl8internal7DeleterISK_EEEEiPNS6_18HandshakeCallbacksEEEE

        Envoy::Extensions::TransportSockets::Tls::SslSocket::SslSocket(std::__1::shared_ptr<Envoy::Ssl::Context>, Envoy::Extensions::TransportSockets::Tls::InitialState, std::__1::shared_ptr<Envoy::Network::TransportSocketOptions const> const&, std::__1::function<std::__1::shared_ptr<Envoy::Ssl::Handshaker> (std::__1::unique_ptr<ssl_st, bssl::internal::Deleter<ssl_st> >, int, Envoy::Ssl::HandshakeCallbacks*)>)+0
        Envoy::Extensions::TransportSockets::Tls::ServerSslSocketFactory::createTransportSocket(std::__1::shared_ptr<Envoy::Network::TransportSocketOptions const>) const+227
        Envoy::Server::ActiveTcpListener::newConnection(std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, std::__1::unique_ptr<Envoy::StreamInfo::StreamInfo, std::__1::default_delete<Envoy::StreamInfo::StreamInfo> >)+130
        Envoy::Server::ActiveTcpSocket::newConnection()+377
        Envoy::Server::ActiveTcpSocket::continueFilterChain(bool)+107
        Envoy::Server::ActiveTcpListener::onAcceptWorker(std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, bool, bool)+163
        Envoy::Network::TcpListenerImpl::onSocketEvent(short)+856
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000

### 2. 注册连接的 ReadReady/WriteReady 的 callback 到 ConnectionImpl
***** elapsed=1026881729: tid=4293,comm=wrk:worker_1: sys_enter_epoll_ctl, epfd=14, op=EPOLL_CTL_ADD, fd=42, events=0x80000005
EPOLL_CTL_ADD/MOD ReadReady(EPOLLIN)
EPOLL_CTL_ADD/MOD WriteReady(EPOLLOUT)
EPOLL_CTL_ADD/MOD EdgeTrigger

        epoll_ctl+14
        epoll_nochangelist_add+54
        evmap_io_add_+421
        event_add_nolock_+603
        event_add+54
        Envoy::Event::FileEventImpl::FileEventImpl(Envoy::Event::DispatcherImpl&, int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)+362
        Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)+284
        Envoy::Network::IoSocketHandleImpl::initializeFileEvent(Envoy::Event::Dispatcher&, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)+126
        Envoy::Network::ConnectionImpl::ConnectionImpl(Envoy::Event::Dispatcher&, std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, std::__1::unique_ptr<Envoy::Network::TransportSocket, std::__1::default_delete<Envoy::Network::TransportSocket> >&&, Envoy::StreamInfo::StreamInfo&, bool)+1026
        Envoy::Network::ServerConnectionImpl::ServerConnectionImpl(Envoy::Event::Dispatcher&, std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, std::__1::unique_ptr<Envoy::Network::TransportSocket, std::__1::default_delete<Envoy::Network::TransportSocket> >&&, Envoy::StreamInfo::StreamInfo&, bool)+107
        Envoy::Event::DispatcherImpl::createServerConnection(std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, std::__1::unique_ptr<Envoy::Network::TransportSocket, std::__1::default_delete<Envoy::Network::TransportSocket> >&&, Envoy::StreamInfo::StreamInfo&)+70
        Envoy::Server::ActiveTcpListener::newConnection(std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, std::__1::unique_ptr<Envoy::StreamInfo::StreamInfo, std::__1::default_delete<Envoy::StreamInfo::StreamInfo> >)+307
        Envoy::Server::ActiveTcpSocket::newConnection()+377
        Envoy::Server::ActiveTcpSocket::continueFilterChain(bool)+107
        Envoy::Server::ActiveTcpListener::onAcceptWorker(std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, bool, bool)+163
        Envoy::Network::TcpListenerImpl::onSocketEvent(short)+856
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217


***** elapsed=1026910626: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions16TransportSockets3Tls9SslSocket27setTransportSocketCallbacksERNS_7Network24TransportSocketCallbacksE

        Envoy::Extensions::TransportSockets::Tls::SslSocket::setTransportSocketCallbacks(Envoy::Network::TransportSocketCallbacks&)+0
        Envoy::Network::ServerConnectionImpl::ServerConnectionImpl(Envoy::Event::Dispatcher&, std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, std::__1::unique_ptr<Envoy::Network::TransportSocket, std::__1::default_delete<Envoy::Network::TransportSocket> >&&, Envoy::StreamInfo::StreamInfo&, bool)+107
        Envoy::Event::DispatcherImpl::createServerConnection(std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, std::__1::unique_ptr<Envoy::Network::TransportSocket, std::__1::default_delete<Envoy::Network::TransportSocket> >&&, Envoy::StreamInfo::StreamInfo&)+70
        Envoy::Server::ActiveTcpListener::newConnection(std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, std::__1::unique_ptr<Envoy::StreamInfo::StreamInfo, std::__1::default_delete<Envoy::StreamInfo::StreamInfo> >)+307
        Envoy::Server::ActiveTcpSocket::newConnection()+377
        Envoy::Server::ActiveTcpSocket::continueFilterChain(bool)+107
        Envoy::Server::ActiveTcpListener::onAcceptWorker(std::__1::unique_ptr<Envoy::Network::ConnectionSocket, std::__1::default_delete<Envoy::Network::ConnectionSocket> >&&, bool, bool)+163
        Envoy::Network::TcpListenerImpl::onSocketEvent(short)+856
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92

comm:wrk:worker_1    : setsockopt: level=6, fd=42, optname=1, optval=1, optlen=4. 

***** elapsed=1027034582: tid=4293,comm=wrk:worker_1: END:EventFired

******* WAKE-ROUND:END Summary *******
***** elapsed=1027048750: tid=4293,comm=wrk:worker_1: sys_enter_epoll_wait, runableDuaration=12738117, tid2epollNrFdReady=1
*** last_epoll_wait_args: epfd=14, events=945353600, maxevents=32, timeout=100 
***************************

### 连接发生 ReadReady/WriteReady 回调 到 ConnectionImpl。开始了本 fd 的新一轮回调处理。
***** elapsed=1027065513: tid=4293,comm=wrk:worker_1: BEGIN:EventFired:FileEventImpl::assignEvents::eventCallback()
FileEventImpl*=0x563d38fb4ee0, fd=42, events=0x26
libevent: EV_READ
libevent: EV_WRITE
libevent: EV_ET


***** elapsed=1027103573: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions16TransportSockets3Tls9SslSocket7doWriteERNS_6Buffer8InstanceEb

        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+0
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### TLS 握手开始，读 socket，期待读到 TLS ClientHello
***** elapsed=1027121336: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=5

        readv+77
        Envoy::Network::IoSocketHandleImpl::readv(unsigned long, Envoy::Buffer::RawSlice*, unsigned long)+247
        Envoy::Extensions::TransportSockets::Tls::(anonymous namespace)::io_handle_read(bio_st*, char*, int)+54
        BIO_read+46
        bssl::ssl_read_buffer_extend_to(ssl_st*, unsigned long)+457
        bssl::ssl_handle_open_record(ssl_st*, bool*, bssl::ssl_open_record_t, unsigned long, unsigned char)+222
        bssl::ssl_run_handshake(bssl::SSL_HANDSHAKE*, bool*)+247
        SSL_do_handshake+100
        Envoy::Extensions::TransportSockets::Tls::SslHandshakerImpl::doHandshake()+30
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+56
        Envoy::Network::ConnectionImpl::onWriteReady()+1876
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217


***** elapsed=1027135256: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=213

        readv+77
        Envoy::Network::IoSocketHandleImpl::readv(unsigned long, Envoy::Buffer::RawSlice*, unsigned long)+247
        Envoy::Extensions::TransportSockets::Tls::(anonymous namespace)::io_handle_read(bio_st*, char*, int)+54
        BIO_read+46
        bssl::ssl_read_buffer_extend_to(ssl_st*, unsigned long)+457
        bssl::ssl_handle_open_record(ssl_st*, bool*, bssl::ssl_open_record_t, unsigned long, unsigned char)+222
        bssl::ssl_run_handshake(bssl::SSL_HANDSHAKE*, bool*)+247
        SSL_do_handshake+100
        Envoy::Extensions::TransportSockets::Tls::SslHandshakerImpl::doHandshake()+30
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+56
        Envoy::Network::ConnectionImpl::onWriteReady()+1876
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### TLS 握手中，已经完成 TLS ClientHello 的读取。发送 TLS Server Hello， 2083 bytes
***** elapsed=1032040321: tid=4293,comm=wrk:worker_1: socket_write, probe=tracepoint:syscalls:sys_exit_writev, fd=42, ret=2083

        writev+77
        Envoy::Network::IoSocketHandleImpl::writev(Envoy::Buffer::RawSlice const*, unsigned long)+263
        Envoy::Extensions::TransportSockets::Tls::(anonymous namespace)::io_handle_write(bio_st*, char const*, int)+48
        BIO_write+46
        bssl::tls_flush_flight(ssl_st*)+306
        bssl::ssl_run_handshake(bssl::SSL_HANDSHAKE*, bool*)+290
        SSL_do_handshake+100
        Envoy::Extensions::TransportSockets::Tls::SslHandshakerImpl::doHandshake()+30
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+56
        Envoy::Network::ConnectionImpl::onWriteReady()+1876
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### TLS 握手中，已经读完了现有的 socket 数据
***** elapsed=1032093848: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=-11

        readv+77
        Envoy::Network::IoSocketHandleImpl::readv(unsigned long, Envoy::Buffer::RawSlice*, unsigned long)+247
        Envoy::Extensions::TransportSockets::Tls::(anonymous namespace)::io_handle_read(bio_st*, char*, int)+54
        BIO_read+46
        bssl::ssl_read_buffer_extend_to(ssl_st*, unsigned long)+457
        bssl::ssl_handle_open_record(ssl_st*, bool*, bssl::ssl_open_record_t, unsigned long, unsigned char)+222
        bssl::ssl_run_handshake(bssl::SSL_HANDSHAKE*, bool*)+247
        SSL_do_handshake+100
        Envoy::Extensions::TransportSockets::Tls::SslHandshakerImpl::doHandshake()+30
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+56
        Envoy::Network::ConnectionImpl::onWriteReady()+1876
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217


***** elapsed=1032121531: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions16TransportSockets3Tls9SslSocket6doReadERNS_6Buffer8InstanceE

        Envoy::Extensions::TransportSockets::Tls::SslSocket::doRead(Envoy::Buffer::Instance&)+0
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+879
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### 为上一行日志的下级函数调用（即同一个 stack)。尝试读数据，但同样发现，已经读完了现有的 socket 数据
***** elapsed=1032133376: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=-11

        readv+77
        Envoy::Network::IoSocketHandleImpl::readv(unsigned long, Envoy::Buffer::RawSlice*, unsigned long)+247
        Envoy::Extensions::TransportSockets::Tls::(anonymous namespace)::io_handle_read(bio_st*, char*, int)+54
        BIO_read+46
        bssl::ssl_read_buffer_extend_to(ssl_st*, unsigned long)+457
        bssl::ssl_handle_open_record(ssl_st*, bool*, bssl::ssl_open_record_t, unsigned long, unsigned char)+222
        bssl::ssl_run_handshake(bssl::SSL_HANDSHAKE*, bool*)+247
        SSL_do_handshake+100
        Envoy::Extensions::TransportSockets::Tls::SslHandshakerImpl::doHandshake()+30
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doRead(Envoy::Buffer::Instance&)+78
        Envoy::Network::ConnectionImpl::onReadReady()+753
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+879
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### 结束本轮 fd 的回调处理
***** elapsed=1032148400: tid=4293,comm=wrk:worker_1: END:EventFired


******* WAKE-ROUND:END Summary *******
***** elapsed=1032166621: tid=4293,comm=wrk:worker_1: sys_enter_epoll_wait, runableDuaration=5101911, tid2epollNrFdReady=1
*** last_epoll_wait_args: epfd=14, events=945353600, maxevents=32, timeout=20 
***************************

### 连接发生 ReadReady/WriteReady 回调 到 ConnectionImpl。开始了本 fd 的新一轮回调处理。
***** elapsed=1042519655: tid=4293,comm=wrk:worker_1: BEGIN:EventFired:FileEventImpl::assignEvents::eventCallback()
FileEventImpl*=0x563d38fb4ee0, fd=42, events=0x26
libevent: EV_READ
libevent: EV_WRITE
libevent: EV_ET


***** elapsed=1042557319: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions16TransportSockets3Tls9SslSocket7doWriteERNS_6Buffer8InstanceEb

        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+0
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### TLS 握手中。之前已经完成 TLS ClientHello 的读取。之前已经发送了 TLS Server Hello。现在读 socket 数据，mTLS 1.3 期待读到 Client certificate
***** elapsed=1042593080: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=5

        readv+77
        Envoy::Network::IoSocketHandleImpl::readv(unsigned long, Envoy::Buffer::RawSlice*, unsigned long)+247
        Envoy::Extensions::TransportSockets::Tls::(anonymous namespace)::io_handle_read(bio_st*, char*, int)+54
        BIO_read+46
        bssl::ssl_read_buffer_extend_to(ssl_st*, unsigned long)+457
        bssl::ssl_handle_open_record(ssl_st*, bool*, bssl::ssl_open_record_t, unsigned long, unsigned char)+222
        bssl::ssl_run_handshake(bssl::SSL_HANDSHAKE*, bool*)+247
        SSL_do_handshake+100
        Envoy::Extensions::TransportSockets::Tls::SslHandshakerImpl::doHandshake()+30
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+56
        Envoy::Network::ConnectionImpl::onWriteReady()+1876
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217


***** elapsed=1042608782: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=1618
        readv+77
...
***** elapsed=1042794016: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=5
        readv+77
...
***** elapsed=1042811526: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=37
        readv+77
...
***** elapsed=1042920930: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=5
        readv+77
...
***** elapsed=1042932840: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=264
        readv+77
...
***** elapsed=1043015006: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=5
        readv+77
...
***** elapsed=1043028533: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=1
        readv+77
...
***** elapsed=1043054194: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=5
        readv+77
...
***** elapsed=1043070435: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=40
        readv+77
...

### TLS 握手中。mTLS 1.3 读完了 Client certificate 后，通过了校验，返回结果。
***** elapsed=1043609771: tid=4293,comm=wrk:worker_1: socket_write, probe=tracepoint:syscalls:sys_exit_writev, fd=42, ret=1890

        writev+77
        Envoy::Network::IoSocketHandleImpl::writev(Envoy::Buffer::RawSlice const*, unsigned long)+263
        Envoy::Extensions::TransportSockets::Tls::(anonymous namespace)::io_handle_write(bio_st*, char const*, int)+48
        BIO_write+46
        bssl::tls_flush_flight(ssl_st*)+306
        bssl::ssl_run_handshake(bssl::SSL_HANDSHAKE*, bool*)+290
        SSL_do_handshake+100
        Envoy::Extensions::TransportSockets::Tls::SslHandshakerImpl::doHandshake()+30
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+56
        Envoy::Network::ConnectionImpl::onWriteReady()+1876
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### TLS 握手成功
***** elapsed=1043684513: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZThn16_N5Envoy10Extensions16TransportSockets3Tls9SslSocket9onSuccessEP6ssl_st

        non-virtual thunk to Envoy::Extensions::TransportSockets::Tls::SslSocket::onSuccess(ssl_st*)+0
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+56
        Envoy::Network::ConnectionImpl::onWriteReady()+1876
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19


### TLS 握手成功
***** elapsed=1043800613: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZThn16_NK5Envoy10Extensions16TransportSockets3Tls9SslSocket10connectionEv

        non-virtual thunk to Envoy::Extensions::TransportSockets::Tls::SslSocket::connection() const+0
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+56
        Envoy::Network::ConnectionImpl::onWriteReady()+1876
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19


***** elapsed=1043817077: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZThn16_NK5Envoy10Extensions16TransportSockets3Tls9SslSocket10connectionEv

        non-virtual thunk to Envoy::Extensions::TransportSockets::Tls::SslSocket::connection() const+0
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+56
        Envoy::Network::ConnectionImpl::onWriteReady()+1876
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19


***** elapsed=1043831361: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions16TransportSockets3Tls9SslSocket6doReadERNS_6Buffer8InstanceE

        Envoy::Extensions::TransportSockets::Tls::SslSocket::doRead(Envoy::Buffer::Instance&)+0
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+879
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217


***** elapsed=1043865858: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=-11

        readv+77
        Envoy::Network::IoSocketHandleImpl::readv(unsigned long, Envoy::Buffer::RawSlice*, unsigned long)+247
        Envoy::Extensions::TransportSockets::Tls::(anonymous namespace)::io_handle_read(bio_st*, char*, int)+54
        BIO_read+46
        bssl::ssl_read_buffer_extend_to(ssl_st*, unsigned long)+457
        bssl::ssl_handle_open_record(ssl_st*, bool*, bssl::ssl_open_record_t, unsigned long, unsigned char)+222
        ssl_read_impl(ssl_st*)+516
        SSL_read+78
        Envoy::Extensions::TransportSockets::Tls::SslSocket::sslReadIntoSlice(Envoy::Buffer::RawSlice&)+66
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doRead(Envoy::Buffer::Instance&)+273
        Envoy::Network::ConnectionImpl::onReadReady()+753
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+879
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217


***** elapsed=1043893834: tid=4293,comm=wrk:worker_1: END:EventFired

******* WAKE-ROUND:END Summary *******
***** elapsed=1043912452: tid=4293,comm=wrk:worker_1: sys_enter_epoll_wait, runableDuaration=1405214, tid2epollNrFdReady=1
*** last_epoll_wait_args: epfd=14, events=945353600, maxevents=32, timeout=100 
***************************


***** elapsed=1044592091: tid=4293,comm=wrk:worker_1: BEGIN:EventFired:FileEventImpl::assignEvents::eventCallback()
FileEventImpl*=0x563d38fb4ee0, fd=42, events=0x26
libevent: EV_READ
libevent: EV_WRITE
libevent: EV_ET


***** elapsed=1044804243: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions16TransportSockets3Tls9SslSocket7doWriteERNS_6Buffer8InstanceEb

        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+0
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217


***** elapsed=1044842831: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions16TransportSockets3Tls9SslSocket6doReadERNS_6Buffer8InstanceE

        Envoy::Extensions::TransportSockets::Tls::SslSocket::doRead(Envoy::Buffer::Instance&)+0
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+879
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### TLS 握手成功后，读取 HTTP 层内容
***** elapsed=1044882265: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=5

        readv+77
        Envoy::Network::IoSocketHandleImpl::readv(unsigned long, Envoy::Buffer::RawSlice*, unsigned long)+247
        Envoy::Extensions::TransportSockets::Tls::(anonymous namespace)::io_handle_read(bio_st*, char*, int)+54
        BIO_read+46
        bssl::ssl_read_buffer_extend_to(ssl_st*, unsigned long)+457
        bssl::ssl_handle_open_record(ssl_st*, bool*, bssl::ssl_open_record_t, unsigned long, unsigned char)+222
        ssl_read_impl(ssl_st*)+516
        SSL_read+78
        Envoy::Extensions::TransportSockets::Tls::SslSocket::sslReadIntoSlice(Envoy::Buffer::RawSlice&)+66
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doRead(Envoy::Buffer::Instance&)+273
        Envoy::Network::ConnectionImpl::onReadReady()+753
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+879
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217


***** elapsed=1044902210: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=1260

        readv+77
...

### 读完本轮 socket 回调的内容
***** elapsed=1044923026: tid=4293,comm=wrk:worker_1: socket_read, probe=tracepoint:syscalls:sys_exit_readv, fd=42, ret=-11

        readv+77
        Envoy::Network::IoSocketHandleImpl::readv(unsigned long, Envoy::Buffer::RawSlice*, unsigned long)+247
        Envoy::Extensions::TransportSockets::Tls::(anonymous namespace)::io_handle_read(bio_st*, char*, int)+54
        BIO_read+46
        bssl::ssl_read_buffer_extend_to(ssl_st*, unsigned long)+457
        bssl::ssl_handle_open_record(ssl_st*, bool*, bssl::ssl_open_record_t, unsigned long, unsigned char)+222
        ssl_read_impl(ssl_st*)+516
        SSL_read+78
        Envoy::Extensions::TransportSockets::Tls::SslSocket::sslReadIntoSlice(Envoy::Buffer::RawSlice&)+66
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doRead(Envoy::Buffer::Instance&)+273
        Envoy::Network::ConnectionImpl::onReadReady()+753
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+879
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### HTTP Filter 认为 已经完整读取了 HTTP 请求。所以取消 ReadReady 事件的监视，只监视 WriteReady，准备写 Response。
***** elapsed=1045093103: tid=4293,comm=wrk:worker_1: sys_enter_epoll_ctl, epfd=14, op=EPOLL_CTL_DEL, fd=42, events=0x80000005
***** elapsed=1045117348: tid=4293,comm=wrk:worker_1: sys_enter_epoll_ctl, epfd=14, op=EPOLL_CTL_ADD, fd=42, events=0x80002004
EPOLL_CTL_ADD/MOD WriteReady(EPOLLOUT)
EPOLL_CTL_ADD/MOD EdgeTrigger

        epoll_ctl+14
        epoll_nochangelist_add+54
        evmap_io_add_+421
        event_add_nolock_+603
        event_add+54
        Envoy::Network::ConnectionImpl::readDisable(bool)+1077
        Envoy::Http::Http1::ServerConnectionImpl::onMessageCompleteBase()+86
        Envoy::Http::Http1::ConnectionImpl::onMessageComplete()+637
        Envoy::Http::Http1::LegacyHttpParserImpl::Impl::Impl(http_parser_type, void*)::{lambda(http_parser*)#3}::__invoke(http_parser*)+31
        http_parser_execute+7959
        Envoy::Http::Http1::LegacyHttpParserImpl::execute(char const*, int)+31
        Envoy::Http::Http1::ConnectionImpl::dispatchSlice(char const*, unsigned long)+52
        Envoy::Http::Http1::ConnectionImpl::dispatch(Envoy::Buffer::Instance&)+1151
        virtual thunk to Envoy::Http::Http1::ConnectionImpl::dispatch(Envoy::Buffer::Instance&)+21
        Envoy::Http::ConnectionManagerImpl::onData(Envoy::Buffer::Instance&, bool)+76
        Envoy::Network::FilterManagerImpl::onContinueReading(Envoy::Network::FilterManagerImpl::ActiveReadFilter*, Envoy::Network::ReadBufferSource&)+303
        Envoy::Network::ConnectionImpl::onReadReady()+1622
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+879
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### 结束本轮 fd 的回调处理
***** elapsed=1045976752: tid=4293,comm=wrk:worker_1: END:EventFired

******* WAKE-ROUND:END Summary *******
***** elapsed=1045997232: tid=4293,comm=wrk:worker_1: sys_enter_epoll_wait, runableDuaration=1425062, tid2epollNrFdReady=1
*** last_epoll_wait_args: epfd=14, events=945353600, maxevents=32, timeout=96 
***************************

### 连接发生 WriteReady 回调 到 ConnectionImpl。开始了本 fd 的新一轮回调处理。
***** elapsed=1046018418: tid=4293,comm=wrk:worker_1: BEGIN:EventFired:FileEventImpl::assignEvents::eventCallback()
FileEventImpl*=0x563d38fb4ee0, fd=42, events=0x24
libevent: EV_WRITE
libevent: EV_ET


### 虽然 socket 是 WriteReady，但可惜现在没有数据可以写入。很可能是因为 envoy 未收到完整的 upstream HTTP Response。
***** elapsed=1046087700: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions16TransportSockets3Tls9SslSocket7doWriteERNS_6Buffer8InstanceEb

        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+0
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### 结束本轮 fd 的回调处理
***** elapsed=1046102162: tid=4293,comm=wrk:worker_1: END:EventFired

******* WAKE-ROUND:END Summary *******
***** elapsed=1046200490: tid=4293,comm=wrk:worker_1: sys_enter_epoll_wait, runableDuaration=183118, tid2epollNrFdReady=2
*** last_epoll_wait_args: epfd=14, events=945353600, maxevents=32, timeout=96 
***************************

### 在没有 downsteam fd 的回调处理的情况下，envoy 修改了 downstream 的监听要求。推断为 envoy 已经收到完整的 upstream HTTP Response，准备去写 downstream 的 HTTP Response 了。
***** elapsed=1047415061: tid=4293,comm=wrk:worker_1: sys_enter_epoll_ctl, epfd=14, op=EPOLL_CTL_DEL, fd=42, events=0x80002004
***** elapsed=1047434533: tid=4293,comm=wrk:worker_1: sys_enter_epoll_ctl, epfd=14, op=EPOLL_CTL_ADD, fd=42, events=0x80000005
EPOLL_CTL_ADD/MOD ReadReady(EPOLLIN)
EPOLL_CTL_ADD/MOD WriteReady(EPOLLOUT)
EPOLL_CTL_ADD/MOD EdgeTrigger

        epoll_ctl+14
        epoll_nochangelist_add+54
        evmap_io_add_+421
        event_add_nolock_+603
        event_add+54
        Envoy::Network::ConnectionImpl::readDisable(bool)+938
        Envoy::Http::Http1::StreamEncoderImpl::~StreamEncoderImpl()+112
        non-virtual thunk to Envoy::Http::Http1::ServerConnectionImpl::onEncodeComplete()+54
        Envoy::Http::Http1::StreamEncoderImpl::endEncode()+166
        Envoy::Http::Http1::StreamEncoderImpl::encodeData(Envoy::Buffer::Instance&, bool)+340
        Envoy::Http::ConnectionManagerImpl::ActiveStream::encodeData(Envoy::Buffer::Instance&, bool)+679
        Envoy::Http::FilterManager::encodeData(Envoy::Http::ActiveStreamEncoderFilter*, Envoy::Buffer::Instance&, bool, Envoy::Http::FilterManager::FilterIterationStartState)+2138
        Envoy::Router::UpstreamRequest::decodeData(Envoy::Buffer::Instance&, bool)+230
        Envoy::Http::ResponseDecoderWrapper::decodeData(Envoy::Buffer::Instance&, bool)+59
        Envoy::Http::ResponseDecoderWrapper::decodeData(Envoy::Buffer::Instance&, bool)+59
        Envoy::Http::Http1::ClientConnectionImpl::onMessageCompleteBase()+619
        Envoy::Http::Http1::ConnectionImpl::onMessageComplete()+637
        Envoy::Http::Http1::LegacyHttpParserImpl::Impl::Impl(http_parser_type, void*)::{lambda(http_parser*)#3}::__invoke(http_parser*)+31
        http_parser_execute+7705
        Envoy::Http::Http1::LegacyHttpParserImpl::execute(char const*, int)+31
        Envoy::Http::Http1::ConnectionImpl::dispatchSlice(char const*, unsigned long)+52
        Envoy::Http::Http1::ConnectionImpl::dispatch(Envoy::Buffer::Instance&)+1151
        Envoy::Http::Http1::ClientConnectionImpl::dispatch(Envoy::Buffer::Instance&)+29
        Envoy::Http::CodecClient::onData(Envoy::Buffer::Instance&)+48
        Envoy::Http::CodecClient::CodecReadFilter::onData(Envoy::Buffer::Instance&, bool)+21
        Envoy::Network::FilterManagerImpl::onContinueReading(Envoy::Network::FilterManagerImpl::ActiveReadFilter*, Envoy::Network::ReadBufferSource&)+303
        Envoy::Network::ConnectionImpl::onReadReady()+1622
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+879
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92

### 连接发生 WriteReady 回调 到 ConnectionImpl。开始了本 fd 的新一轮回调处理。
***** elapsed=1047624495: tid=4293,comm=wrk:worker_1: BEGIN:EventFired:FileEventImpl::assignEvents::eventCallback()
FileEventImpl*=0x563d38fb4ee0, fd=42, events=0x24
libevent: EV_WRITE
libevent: EV_ET


***** elapsed=1047648141: tid=4293,comm=wrk:worker_1: SslSocket*, probe=uprobe:/proc/3620/root/usr/local/bin/envoy:_ZN5Envoy10Extensions16TransportSockets3Tls9SslSocket7doWriteERNS_6Buffer8InstanceEb

        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+0
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### 写入 HTTP Response
***** elapsed=1047767982: tid=4293,comm=wrk:worker_1: socket_write, probe=tracepoint:syscalls:sys_exit_writev, fd=42, ret=5377

        writev+77
        Envoy::Network::IoSocketHandleImpl::writev(Envoy::Buffer::RawSlice const*, unsigned long)+263
        Envoy::Extensions::TransportSockets::Tls::(anonymous namespace)::io_handle_write(bio_st*, char const*, int)+48
        BIO_write+46
        bssl::ssl_write_buffer_flush(ssl_st*)+211
        bssl::do_tls_write(ssl_st*, int, unsigned char const*, unsigned int)+137
        bssl::tls_write_app_data(ssl_st*, bool*, unsigned char const*, int)+285
        SSL_write+265
        Envoy::Extensions::TransportSockets::Tls::SslSocket::doWrite(Envoy::Buffer::Instance&, bool)+209
        Envoy::Network::ConnectionImpl::onWriteReady()+1876
        Envoy::Network::ConnectionImpl::onFileEvent(unsigned int)+818
        std::__1::__function::__func<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5, std::__1::allocator<Envoy::Event::DispatcherImpl::createFileEvent(int, std::__1::function<void (unsigned int)>, Envoy::Event::FileTriggerType, unsigned int)::$_5>, void (unsigned int)>::operator()(unsigned int&&)+65
        Envoy::Event::FileEventImpl::assignEvents(unsigned int, event_base*)::$_1::__invoke(int, short, void*)+92
        0x7fffffffe000
        event_base_loop+1953
        Envoy::Server::WorkerImpl::threadRoutine(Envoy::Server::GuardDog&, std::__1::function<void ()> const&)+621
        Envoy::Thread::ThreadImplPosix::ThreadImplPosix(std::__1::function<void ()>, absl::optional<Envoy::Thread::Options> const&)::{lambda(void*)#1}::__invoke(void*)+19
        start_thread+217

### 结束本轮 fd 的回调处理
***** elapsed=1047783043: tid=4293,comm=wrk:worker_1: END:EventFired

******* WAKE-ROUND:END Summary *******
***** elapsed=1047792110: tid=4293,comm=wrk:worker_1: sys_enter_epoll_wait, runableDuaration=173473, tid2epollNrFdReady=2
*** last_epoll_wait_args: epfd=14, events=945353600, maxevents=32, timeout=92 
***************************

bpftrace 程序脚本就不贴出来了，有兴趣看这：
https://github.com/labilezhu/pub-diy/blob/main/low-tec/trace/trace-istio/trace-istio-part3/trace-envoy-accept-flow-ssl.bt

结尾

或者上面有很多未尽道明之处，请见谅。一个是时间实在有限，一个是我觉得能深入一行一行读完全文的同学，都是老司机了，多说无益。谢谢观看。

附录

术语

• fd： 是 file descriptor 的缩写，中文叫文件描述符（Windows 编程过来的同学叫：句柄 handle）。一个 socket 可以对应于多个 fd。不同的线程可以在不同的 fd 上 listen 同一个 socket。操作系统负责新连接的负载均衡（尽管做得不太好）。