注,原文来自 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 之 http filter
  • Part 5: eBPF 跟踪 Istio/Envoy 之 http router
  • Part 6: 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/...

这也是为何,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 FilterNetwork 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 监听的状况如下:

$ 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 ListenervirtualInbound 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 程序:

git clone https://github.com/labilezhu/pub-diycd ./pub-diy/low-tec/trace/trace-istio/trace-istio-part3export SCRIPT_HOME=`pwd`export bpftrace_image=cndt-bcc-ubexport PID=4283docker 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 。

# 须要重启 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/...

以下是我精简和退出注解的后果:

##### 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/4096sys_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_8080comm: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 的 sockoptcomm: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/...

#!usr/bin/bpftrace/*IMPORT-ENV: $ENVOY_PIDargs: $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_setsockopt1.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 监听的 FDcat /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/runnableRoundcat /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 相干的 Mapcat /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);}

结尾

或者下面有很多未尽道明之处,请见谅。一个是工夫切实无限,一个是我感觉能深刻一行一行读完全文的同学,都是老司机了,多说无益。谢谢观看。

附录

术语

  • fd: 是 file descriptor 的缩写,中文叫文件描述符(Windows 编程过去的同学叫:句柄 handle)。一个 socket 能够对应于多个 fd。不同的线程能够在不同的 fd 上 listen 同一个 socket。操作系统负责新连贯的负载平衡(只管做得不太好)。