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总是那么几个值，直觉告诉我们不大对劲：

一个客户端的请求从最初的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，算法用如下决策树来表达：

当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：

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

HTTP状态码说明了什么
408 Request Timeout
现象
客户端请求部署在SLB上的服务，但经常出现网络超时情况。

排查过程
首先用SQL统计是否有异常的状态码：

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

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

关于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。这个时候可以认为，客户端问题导致网络超时的可能性是很大了。

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

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

排查过程
经典开局，先看异常状态码分布，但这次我们怀疑是499导致的：

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

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

原文链接