SLB访问日志分析:基于客户端来源和HTTP状态码的实践

阿里云负载均衡SLB可以对多台云服务器(ECS)进行流量分发,支持TCP的四层负载均衡和基于HTTP/HTTPS的七层负载均衡。使用SLB可以降低单台ECS异常时对业务的冲击,提升系统可用性。同时,结合弹性伸缩服务(ESS)动态扩容、缩容后端服务器可以快速应对业务流量的变化。

SLB七层访问日志内容丰富,提供近30个字段,例如:收到请求的时间、客户端的IP地址、处理Latency、请求URI、后端RealServer(阿里云ECS)地址、返回状态码等。在您开启SLB七层访问日志功能后,SLB会记录对应实例上所有访问日志到日志服务。本文以两个主题向大家介绍如何通过日志服务来发掘SLB访问日志背后蕴含的一些价值。

请求从哪里来

这是一个关于client_ip的问题,直接看访问日志的client_ip字段就可以回答。但有时会发现client_ip总是那么几个值,直觉告诉我们不大对劲:

SLB访问日志分析:基于客户端来源和HTTP状态码的实践

一个客户端的请求从最初的ip到SLB负载均衡,如果不经过代理,那么client_ip记录的就是原始客户端ip。而假如请求经过proxy多次转发,这种情况下访问日志记录的client_ip就不能真实反应请求来源了。

好在SLB访问日志中有另两个字段可以帮助我们解决真实client_ip问题:

  • http_x_forwarded_for,取自HTTP扩展头X-Forwarded-For字段,是RFC7293标准。假设客户端在client_0发出请求,到达服务端之前依次经过了三个代理proxy_1、proxy_2、proxy_3,其中proxy_3直连负载均衡器,那么proxy_3会在X-Forwarded-For上追加proxy_2的ip表示是在替proxy_2转发请求。这样多层级联后形成一个用逗号连接的字符串"client_0_ip,proxy_1_ip,proxy_2_ip",字符串中的第一个即是原客户端ip。
  • http_x_real_ip,取自HTTP自定义头X-Real-IP字段,非正式标准但在业内普遍使用。在各层代理始终坚持记录原始客户端ip的前提下,这是最方便且正确的取值。

值得注意的是,X-Forwarded-For和X-Real-IP字段都有可能出现不准确的情况,感兴趣的同学可以读一下这篇文章:HTTP请求头中的X-Forwarded-For

本文按照X-Real-IP优先策略计算真实的请求来源ip,算法用如下决策树来表达:

SLB访问日志分析:基于客户端来源和HTTP状态码的实践

当http_x_forwarded_for、http_x_real_ip字段取值为字符串"-"时,表示该字段值不是有效内容。那么通过SQL的case/when语法把上图的计算方法翻译如下:

* | select (case
        when http_x_real_ip = '-' then (case
                                        when http_x_forwarded_for = '-' then client_ip
                                        when split_part(http_x_forwarded_for, ',', 1)  = '-' then client_ip
                                        else split_part(http_x_forwarded_for, ',', 1) 
                                        end)
        else http_x_real_ip
        end) as real_client_ip

real_client_ip是通过算法得到的优化版真实客户端ip:

SLB访问日志分析:基于客户端来源和HTTP状态码的实践

在real_client_ip基础上,可以使用日志服务IP地理函数计算访问来源的地理(国家、省市、运营商、经纬度)信息。例如按照省维度统计PV分布:

SLB访问日志分析:基于客户端来源和HTTP状态码的实践

基于此的另一个例子,统计真实用户ip下带宽流量、pv:

* | select (case when http_x_real_ip = '-' then (case when http_x_forwarded_for = '-' then client_ip when split_part(http_x_forwarded_for, ',', 1)  = '-' then client_ip else split_part(http_x_forwarded_for, ',', 1) end) else http_x_real_ip end) as real_client_ip, sum(request_length) as request_bytes, sum(body_bytes_sent) as response_bytes, count(1) as pv group by real_client_ip

HTTP状态码说明了什么

408 Request Timeout

现象

客户端请求部署在SLB上的服务,但经常出现网络超时情况。

排查过程

首先用SQL统计是否有异常的状态码:

not (status : 200) | select status, count(*) as pv group by status order by pv desc

分析发现在最近15分钟的访问日志中有些408返回的请求:

SLB访问日志分析:基于客户端来源和HTTP状态码的实践

关于408状态码,它表示服务端在一定时间内没有收到完整的请求,这个时候服务端决定不再等待,在响应中将Connection首部值设置为close并主动关闭连接。

发生408错误的时候,表现为Request Timeout。最大可能的两个原因有:客户端没有在超时时间内把数据包发到服务端;或者是因为服务端负载很重,没有及时处理请求。如果通过监控可以排除服务端负载原因,那么可以将更多关注点转移到客户端身上。

统计408状态的client_ip来源:

status : 408 | select client_ip, count(*) as pv group by client_ip order by pv desc

如果client_ip集中在几个特定来源上,那么,个别客户端网络流量导致问题的可能性就比较大。

同时,查看408状态码的日志发现,异常请求的upstream_addr、upstream_status都没有记录,这说明请求没有到达后端real server。这个时候可以认为,客户端问题导致网络超时的可能性是很大了。

SLB访问日志分析:基于客户端来源和HTTP状态码的实践

接下来,就请到客户端上查看网路监控或抓包调查吧。

499 Client Closed Request

现象

SLB负载均衡上的流量出现下跌,同时后端服务器上没有看到5xx错误。

排查过程

经典开局,先看异常状态码分布,但这次我们怀疑是499导致的:

SLB访问日志分析:基于客户端来源和HTTP状态码的实践

499状态码表示服务端Nginx正在处理请求过程中,客户端主动关闭了连接。

通过异常的访问日志加以印证,upstream_addr记录了请求在real server上进行处理,但是没有记录响应的后端状态码upstream_status,说明后端服务器没有完成请求的处理。并且,整个请求的处理时间request_time用了10秒多,也许正是因为长时间的等待导致用户停止了下载任务。

更多关于SLB七层访问日志分析

  • 文档

负载均衡7层访问日志功能

SLB访问日志分析-文档

SLB访问日志分析-视频

  • 云栖文章

新功能:阿里云负载均衡支持访问日志功能

用好SLB访问日志,做实时可视化分析

上一篇:VSCode代码片段Snippets的使用(添加Copyright、生成Vue代码片段等)


下一篇:eclipse(4.9)通过代理更新软件的问题!