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

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

阿里云负载均衡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状态码的实践

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秒多,也许正是因为长时间的等待导致用户停止了下载任务。

原文链接

相关推荐