--- title: "8. 日志记录" linkTitle: "8. 日志记录" weight: 190 description: "日志级别、格式、配置文件、时间戳、捕获、状态及示例" icon: fa-solid fa-file-lines module: [HAPROXY] categories: [任务] aliases: - /haproxy/configuration/logging/ - /docs/haproxy/configuration/logging/ - /haproxy/configuration-logging/ upstream_link: "https://docs.haproxy.org/3.4/configuration.html" upstream_name: "HAProxy 3.4 Configuration Manual" upstream_ref: "v3.4.4, chapter 8" --- 本文的强项之一无疑是其精确的日志记录。它可能为这类产品提供了最详尽的信息级别，这对排查复杂环境中的问题至关重要。日志中提供的标准信息包括客户端端口、TCP/HTTP 状态定时器、流在终止时的精确状态以及精确的终止原因，关于将流量导向服务器的决策信息，当然还包括捕获任意头字段的能力。 为提升系统管理能力的响应速度，该功能可清晰呈现所遇到的内部与外部问题，且可同时将日志发送至多个目标，并针对不同级别设置过滤器： - 全局进程级日志（系统错误、启动/停止等） - 每个实例的系统和内部错误（资源不足、缺陷等） - 每个实例的外部问题（服务器上下线、连接数上限） - 每个实例的活动日志（客户端连接），无论是在建立阶段还是终止阶段 - 按请求控制日志级别，例如：http-request set-log-level silent if sensitive_request 将不同级别的日志分发至不同的日志服务器，可使多个生产团队协同工作，并尽快解决各自的问题。例如，系统团队可监控系统级错误，应用团队可实时监控其服务器的启停状态，安全团队则可延迟一小时分析活动日志。 ## 8.1. 日志级别 {#section-8-1} TCP 和 HTTP 连接可记录包括日期、时间、源 IP 地址、目标地址、连接持续时间、响应时间、HTTP 请求、HTTP 返回码、传输字节数、流结束条件，甚至交换的 Cookie 值等信息。例如，用于追踪特定用户的问题。所有消息可发送至最多两个 syslog 服务器。有关日志设施的更多信息，请参阅 "log" 关键字在 [第 4.2 节](/zh/docs/haproxy/proxies/#section-4-2) 中的说明。 ## 8.2. 日志格式 {#section-8-2} HAProxy 支持 5 种日志格式。这些格式之间存在若干共用字段，将在后续段落中详细说明。部分字段可能因配置中特定选项的指示而略有差异。支持的格式如下： - 默认格式，极为简单，极少使用。该格式仅在连接被接受的瞬间提供关于入站连接的极简信息：源 IP:端口、目标 IP:端口和前端名称。此模式最终将被移除，因此不会进行详细描述。 - TCP 格式，功能更强大。当在前端配置了 "option tcplog" 时，该格式被启用。HAProxy 通常会在连接终止后才进行日志记录。该格式提供更丰富的信息，例如计时器、连接数、队列大小等……推荐用于纯 TCP 代理。 - HTTP 格式，适用于 HTTP 代理的最先进格式。当在前端启用 "option httplog" 时，该格式被激活。它提供与 TCP 格式相同的信息，并增加了一些 HTTP 特有的字段，例如请求、状态码，以及头和 Cookie 的捕获。建议对 HTTP 代理使用此格式。 - CLF HTTP 格式，与 HTTP 格式等效，但字段排列顺序与 CLF 格式一致。在此模式下，所有计时器、捕获、标志等均在通用字段结束后按字段逐一出现，顺序与标准 HTTP 格式中一致。 - 自定义日志格式，可定义自有日志行。 后续段落将深入探讨每种格式的详细信息。格式规范将按 "field" 进行。除非另有说明，字段是指由任意数量空格分隔的文本片段。由于 syslog 服务器可能在行首插入字段，因此始终假设首个字段为包含进程名称和标识符的字段。 请注意：由于日志行可能非常长，下述各段中的日志示例可能会被拆分为多行。示例日志行将以三个右尖括号（'>>>'）开头，每当一条日志被拆分为多行时，非末尾行将以反斜杠（\）结尾，下一行将缩进两个字符。 ### 8.2.1. 默认日志格式 {#section-8-2-1} 此格式在未设置特定选项时使用。连接一旦被接受，日志即被发出。请注意，当前此格式是唯一记录请求目标 IP 和端口的格式。 示例： ```shell listen www mode http log global server srv1 127.0.0.1:8000 >>> Feb 6 12:12:09 localhost \ haproxy[14385]: Connect from 10.0.1.2:33312 to 10.0.3.31:8012 \ (www/HTTP) ``` 字段格式 从上例提取 1 process_name '[' pid ']:' HAProxy[14385]: 2 'Connect from' Connect from 3 source_ip ':' source_port 10.0.1.2:33312 4 'to' to 5 destination_ip ':' destination_port 10.0.3.31:8012 6 '(' frontend_name '/' mode ')' (www/HTTP) 详细字段说明： - "source_ip" 是发起连接的客户端的 IP 地址。 - "source_port" 是发起连接的客户端的 TCP 端口。 - "destination_ip" 是客户端连接的目标 IP 地址。 - "destination_port" 是客户端连接的目标 TCP 端口。 - "frontend_name" 是接收并处理该连接的前端（或监听器）的名称。 - "mode 是前端当前运行的模式（TCP 或 HTTP）。 若为 Unix 套接字，源地址和目标地址将标记为“unix:”，端口反映接受连接的套接字的内部 ID（与统计信息中报告的 ID 相同）。 建议新安装时不要使用此已弃用的格式，因为它最终将被移除。 ### 8.2.2. TCP 日志格式 {#section-8-2-2} 当在前端中指定 "option tcplog" 时，使用 TCP 格式。该格式是纯 TCP 代理的推荐格式，可提供大量用于故障排查的宝贵信息。由于此格式包含计时器和字节数统计，日志通常在会话结束时输出。若指定 "option logasap"，则可在会话早期输出日志，这在远程终端等具有长会话的环境中尤为合理。匹配 "monitor" 规则的会话将永不记录日志。也可在前端中指定 "option dontlognull"，以避免在客户端与服务器之间未交换任何数据的会话中输出日志。若在前端中指定 "option dontlog-normal"，则正常连接将不会被记录。 TCP 日志格式在内部被声明为基于以下确切字符串的自定义日志格式，该字符串也可用作扩展格式的基础（如需）。此外，可使用 HAPROXY_TCP_LOG_FMT 变量替代。请参阅 [第 8.2.6 节](/zh/docs/haproxy/configuration-logging/#section-8-2-6)“自定义日志格式”，了解如何使用。 ```shell # strict equivalent of "option tcplog" log-format "%ci:%cp [%t] %ft %b/%s %Tw/%Tc/%Tt %B %ts \ %ac/%fc/%bc/%sc/%rc %sq/%bq" # or using the HAPROXY_TCP_LOG_FMT variable log-format "${HAPROXY_TCP_LOG_FMT}" ``` 且 CLF 日志格式在内部被声明为基于此确切字符串的自定义日志格式： ```shell # strict equivalent of "option tcplog clf" log-format "%{Q}o %{-Q}ci - - [%T] \"TCP \" 000 %B \"\" \"\" %cp \ %ms %ft %b %s %Th %Tw %Tc %Tt %U %ts-- %ac %fc %bc \ %sc %rc %sq %bq \"\" \"\" " ``` 部分字段可能因某些配置选项的不同而略有差异，这些字段在下方字段名后以星号（\*）标记。 示例： ```shell frontend fnt mode tcp option tcplog log global default_backend bck backend bck server srv1 127.0.0.1:8000 >>> Feb 6 12:12:56 localhost \ haproxy[14387]: 10.0.1.2:33313 [06/Feb/2009:12:12:51.443] fnt \ bck/srv1 0/0/5007 212 -- 0/0/0/0/3 0/0 ``` 字段格式 从上例中提取 1 process_name '[' pid ']:' HAProxy[14387]: 2 client_ip ':' client_port 10.0.1.2:33313 3 '[' accept_date ']' [06/Feb/2009:12:12:51.443] 4 frontend_name fnt 5 backend_name '/' server_name bck/srv1 6 Tw '/' Tc '/' Tt\* 0/0/5007 7 bytes_read\* 212 8 termination_state -- 9 actconn '/' feconn '/' beconn '/' srv_conn '/' retries\* 0/0/0/0/3 10 srv_queue '/' backend_queue 0/0 详细字段说明： - "client_ip" 是发起 TCP 连接至 HAProxy 的客户端 IP 地址。如果连接是在 Unix 套接字上接受的，则 IP 地址将被替换为单词 "unix"。请注意，当连接在配置了 "accept-proxy" 的套接字上接受，且正确使用了 PROXY 协议，或在配置了 "accept-netscaler-cip" 的套接字上接受，且正确使用了 NetScaler 客户端 IP 插入协议时，日志将反映转发连接的信息。 - "client_port" 是发起连接的客户端的 TCP 端口。如果连接是在 Unix 套接字上接受的，则端口将被接受该连接的套接字 ID 替代，该 ID 同样会在统计信息接口中报告。 - "accept_date" 是 HAProxy 接收到连接的确切日期（若系统队列中存在延迟，该日期可能与网络上观察到的日期略有差异）。该日期通常与上游防火墙日志中出现的日期一致。在 HTTP 模式下，accept_date 字段将在连接准备好接收新请求的时刻重置（HTTP/1 为上一个响应结束时，HTTP/2 为上一个请求结束后立即）。 - "frontend_name" 是接收并处理该连接的前端（或监听器）的名称。 - "backend_name" 是用于管理与服务器连接的后端（或监听器）的名称。若未应用切换规则，其值将与前端相同，这对 TCP 应用程序而言较为常见。 - "server_name" 是连接最后被发送至的服务器名称，若发生连接错误并触发重分派，该名称可能与首个服务器不同。请注意，该服务器属于处理请求的后端。若连接在到达服务器前被中止，则显示为 "``" 而非服务器名称。 - "Tw" 是连接在各个队列中等待的总时间，单位为毫秒。如果连接在进入队列前被中止，则该值可能为 "-1"。更多详情请参见下方 "Timers"。 - "Tc" 是连接至最终服务器期间花费的总时间（单位：毫秒），包含重试时间。若在建立连接前连接被中止，则该值可能为 "-1"。更多详情请参见下方 "Timers"。 - "Tt" 是从 accept 到最后一次关闭之间经过的总时间，单位为毫秒，涵盖所有可能的处理过程。有一个例外情况：若指定了 "option logasap"，则时间计数会在日志发出时停止。此时，数值前会附加一个 "+" 号，表示最终值将更大。有关更多详情，请参见下方 "Timers"。 - "bytes_read" 是在记录日志时，从服务器传输到客户端的总字节数。若指定了 "option logasap"，该值前会加上 "+" 号，表示最终值可能更大。请注意，该值为 64 位计数器，因此日志分析工具必须能够处理该值而不会溢出。 - "termination_state" 是会话结束时所处的条件。这表示会话状态、导致会话终止的一方以及终止原因（超时、错误等）。正常标志应为 "--"，表示会话由任一端关闭，且缓冲区中无剩余数据。详见下文“断开连接时的流状态”。 - "actconn" 是会话记录时进程的并发连接总数。该值可用于检测是否达到每进程的系统限制。例如，当多个连接错误发生时，若 actconn 接近 512，很可能系统将进程的文件描述符使用上限设为 1024，且所有文件描述符均已耗尽。请参阅 [第 3 节](/zh/docs/haproxy/global/)“全局段”以了解如何调整系统设置。 - "feconn" 是会话记录时前端的并发连接总数。该值可用于估算维持高负载所需的资源量，并检测前端的 "maxconn" 是否已达到。当该值出现大幅跃升时，通常是因为后端服务器发生拥塞，但有时也可能由拒绝服务攻击引起。 - "beconn" 是会话记录时后端处理的并发连接总数。该数值包括后端服务器上当前活跃的并发连接总数，以及队列中等待的连接数量。可用于估算支持特定应用高负载所需的额外服务器数量。当该数值出现大幅跃升时，通常表明后端服务器存在拥塞，但有时也可能由拒绝服务攻击引起。 - "srv_conn" 是会话记录时服务器上仍处于活跃状态的并发连接总数。该值绝不会超过服务器配置的 "maxconn" 参数。若该值经常接近或等于服务器的 "maxconn"，说明流量控制参与程度较高，表明服务器的 maxconn 值可能过低，或用于处理负载的服务器数量不足，无法实现最优响应时间。当仅有一个服务器的 "srv_conn" 值较高时，通常意味着该服务器存在某些问题，导致连接处理时间长于其他服务器。 - "retries" 是该会话在尝试连接服务器时经历的连接重试次数。通常情况下应为零，除非服务器在连接尝试的瞬间正在停止。频繁重试通常表明 HAProxy 与服务器之间存在网络问题，或服务器端系统队列配置不当，导致无法将新连接加入队列。该字段可选择性地以加号 '+' 作为前缀，表示在初始服务器达到最大重试次数后，会话已发生重分派。此时日志中显示的服务器名称为重分派目标服务器，而非首次尝试的服务器，尽管在使用哈希算法等情况下两者可能相同。因此，一般规则是：当重试次数前出现 '+' 符号时，该次数不应归因于日志中记录的服务器。 - "srv_queue" 是在当前请求之前，服务器队列中已处理的请求数量。当请求未经过服务器队列时，该值为 0。通过将请求在队列中等待的时间除以队列中的请求数量，可估算服务器响应时间的近似值。请注意，若会话发生重分派并经过两个服务器队列，其位置将累加。除非发生重分派，否则请求不应同时经过服务器队列和后端队列。 - "backend_queue" 是在当前请求之前，后端全局队列中已处理的请求数量。当请求未经过全局队列时，该值为 0。该值可用于估算平均队列长度，除以服务器的 "maxconn" 参数后，即可得出缺失服务器的数量。请注意，若会话发生重分派，请求可能两次经过后端队列，此时两个位置将累加。除非发生重分派，否则请求不应同时经过服务器队列和后端队列。 ### 8.2.3. HTTP 日志格式 {#section-8-2-3} 本文档中的 HTTP 格式最为完整，且最适用于 HTTP 代理。当在前端中指定 "option httplog" 时启用该格式。它提供的信息级别与 TCP 格式相同，同时具备 HTTP 协议特有的附加功能。与 TCP 格式类似，日志通常在流结束时发出，除非指定了 "option logasap"，这通常仅对下载站点有意义。匹配 "monitor" 规则的流将永远不会被记录。还可以通过在前端中指定 "option dontlognull"，避免记录客户端未发送任何数据的流。若在前端中指定 "option dontlog-normal"，则成功连接将不会被记录。 HTTP 日志格式在内部被声明为基于以下确切字符串的自定义日志格式，该字符串也可用作扩展格式的基础（如需）。此外，可使用 HAPROXY_HTTP_LOG_FMT 变量替代。请参阅 [第 8.2.6 节](/zh/docs/haproxy/configuration-logging/#section-8-2-6)“自定义日志格式”，了解如何使用。 ```shell # strict equivalent of "option httplog" log-format "%ci:%cp [%tr] %ft %b/%s %TR/%Tw/%Tc/%Tr/%Ta %ST %B %CC \ %CS %tsc %ac/%fc/%bc/%sc/%rc %sq/%bq %hr %hs %{+Q}r" # or using the HAPROXY_HTTP_LOG_FMT variable log-format "${HAPROXY_HTTP_LOG_FMT}" ``` 且 CLF 日志格式在内部被声明为基于此确切字符串的自定义日志格式： ```shell # strict equivalent of "option httplog clf" log-format "%{+Q}o %{-Q}ci - - [%trg] %r %ST %B \"\" \"\" %cp \ %ms %ft %b %s %TR %Tw %Tc %Tr %Ta %tsc %ac %fc \ %bc %sc %rc %sq %bq %CC %CS %hrl %hsl" ``` 大多数字段与 TCP 日志共享，部分字段有所不同。某些字段的值可能因配置选项的不同而略有差异。这些字段在下方字段名后以星号（'*'）标记。 示例： ```shell frontend http-in mode http option httplog log global default_backend bck backend static server srv1 127.0.0.1:8000 >>> Feb 6 12:14:14 localhost \ haproxy[14389]: 10.0.1.2:33317 [06/Feb/2009:12:14:14.655] http-in \ static/srv1 10/0/30/69/109 200 2750 - - ---- 1/1/1/1/0 0/0 {1wt.eu} \ {} "GET /index.html HTTP/1.1" ``` 字段格式 从上例中提取 1 process_name '[' pid ']:' HAProxy[14389]: 2 client_ip ':' client_port 10.0.1.2:33317 3 '[' request_date ']' [06/Feb/2009:12:14:14.655] 4 frontend_name http-in 5 backend_name '/' server_name static/srv1 6 TR '/' Tw '/' Tc '/' Tr '/' Ta\* 10/0/30/69/109 7 status_code 200 8 bytes_read\* 2750 9 captured_request_cookie - 10 captured_response_cookie - 11 termination_state ---- 12 actconn '/' feconn '/' beconn '/' srv_conn '/' retries\* 1/1/1/1/0 13 srv_queue '/' backend_queue 0/0 14 '{' captured_request_headers\* '}' {HAProxy.1wt.eu} 15 '{' captured_response_headers\* '}' {} 16 '"' http_request '"' "GET /index.html HTTP/1.1" 详细字段说明： - "client_ip" 是发起 TCP 连接至 HAProxy 的客户端 IP 地址。如果连接是在 Unix 套接字上接受的，则 IP 地址将被替换为单词 "unix"。请注意，当连接在配置了 "accept-proxy" 的套接字上接受，且正确使用了 PROXY 协议，或在配置了 "accept-netscaler-cip" 的套接字上接受，且正确使用了 NetScaler 客户端 IP 插入协议时，日志将反映转发连接的信息。 - "client_port" 是发起连接的客户端的 TCP 端口。如果连接是在 Unix 套接字上接受的，则端口将被接受该连接的套接字 ID 替代，该 ID 同样会在统计信息接口中报告。 - "request_date" 是 HAProxy 收到 HTTP 请求第一个字节的确切时间（日志字段 %tr）。 - "frontend_name" 是接收并处理该连接的前端（或监听器）的名称。 - "backend_name" 是用于管理与服务器连接的后端（或监听器）的名称。若未应用切换规则，该名称将与前端相同。 - "server_name" 是连接最后被发送至的服务器名称，若发生连接错误并触发重分派，该名称可能与首个服务器不同。请注意，该服务器属于处理请求的后端。若请求在到达服务器前被中止，则显示为 "``" 而非服务器名称。若请求被统计信息子系统拦截，则显示为 "``"。 - "TR" 是在接收到首个字节后，等待客户端发送完整 HTTP 请求（不包含正文）所花费的总时间，单位为毫秒。若连接在完整请求接收完成前被中止，或接收到无效请求，则该值可能为 "-1"。该值通常应非常小，因为请求通常可容纳于单个数据包中。此处时间过长通常表明客户端与 HAProxy 之间存在网络问题，或请求为手动输入。详见 [第 8.4 节](/zh/docs/haproxy/configuration-logging/#section-8-4) “时间事件” 获取更多详情。 - "Tw" 是连接在各个队列中等待的总时间，单位为毫秒。如果连接在进入队列前被中止，则该值可能为 "-1"。有关更多详细信息，请参见 [第 8.4 节](/zh/docs/haproxy/configuration-logging/#section-8-4) “时间事件”。 - "Tc" 是连接至最终服务器期间花费的总时间（单位：毫秒），包含重试时间。若请求在建立连接前被中止，则该值可能为 "-1"。更多详情请参见 [第 8.4 节](/zh/docs/haproxy/configuration-logging/#section-8-4) “时间事件”。 - "Tr" 是客户端等待服务器发送完整 HTTP 响应所花费的总时间（单位：毫秒），不包含数据传输时间。若请求在完整响应接收前被中止，则该值可能为 "-1"。该时间通常与服务器处理请求的时间一致，但可能受客户端向服务器发送的数据量影响。在 "GET" 请求中，若该值过大，通常表明服务器过载。更多详情请参见 [第 8.4 节](/zh/docs/haproxy/configuration-logging/#section-8-4)“时间事件”。 - "Ta" 是请求在 HAProxy 中保持活跃的时间，单位为毫秒，表示从接收到请求的第一个字节到发送响应的最后一个字节所经过的总时间。该时间涵盖所有可能的处理过程，但不包括握手时间（参见 Th）和空闲时间（参见 Ti）。有一个例外情况：若指定了 "option logasap"，则时间计数将在日志发出时停止。此时，数值前会附加一个 "+" 号，表示最终结果将更大。详情请参见 [第 8.4 节](/zh/docs/haproxy/configuration-logging/#section-8-4) “时间事件”。 - "status_code" 是 HAProxy 返回给客户端的 HTTP 状态码。该状态码通常由服务器设置，但在服务器无法访问或其响应被 HAProxy 阻断时，也可能由 HAProxy 设置。 - "bytes_read" 是在记录日志时向客户端传输的总字节数。该数值包含 HTTP 头。若指定 "option logasap"，此值前会附加 "+" 号，表示最终值可能更大。请注意，该数值为 64 位计数器，因此日志分析工具必须能够处理该数值而不会溢出。 - "captured_request_cookie" 是一个可选的“name=value”条目，表示客户端在请求中携带了该 Cookie。Cookie 名称及其最大长度由前端配置中的“capture cookie”语句定义。当该选项未设置时，该字段为单个连字符（'-'）。仅可捕获一个 Cookie，通常用于跟踪客户端与服务器之间的会话 ID 交换，以检测因应用程序缺陷导致的客户端会话交叉问题。详情请参阅下文“捕获 HTTP 头和 Cookie”段。 - "captured_response_cookie" 是一个可选的“name=value”条目，表示服务器在其响应中返回了 Cookie。Cookie 名称及其最大长度由前端配置中的“capture cookie”语句定义。当该选项未设置时，该字段为单个连字符（'-'）。仅可捕获一个 Cookie，通常用于跟踪客户端与服务器之间的会话 ID 交换，以检测因应用程序缺陷导致的客户端会话交叉问题。详情请参阅下方“捕获 HTTP 头和 Cookie”段。 - "termination_state" 是流结束时所处的条件。这表示流状态，哪一端导致流结束，以及原因（超时、错误等），类似于 TCP 日志，并包含最后两个字符中关于 Cookie 持久化操作的信息。正常标志应以 "--" 开头，表示流由任一端关闭，且缓冲区中无剩余数据。详见下文“断开连接时的流状态”获取更多详情。 - "actconn" 是流被记录时进程的并发连接总数。 该值可用于检测是否达到每进程的系统限制。例如，当多个连接错误发生时，若 actconn 接近 512 或 1024，很可能表明系统将进程的文件描述符使用上限设为 1024，且所有文件描述符均已耗尽。 请参阅 [第 3 节](/zh/docs/haproxy/global/)“全局段”以了解如何调整系统配置。 - "feconn" 是流记录时前端的并发连接总数。 该值有助于估算维持高负载所需的资源量，并检测前端的 "maxconn" 是否已达到。 该值通常出现大幅跃升时，往往是因为后端服务器发生拥塞，但有时也可能由拒绝服务攻击引起。 - "beconn" 是在日志记录时后端处理的并发连接总数。该数值包括后端服务器上当前活跃的并发连接数以及队列中等待的连接数。可用于估算支持特定应用高负载所需的额外服务器数量。当该值出现大幅跃升时，通常表明后端服务器存在拥塞，但有时也可能由拒绝服务攻击引起。 - "srv_conn" 是流记录时服务器上仍处于活跃状态的并发连接总数。该值绝不会超过服务器配置的 "maxconn" 参数。若该值经常接近或等于服务器的 "maxconn"，表明流量控制参与程度较高，即服务器的 maxconn 值可能过低，或用于处理负载的服务器数量不足，无法实现最优响应时间。当仅有一个服务器的 "srv_conn" 值较高时，通常意味着该服务器存在某些问题，导致请求处理时间长于其他服务器。 - "retries" 是此流在尝试连接服务器时经历的连接重试次数。正常情况下应为零，除非服务器在连接尝试的同一时刻被停止。频繁重试通常表明 HAProxy 与服务器之间存在网络问题，或服务器端系统队列配置不当，导致无法将新连接排队。该字段可选择性地以加号 '+' 开头，表示在初始服务器达到最大重试次数后，连接已被重分派。此时日志中显示的服务器名称是连接被重分派至的目标服务器，而非首个服务器，尽管在某些情况下（例如使用哈希时）两者可能相同。因此，一般规则是：当重试次数前出现 '+' 符号时，该次数不应归因于日志中记录的服务器。 - "srv_queue" 是在当前请求之前，服务器队列中已处理的请求数量。当请求未经过服务器队列时，该值为 0。通过将请求在队列中等待的时间除以队列中的请求数量，可估算服务器响应时间的近似值。请注意，若流经历重分派并经过两个服务器队列，其位置将累加。除非发生重分派，否则请求不应同时经过服务器队列和后端队列。 - "backend_queue" 是在当前请求之前，后端全局队列中已处理的请求数量。当请求未经过全局队列时，该值为 0。该值可用于估算平均队列长度，除以服务器的 "maxconn" 参数后，即可得出缺失服务器的数量。请注意，若流经历重分派，可能两次经过后端队列，此时两个位置将累加。除非发生重分派，否则请求不应同时经过服务器队列和后端队列。 - "captured_request_headers" 是由于前端中存在 "capture request header" 语句而捕获的请求头列表。可捕获多个头，它们之间以竖线字符（'\|'）分隔。当未启用捕获时，不显示花括号，导致后续字段位置偏移。请注意，此字段可能包含空格，使用时需要比未使用时更智能的日志解析器。有关更多详细信息，请参阅下方“捕获 HTTP 头和 Cookie”段。 - "captured_response_headers" 是由于前端中存在 "capture response header" 语句而在响应中捕获的头列表。可捕获多个头，它们将使用竖线字符（'|'）分隔。当未启用捕获时，大括号不会出现，导致后续字段位置偏移。请注意，此字段可能包含空格，使用时需要比未使用时更智能的日志解析器。有关更多详细信息，请参阅下方“捕获 HTTP 头和 Cookie”段。 - "http_request" 是完整的 HTTP 请求行，包含方法、请求路径和 HTTP 版本字符串。不可打印字符会被编码（详见下文“不可打印字符”段）。此字段始终位于最后，始终用引号包围，且是唯一可包含引号的字段。若向日志格式中添加新字段，将插入此字段之前。当请求过大且超出标准 syslog 缓冲区（1024 字符）容量时，该字段可能被截断。因此，此字段必须始终位于最后。 ### 8.2.4. HTTPS 日志格式 {#section-8-2-4} HTTPS 格式最适合用于 SSL 连接上的 HTTP。它是 HTTP 格式（参见 [第 8.2.3 节](/zh/docs/haproxy/configuration-logging/#section-8-2-3)）的扩展，在其中添加了与 SSL 相关的信息。当在前端中指定 "option httpslog" 时，该格式被启用。与 TCP 和 HTTP 格式类似，日志通常在流结束时发出，除非指定了 "option logasap"。若流匹配 "monitor" 规则，则该流将不会被记录。也可通过在前端中指定 "option dontlognull" 来避免记录客户端未发送任何数据的流。若在前端中指定 "option dontlog-normal"，则正常连接将不会被记录。 HTTPS 日志格式在内部被定义为基于以下精确字符串的自定义日志格式，该字符串也可用作扩展格式的基础（如需）。此外，可使用 HAPROXY_HTTPS_LOG_FMT 变量替代。请参阅 [第 8.2.6 节](/zh/docs/haproxy/configuration-logging/#section-8-2-6)“自定义日志格式”，了解如何使用。 ```shell # strict equivalent of "option httpslog" log-format "%ci:%cp [%tr] %ft %b/%s %TR/%Tw/%Tc/%Tr/%Ta %ST %B %CC \ %CS %tsc %ac/%fc/%bc/%sc/%rc %sq/%bq %hr %hs %{+Q}r \ %[fc_err]/%[ssl_fc_err,hex]/%[ssl_c_err]/\ %[ssl_c_ca_err]/%[ssl_fc_is_resumed] %[ssl_fc_sni]/%sslv/%sslc" # or using the HAPROXY_HTTPS_LOG_FMT variable log-format "${HAPROXY_HTTPS_LOG_FMT}" ``` 该格式本质上是 HTTP 格式（参见 [第 8.2.3 节](/zh/docs/haproxy/configuration-logging/#section-8-2-3)），并在其基础上附加了新字段。新增字段（第 17 行和第 18 行）将在下文详述。关于 HTTP 字段的说明，请参见 HTTP 段。 示例： ```shell frontend https-in mode http option httpslog log global bind *:443 ssl crt mycerts/srv.pem ... default_backend bck backend static server srv1 127.0.0.1:8000 ssl crt mycerts/clt.pem ... >>> Feb 6 12:14:14 localhost \ haproxy[14389]: 10.0.1.2:33317 [06/Feb/2009:12:14:14.655] https-in \ static/srv1 10/0/30/69/109 200 2750 - - ---- 1/1/1/1/0 0/0 {1wt.eu} \ {} "GET /index.html HTTP/1.1" 0/0/0/0/0 \ 1wt.eu/TLSv1.3/TLS_AES_256_GCM_SHA384 ``` 字段格式 从上例中提取 1 process_name '[' pid ']:' HAProxy[14389]: 2 client_ip ':' client_port 10.0.1.2:33317 3 '[' request_date ']' [06/Feb/2009:12:14:14.655] 4 frontend_name https-in 5 backend_name '/' server_name static/srv1 6 TR '/' Tw '/' Tc '/' Tr '/' Ta\* 10/0/30/69/109 7 status_code 200 8 bytes_read\* 2750 9 captured_request_cookie - 10 captured_response_cookie - 11 termination_state ---- 12 actconn '/' feconn '/' beconn '/' srv_conn '/' retries\* 1/1/1/1/0 13 srv_queue '/' backend_queue 0/0 14 '{' captured_request_headers\* '}' {HAProxy.1wt.eu} 15 '{' captured_response_headers\* '}' {} 16 '"' http_request '"' "GET /index.html HTTP/1.1" 17 fc_err '/' ssl_fc_err '/' ssl_c_err '/' ssl_c_ca_err '/' ssl_fc_is_resumed 0/0/0/0/0 18 ssl_fc_sni '/' ssl_version '/' ssl_ciphers 1wt.eu/TLSv1.3/TLS_AES_256_GCM_SHA384 详细字段说明： - "fc_err" 是前端一侧连接的状态。它对应于 "fc_err" 样本提取。有关更多信息，请参阅 "fc_err" 和 "fc_err_str" 样本提取函数。 - "ssl_fc_err" 是从前端视角看，该连接上首次 SSL 错误栈中的最后一个错误。可用于检测 SSL 握手错误等情形。若一切正常，则其值为 0。有关更多信息，请参见 "ssl_fc_err" 样本提取的说明。 - "ssl_c_err" 表示客户端证书验证过程的状态。即使验证错误码非空，握手仍可能成功，若该错误码属于被忽略的类型。请参见 "ssl_c_err" 样本提取和 "crt-ignore-err" 选项。 - "ssl_c_ca_err" 表示客户端证书链验证过程的状态。握手过程可能成功，但若验证错误码非空，且该错误码属于被忽略的类型，则仍可能出现这种情况。请参见 "ssl_c_ca_err" 样本提取和 "ca-ignore-err" 选项。 - "ssl_fc_is_resumed" 在传入的 TLS 会话通过有状态缓存或无状态票据恢复时为真。请注意，一个 TLS 会话可被多个请求共享。 - "ssl_fc_sni" 是客户端用于选择要使用的证书的 SNI（服务器名称指示）。通常与连接的第一个请求的主机名匹配。若该字段缺失，可能表示客户端未发送 SNI，此时 HAProxy 将使用默认证书，或在启用 strict-sni 时拒绝连接。 - "ssl_version" 是前端的 SSL 版本。 - "ssl_ciphers" 是连接所使用的 SSL 密码。 ### 8.2.5. 错误日志格式 {#section-8-2-5} 当入站连接因 SSL 握手失败或无效的 PROXY 协议头而中断时，HAProxy 将使用较短的固定行格式记录该事件，除非通过 "error-log-format" 行定义了专用错误日志格式。默认情况下，日志级别为 LOG_INFO，除非在后端中设置了选项 "log-separate-errors"，此时将使用 LOG_ERR 级别。若设置了 "dontlognull" 选项，则不会记录未交换任何数据的连接（例如探测连接）。 默认格式如下所示： ```text >>> Dec 3 18:27:14 localhost \ haproxy[6103]: 127.0.0.1:56059 [03/Dec/2012:17:35:10.380] frt/f1: \ Connection error during SSL handshake Field Format Extract from the example above 1 process_name '[' pid ']:' haproxy[6103]: 2 client_ip ':' client_port 127.0.0.1:56059 3 '[' accept_date ']' [03/Dec/2012:17:35:10.380] 4 frontend_name "/" bind_name ":" frt/f1: 5 message Connection error during SSL handshake ``` 这些字段仅提供最少的信息，以帮助排查连接失败问题。 通过使用 "error-log-format" 指令，将不再使用上述传统日志格式，所有错误日志行将遵循已定义的格式。 一个较为完整的 error-log-format 示例，将报告源地址和端口、连接 accept() 日期、前端名称、进程上和该前端的活跃连接数、HAProxy 内部错误标识符（前端连接）、十六进制 OpenSSL 错误编号（可复制粘贴至 "openssl errstr" 以获取完整解码）、客户端证书提取状态（0 表示无错误）、使用 CA 验证客户端证书的状态（0 表示无错误）、连接是否为新建或已恢复的布尔值、客户端提供的可选服务器名称指示（SNI）、SSL 版本名称以及连接上使用的 SSL 密码套件（如有）。请注意，后端连接错误不会在此处报告，因为后端连接失败的前提是其已成功通过流，因此将作为常规流量日志记录（参见 option httplog 或 option httpslog）。 ```haproxy # detailed frontend connection error log error-log-format "%ci:%cp [%tr] %ft %ac/%fc %[fc_err]/\ %[ssl_fc_err,hex]/%[ssl_c_err]/%[ssl_c_ca_err]/%[ssl_fc_is_resumed] \ %[ssl_fc_sni]/%sslv/%sslc" ``` ### 8.2.6. 自定义日志格式 {#section-8-2-6} 历史上，自定义日志格式仅用于生成日志。但当其被用于通过组合多个复杂表达式来生成字符串时，其便捷性使得许多原本仅接受字符串作为参数的指令开始采用自定义日志格式定义。如今，这些指令可接受的参数类型已扩展为支持此类自定义日志格式定义。本文档中通常以“``”表示的此类参数，其定义方式与本节所述的 "log-format" 指令的参数完全相同。 当涉及日志且默认日志格式无法满足需求时，可极为细致地定义新的日志格式。由于从零开始创建日志格式并非总是简单任务，强烈建议首先查看现有格式（"option tcplog"、"option httplog"、"option httpslog"），选择最接近预期的格式，复制其 "log-format" 对应字符串，并进行调整。 自定义日志格式定义从配置角度而言是一个单一参数。这意味着其内容不得包含空格（空格或制表符），除非这些空格通过反斜杠字符（'\'）进行转义，或整个定义被引号包围（这是推荐的使用方式）。由于历史经验表明，未加引号的格式字符串极易出错，单个遗漏的反斜杠字符就可能导致格式被静默截断，因此不再建议使用未加引号的格式字符串。尽管由于 1.5-dev9 版本发布后日志格式的广泛采用，此类配置至今仍普遍存在（该版本发布三年前引号尚不可用），但建议现在将其转换为带引号的字符串，并移除反斜杠。 日志格式定义由任意数量的日志格式项组成，各项之间用文本和空格分隔。日志格式项以字符 '%' 开头。若需原样输出 '%'，必须在其前添加另一个 '%'，形成 '%%'。 日志格式项可以是别名或样本表达式： 如果某项名称用方括号（'[' .. ']'）括起，则将其用作样本表达式规则（参见 [第 7.3 节](/zh/docs/haproxy/acls-and-samples/#section-7-3)）。这可用于添加一些较少见的信息，例如客户端 SSL 证书的 DN，或记录将用于向粘性表中存储条目时所使用的键。该用法也常用于非日志类动作（如头操作、变量处理等）。 否则，如果该项使用字母数字名称命名，则为别名。（有关可用别名的列表，请参见下表） 项目可使用花括号（'{}'）传递参数，多个参数在花括号内以逗号分隔。可通过在标志前加 '+' 或 '-' 符号来添加或移除标志（详见下文可用标志列表）。 特殊别名 "%o" 可用于将其标志传播到同一格式字符串中的所有其他 logformat 项。在使用带引号的（"Q"）和转义的（"E"）字符串格式时，此功能尤为便捷。 特殊别名 "%OG" 可用于以人类可读格式检索日志来源（日志生成位置）。在使用 "option logasap" 时尤为有用，因为某些日志变量或样本提取可能在日志格式表达式被评估的时间或位置不同而报告不完整值，或表现出不同行为。可能的取值包括： - "sess_error"：在会话错误处理期间生成日志 - "sess_killed"：在会话中止期间生成日志（已终止的初始会话） - "txn_accept"：在前端连接被接受后立即生成日志 - "txn_request"：在客户端请求接收后生成日志 - "txn_connect"：在后端连接建立后生成日志 - "txn_response"：在服务器响应处理期间生成日志 - "txn_close"：在最终事务步骤生成日志，关闭前 - "unspec"：未知或未指定 "%OG" 仅在日志记录上下文中相关 项目可选择性地通过 ('()') 命名。名称必须紧跟在 '%' 之后（位于参数之前）。当设置编码标志如 "json" 或 "cbor" 时，该名称将自动作为键名使用。若未指定编码标志（默认情况），则忽略项目名称。也可通过在名称后附加 ':type' 强制指定项目的输出类型，格式如下：%(itemname:itemtype)aliasname 或 %(itemname:itemtype)[expr]，其中 itemtype 可为 'str'、'sint' 或 'bool'。指定类型仅在使用编码方法时有意义。此外，支持为匿名项目提供空名称以强制输出类型：%(:itemtype)，即在未全局设置编码时使用，详见下方标志定义。 由于自定义日志格式最初仅用于日志记录，因此在不同使用场景下对不可打印字符和不安全字符（ASCII 码 32 至 126 以外的字符，以及少数其他字符）的处理存在特殊规则。[第 8.6 节](/zh/docs/haproxy/configuration-logging/#section-8-6)详细说明了日志中具体采取的措施，以确保不会发送可能影响终端输出可读性的不安全编码。当用于构造 HTTP 头、健康检查或响应负载时，规则较为宽松，仅对 HTTP 头字段中禁止出现的字符使用百分号 % 前缀的十六进制编码进行替换。通常这不会造成问题，但在某些情况下可能影响输出，例如在构建错误页面或完整响应负载时，期望原样重现的换行符可能显示为 "%0A"。 请注意：在配置指令 "log-format"、"log-format-sd" 和 "unique-id-format" 中，空格被视为分隔符并被合并。 请注意：使用 RFC5424 syslog 消息格式时，PARAM-VALUE 内部的字符 '"'、\ 和 ']' 应使用 \ 作为前缀进行转义（详见 以获取更多详情）。在此类情况下，应考虑使用标志 "E"。 支持的项目标志包括（可从项目的参数中启用或禁用）： - Q: 对字符串进行转义 - X: 十六进制表示（IP 地址、端口、%Ts、%rt、%pid） - E: 使用 '\' 作为前缀，对字符串中的引号 '"'、'\' 和 ']' 进行转义（用于 RFC5424 结构化数据日志格式） - bin: 尝试保留二进制数据，这在处理输出二进制数据的样本表达式时可能有用，以保留原始数据。但需注意，这显然可能生成不可打印字符，包括空字节（NULL-byte），而大多数 syslog 接收端不期望此类数据。因此，该选项主要适用于 set-var-fmt、环形缓冲区和具备二进制能力的日志接收端。此选项只能全局设置（使用 %o），若在单个项的选项中设置将被忽略。 - json: 自动将值以 JSON 格式编码（全局设置时，仅考虑命名的日志格式项）。未完成的数值（例如：使用 logasap 时的 '%B'），通常以 '+' 前缀但不进行编码，将原样编码。同时，'+E' 选项将被忽略。 - cbor: 自动将值以 CBOR 格式编码（全局设置时，仅考虑命名的日志格式项）。默认情况下，CBOR 编码数据以十六进制形式表示，以确保其在 stdout 上可打印，并可与常规 syslog 接收端配合使用。与 json 编码类似，未完成的数值将原样编码，'+E' 选项将被忽略。当与 '+bin' 选项结合使用时，将直接生成原始二进制 CBOR 负载。请注意，这显然可能生成不可打印字符，因此主要适用于 set-var-fmt、环形缓冲区和具备二进制能力的日志接收端。 示例： ```text log-format %T\ %t\ Some\ Text log-format %{+Q}o\ %t\ %s\ %{-Q}r log-format-sd %{+Q,+E}o\ [exampleSDID@1234\ header=%[capture.req.hdr(0)]] log-format "%{+json}o %(request)r %(custom_expr)[str(custom)]" log-format "%{+cbor}o %(request)r %(custom_expr)[str(custom)]" ``` 请参阅下表以了解当前定义的别名： ```text +---+------+------------------------------------------------------+---------+ | R | alias| field name (8.2.2 and 8.2.3 for description) | type | | | | sample fetch alternative | | +===+======+======================================================+=========+ | | %o | special, apply flags on all following items | | +---+------+------------------------------------------------------+---------+ | date formats | +---+------+------------------------------------------------------+---------+ | | %T | Accept date UTC + timezone | | | | | %[accept_date,utime("%d/%b/%Y:%H:%M:%S %z")] | date | +---+------+------------------------------------------------------+---------+ | | %Tl | Accept date local + timezone | | | | | %[accept_date,ltime("%d/%b/%Y:%H:%M:%S %z")] | date | +---+------+------------------------------------------------------+---------+ | | %Ts | Accept date as a UNIX timestamp | numeric | | | | %[accept_date] | | +---+------+------------------------------------------------------+---------+ | | %t | Accept date local (with millisecond resolution) | | | | | %[accept_date(ms),ms_ltime("%d/%b/%Y:%H:%M:%S.%3N")] | date | +---+------+------------------------------------------------------+---------+ | | %ms | Accept date milliseconds | | | | | %[accept_date(ms),ms_utime("%3N")] | numeric | +---+------+------------------------------------------------------+---------+ | H | %tr | Request date local (with millisecond resolution) | | | | | %[request_date(ms),ms_ltime("%d/%b/%Y:%H:%M:%S.%3N")]| date | +---+------+------------------------------------------------------+---------+ | H | %trg | Request date UTC + timezone | | | | | %[request_date,utime("%d/%b/%Y:%H:%M:%S %z")] | date | +---+------+------------------------------------------------------+---------+ | H | %trl | Request date local + timezone | | | | | %[request_date,ltime("%d/%b/%Y:%H:%M:%S %z")] | date | +---+------+------------------------------------------------------+---------+ | Timing events | +---+------+------------------------------------------------------+---------+ | H | %Ta | Active time of the request (from TR to end) | | | | | %[txn.timer.total] | numeric | +---+------+------------------------------------------------------+---------+ | | %Tc | Tc | | | | | %[bc.timer.connect] | numeric | +---+------+------------------------------------------------------+---------+ | | %Td | Td = Tt - (Tq + Tw + Tc + Tr) | | | | | %[res.timer.data] | numeric | +---+------+------------------------------------------------------+---------+ | | %Th | connection handshake time (SSL, PROXY proto) | | | | | %[fc.timer.handshake] | numeric | +---+------+------------------------------------------------------+---------+ | H | %Ti | idle time before the HTTP request | | | | | %[req.timer.idle] | numeric | +---+------+------------------------------------------------------+---------+ | H | %Tq | Th + Ti + TR | | | | | %[req.timer.tq] | numeric | +---+------+------------------------------------------------------+---------+ | H | %TR | time to receive the full request from 1st byte | | | | | %[req.timer.hdr] | numeric | +---+------+------------------------------------------------------+---------+ | H | %Tr | Tr (response time) | | | | | %[res.timer.hdr] | numeric | +---+------+------------------------------------------------------+---------+ | | %Tt | Tt | | | | | %[fc.timer.total] | numeric | +---+------+------------------------------------------------------+---------+ | | %Tu | Tu | | | | | %[txn.timer.user] | numeric | +---+------+------------------------------------------------------+---------+ | | %Tw | Tw | | | | | %[req.timer.queue] | numeric | +---+------+------------------------------------------------------+---------+ | Others | +---+------+------------------------------------------------------+---------+ | | %B | bytes_read (from server to client) | numeric | | | | %[res.bytes_in] | | +---+------+------------------------------------------------------+---------+ | H | %CC | captured_request_cookie | string | +---+------+------------------------------------------------------+---------+ | H | %CS | captured_response_cookie | string | +---+------+------------------------------------------------------+---------+ | | %H | hostname | string | | | | %[hostname] | | +---+------+------------------------------------------------------+---------+ | H | %HM | HTTP method (ex: POST) | string | | | | %[method] +---+------+------------------------------------------------------+---------+ | H | %HP | HTTP request URI without query string | string | +---+------+------------------------------------------------------+---------+ | H | %HPO | HTTP path only (without host nor query string) | string | +---+------+------------------------------------------------------+---------+ | H | %HQ | HTTP request URI query string (ex: ?bar=baz) | string | | | | ?%[query] | | +---+------+------------------------------------------------------+---------+ | H | %HU | HTTP request URI (ex: /foo?bar=baz) | string | +---+------+------------------------------------------------------+---------+ | H | %HV | HTTP version (ex: HTTP/1.0) | string | | | | HTTP/%[req.ver] | | +---+------+------------------------------------------------------+---------+ | | %ID | unique-id | string | | | | %[unique-id] | | +---+------+------------------------------------------------------+---------+ | | %ST | status_code | numeric | | | | %[txn.status] | | +---+------+------------------------------------------------------+---------+ | | %U | bytes_uploaded (from client to server) | numeric | | | | %[req.bytes_in] | | +---+------+------------------------------------------------------+---------+ | | %ac | actconn | | | | | %[act_conn] | numeric | +---+------+------------------------------------------------------+---------+ | | %b | backend_name | | | | | %[be_name] | string | +---+------+------------------------------------------------------+---------+ | | %bc | beconn (backend concurrent connections) | numeric | | | | %[be_conn] | | +---+------+------------------------------------------------------+---------+ | | %bi | backend_source_ip (connecting address) | | | | | %[bc_src] | IP | +---+------+------------------------------------------------------+---------+ | | %bp | backend_source_port (connecting address) | | | | | %[bc_src_port] | numeric | +---+------+------------------------------------------------------+---------+ | | %bq | backend_queue | numeric | | | | %[bc_be_queue] | | +---+------+------------------------------------------------------+---------+ | | %ci | client_ip (accepted address) | | | | | %[src] | IP | +---+------+------------------------------------------------------+---------+ | | %cp | client_port (accepted address) | | | | | %[src_port] | numeric | +---+------+------------------------------------------------------+---------+ | | %f | frontend_name | string | | | | %[fe_name] | | +---+------+------------------------------------------------------+---------+ | | %fc | feconn (frontend concurrent connections) | numeric | | | | %[fe_conn] | | +---+------+------------------------------------------------------+---------+ | | %fi | frontend_ip (accepting address) | | | | | %[dst] | IP | +---+------+------------------------------------------------------+---------+ | | %fp | frontend_port (accepting address) | | | | | %[dst_port] | numeric | +---+------+------------------------------------------------------+---------+ | | %ft | frontend_name_transport ('~' suffix for SSL) | string | +---+------+------------------------------------------------------+---------+ | | %lc | frontend_log_counter | numeric | +---+------+------------------------------------------------------+---------+ | | %hr | captured_request_headers default style | string | +---+------+------------------------------------------------------+---------+ | | %hrl | captured_request_headers CLF style | string | | | | | list | +---+------+------------------------------------------------------+---------+ | | %hs | captured_response_headers default style | string | +---+------+------------------------------------------------------+---------+ | | %hsl | captured_response_headers CLF style | string | | | | | list | +---+------+------------------------------------------------------+---------+ | L | %OG | human readable log origin | string | +---+------+------------------------------------------------------+---------+ | | %pid | PID | | | | | %[pid] | numeric | +---+------+------------------------------------------------------+---------+ | H | %r | http_request | string | +---+------+------------------------------------------------------+---------+ | | %rc | retries | numeric | | | | %[txn.redispatched,iif(+,)]%[txn.conn_retries] | | +---+------+------------------------------------------------------+---------+ | | %rt | request_counter (HTTP req or TCP session) | numeric | | | | %[txn.id32] | | +---+------+------------------------------------------------------+---------+ | | %s | server_name | string | | | | %[srv_name] | | +---+------+------------------------------------------------------+---------+ | | %sc | srv_conn (server concurrent connections) | numeric | +---+------+------------------------------------------------------+---------+ | | %si | server_IP (target address) | | | | | %[bc_dst] | IP | +---+------+------------------------------------------------------+---------+ | | %sp | server_port (target address) | | | | | %[bc_dst_port] | numeric | +---+------+------------------------------------------------------+---------+ | | %sq | srv_queue | numeric | | | | %[bc_srv_queue] | | +---+------+------------------------------------------------------+---------+ | S | %sslc| ssl_ciphers (ex: AES-SHA) | | | | | %[ssl_fc_cipher] | string | +---+------+------------------------------------------------------+---------+ | S | %sslv| ssl_version (ex: TLSv1) | | | | | %[ssl_fc_protocol] | string | +---+------+------------------------------------------------------+---------+ | | %ts | termination_state | string | | | | %[txn.sess_term_state] | | +---+------+------------------------------------------------------+---------+ | H | %tsc | termination_state with cookie status | string | +---+------+------------------------------------------------------+---------+ ``` R = Restrictions: H = mode http only; S = SSL only; L = log only ## 8.3. 高级日志记录选项 {#section-8-3} 一些高级日志选项常被寻找，但仅通过查看各项配置选项往往难以发现。以下是少数可启用更优日志功能的选项入口。有关其用法的更多信息，请参阅关键字参考。 ### 8.3.1. 禁用外部测试日志记录 {#section-8-3-1} 对 HAProxy 执行健康检查的情况十分常见。有时是第 3 层负载均衡器，例如 LVS 或任何商用负载均衡器，有时则可能是更完整的监控系统，例如 Nagios。当检查频率非常高时，用户常会询问如何禁用这些检查的日志记录。有三种可能的解决方案： - 若连接来自任意位置且仅为 TCP 探测，通常建议在前端通过设置 "option dontlognull" 来禁用无数据交换连接的日志记录。该设置同时也会禁用端口扫描日志记录，是否需要此功能应根据实际需求决定。 - 可以在多种条件下（如源网络、路径、User-Agent 等）使用 "http-request set-log-level silent" 动作。 - 若测试在已知的 URI 上执行，请使用 "monitor-uri" 将该 URI 声明为专用监控地址。任何发送此请求的主机仅会收到健康检查结果，且该请求不会被记录。 ### 8.3.2. 在日志记录之前等待流终止 {#section-8-3-2} 在连接结束时记录日志的问题在于，对于长时间的流（如远程终端会话或大文件下载），你无法了解其间发生了什么。此问题可通过在前端配置中指定“option logasap”来规避。HAProxy 将在数据传输开始前尽可能早地记录日志。这意味着在 TCP 情况下，仍会记录与服务器的连接状态；在 HTTP 情况下，则在处理完服务器头后立即记录。此时报告的字节数为发送给客户端的头字节数。为避免与正常日志混淆，总时间字段和字节数前会加上“+”号，表示实际数值肯定更大。 ### 8.3.3. 提高错误日志级别 {#section-8-3-3} 有时将正常流量日志与错误日志分离更为方便，例如便于从日志文件中监控错误。当使用选项 "log-separate-errors" 时，发生错误、超时、重试、重分派或 HTTP 状态码 5xx 的连接，其 syslog 级别将从 "info" 提升至 "err"。这有助于 syslog 守护进程将日志存储于独立文件中。请注意，必须同时保留在正常流量文件中的错误日志，以确保日志顺序不被破坏。如果已配置 syslog 守护进程将所有高于 "notice" 级别的日志存储于 "admin" 文件中，则需格外小心，因为 "err" 级别高于 "notice"。 ### 8.3.4. 禁用成功连接的日志记录 {#section-8-3-4} 尽管初听之下可能显得奇怪，但一些大型网站每秒需处理数千条日志，且在长期保存日志或从中检测错误方面面临困难。若在前端中设置选项 "dontlog-normal"，所有正常连接将不会被记录。此处定义的正常连接是指无任何错误、超时、重试或重分派的连接。在 HTTP 中，还会检查状态码，状态码为 5xx 的响应不被视为正常，也将被记录。当然，此举强烈不建议，因为它会移除日志中绝大部分有用信息。仅在别无选择时方可执行。 ### 8.3.5. 日志配置文件 {#section-8-3-5} 虽然某些指令如 "log-format"、"log-format-sd"、"error-log-format" 或 "log-tag" 可用于全局或在代理级别配置日志格式，但将此类设置尽可能靠近日志端点配置可能更为合适，即按每个 "log" 指令配置。 本文第 "log-profile" 段发挥作用之处在于："log-profile" 可在配置文件中的任意位置定义。该段接受一组不同的关键字，用于描述针对特定 `log` 指令所生成日志的构建方式。 通过 "log" 指令，可选择通过名称指定特定的日志配置文件。同一配置文件可从多个 "log" 指令中使用。 log-profile `` 创建一个标识为 `` 的新日志配置文件 log-tag `` 使用 "log-tag" 指令全局或按代理覆盖 syslog 日志标签。 在 `` 上 [drop] [format ``] [sd ``] 重写通常用于在 `` 日志记录步骤构建日志行的格式字符串。`` 用于重写 "log-format" 或 "error-log-format" 字符串（取决于 ``），而 `` 用于重写 "log-format-sd" 字符串（两者可同时使用）。 "drop" 特殊关键字可用于指定对指定的 `` 不发出日志。 若先前已定义，该关键字优先于 "format" 和 "sd"。 `` 的可能取值如下： - "accept" ：在前端连接被接受后立即生成日志时，覆盖 log-format - "request" ：在接收到客户端请求后生成日志时，覆盖 log-format - "connect" ：在后端连接建立后生成日志时，覆盖 log-format - "response" ：在服务器响应处理过程中生成日志时，覆盖 log-format - "close" ：在最终事务（txn）步骤生成日志时，覆盖 log-format - "error" ：在事务错误导致日志生成时，覆盖 error-log-format - "any" ：覆盖所有日志步骤的 log-format 和 error-log-format，除非声明了更精确的步骤覆盖 请参阅 "do-log" 动作以获取相关的额外 `` 值。 此设置仅对在使用 "log-format" 指令有意义的上下文中的 "log" 指令有效（例如：http 和 tcp 代理）。否则将被忽略。 示例： ```text log-profile myprof log-tag "custom-tag" on error format "%ci: error" on connect drop on any sd "custom-sd" listen myproxy mode http option httplog log-tag "normal" log stdout format rfc5424 local0 # success: # <134>1 2024-06-12T10:09:11.823400+02:00 - normal 224482 - - 127.0.0.1:53594 [12/Jun/2024:10:09:11.814] myproxy myproxy/ 0/-1/-1/-1/0 200 49 - - LR-- 1/1/0/0/0 0/0 "GET / HTTP/1.1" # # error: # <134>1 2024-06-12T10:09:44.810929+02:00 - normal 224482 - - 127.0.0.1:59258 [12/Jun/2024:10:09:44.426] myproxy myproxy/ -1/-1/-1/-1/384 400 0 - - CR-- 1/1/0/0/0 0/0 "" log 127.0.0.1:514 format rfc5424 profile myprof local0 # success: # <134>1 2024-06-12T10:09:11.823428+02:00 - custom-tag 224482 - custom-sd 127.0.0.1:53594 [12/Jun/2024:10:09:11.814] myproxy myproxy/ 0/-1/-1/-1/0 200 49 - - LR-- 1/1/0/0/0 0/0 "GET / HTTP/1.1" # # error: # <134>1 2024-06-12T10:09:51.566524+02:00 - custom-tag 224482 - - 127.0.0.1: error ``` ## 8.4. 事件计时 {#section-8-4} 计时器在排查网络问题时提供极大帮助。所有值均以毫秒（ms）为单位报告。这些计时器应与流终止标志配合使用。在 TCP 模式下，若前端启用了 "option tcplog"，将报告 3 个控制点，格式为 "Tw/Tc/Tt"；在 HTTP 模式下，将报告 5 个控制点，格式为 "TR/Tw/Tc/Tr/Ta"。此外，还提供三个其他测量值，分别为 "Th"、"Ti" 和 "Tq"。 HTTP 模式下的时间事件： ```text first request 2nd request |<-------------------------------->|<-------------- ... t tr t tr ... ---|----|----|----|----|----|----|----|----|-- : Th Ti TR Tw Tc Tr Td: Ti ... :<---- Tq ---->: : :<-------------- Tt -------------->: :<-- -----Tu--------------->: :<--------- Ta --------->: ``` TCP 模式下的时间事件： ```text TCP session |<----------------->| t t ---|----|----|----|----|--- | Th Tw Tc Td | |<------ Tt ------->| ``` - Th：接受 TCP 连接并完成低层协议握手的总时间。目前，这些协议包括 proxy-protocol 和 SSL。在整个连接生命周期中，此操作可能仅发生一次。此处时间较长可能表明客户端仅预先建立了连接而未发送数据，或因网络问题导致无法在合理时间内完成握手（例如 MTU 问题），或 SSL 握手计算开销过大。请注意，此时间仅在首个请求前报告，因此可对所有请求的值取平均以计算摊销值。后续请求在此处始终报告为零。 该计时器在日志格式中命名为 %Th，作为样本提取时则命名为 fc.timer.handshake。 - Ti：为 HTTP 请求的空闲时间（仅限 HTTP 模式）。该计时器在握手完成与 HTTP 请求首个字节之间计时。在持久连接模式下处理第二个请求时，计时器在前一个响应传输结束后开始计时。当使用 HTTP/2 等多路复用协议时，计时器在前一个请求结束后立即开始计时。部分浏览器会预先建立与服务器的连接，以降低未来请求的延迟，并将连接保持待命状态直至需要使用。此延迟将被报告为空闲时间。值 -1 表示连接上未收到任何数据。 该计时器在日志格式中命名为 %Ti，作为样本提取时则为 req.timer.idle。 - TR：获取客户端请求的总时间（仅限 HTTP 模式）。该值表示从接收到首个字节到代理收到标记 HTTP 头结束的空行之间所经过的时间。值 "-1" 表示从未收到头结束标记。这种情况发生在客户端提前关闭或超时时。由于大多数请求可容纳于单个数据包中，该时间通常很短。若时间较长，可能表明在测试过程中手动输入了请求。 该计时器在日志格式中命名为 %TR，作为样本提取时则为 req.timer.hdr。 - Tq：从接受客户端请求的时刻起，或从上一个响应的最后一个字节发出后开始计算的总时间（仅限 HTTP 模式）。其值严格等于 Th + Ti + TR，除非其中任一项为 -1，此时也返回 -1。在 HTTP 持久连接和浏览器预连接功能出现之前，该计时器曾非常有用。如今建议放弃使用，转而采用 TR，因为空闲时间会显著增加报告中的噪声。 该计时器在日志格式中命名为 %Tq，在样本提取中为 req.timer.tq。 - Tw：在队列中等待连接槽位所花费的总时间。该值包含后端队列以及服务器队列，取决于队列大小以及服务器完成先前请求所需的时间。值 "-1" 表示请求在进入队列前已被终止，通常发生在无效或被拒绝的请求上。 该计时器在日志格式中命名为 %Tw，作为样本提取时则为 req.timer.queue。 - Tc：建立与服务器的 TCP 连接所花费的总时间。该值表示代理发送连接请求的时刻，到服务器确认连接的时刻之间的时间间隔，或表示从 TCP SYN 数据包发出，到收到对应的 SYN/ACK 数据包的时间间隔。值 "-1" 表示连接从未建立成功。 该计时器在日志格式中命名为 %Tc，在样本提取中命名为 bc.timer.connect。 - Tr：服务器响应时间（仅限 HTTP 模式）。该值表示从与服务器建立 TCP 连接的时刻，到服务器发送完整响应头的时刻之间所经过的时间。它仅反映请求处理时间，不包含因数据传输导致的网络开销。请注意，当客户端需向服务器发送数据时（例如在 POST 请求期间），该时间已开始计算，这可能导致观察到的响应时间出现偏差。因此，建议不要过于依赖此字段来评估来自不可信网络后端的客户端发起的 POST 请求。此处值为 "-1" 表示从未收到最后一个响应头（空行），极可能是服务器超时发生在服务器完成请求处理之前，或服务器返回了无效响应。 该计时器在日志格式中命名为 %Tr，作为样本提取时则为 res.timer.hdr。 - Td：表示响应负载从开始传输到向客户端发送最后一个字节的总耗时。在 HTTP 中，该时间从最后一个响应头发送完成后开始计算（即 Tr 之后）。 发送的数据无法保证客户端能够收到，数据可能滞留在内核或网络中。 该计时器在日志格式中命名为 %Td，在样本提取中命名为 res.timer.data。 - Ta：HTTP 请求的总活跃时间，指代理接收到请求头第一个字节的时刻，到发出响应体最后一个字节的时刻之间的时长。例外情况是当指定了 "logasap" 选项时，此时仅等于 (TR + Tw + Tc + Tr)，并以加号“+”作为前缀。通过该字段，可减去其他有效计时器，推导出 "Td"，即数据传输时间： ```text Td = Ta - (TR + Tw + Tc + Tr) ``` Timers with "-1" values have to be excluded from this equation. Note that "Ta" can never be negative. This timer is named %Ta as a log-format alias, and txn.timer.total as a sample fetch. - Tt：从代理接受连接到两端均关闭的总流持续时间。当指定 "logasap" 选项时例外。此时，其值仅等于 (Th+Ti+TR+Tw+Tc+Tr)，并以 '+' 号前缀。通过从该字段中减去其他有效计时器，可推导出 "Td"，即数据传输时间： ```text Td = Tt - (Th + Ti + TR + Tw + Tc + Tr) ``` Timers with "-1" values have to be excluded from this equation. In TCP mode, "Ti", "Tq" and "Tr" have to be excluded too. Note that "Tt" can never be negative and that for HTTP, Tt is simply equal to (Th+Ti+Ta). This timer is named %Tt as a log-format alias, and fc.timer.total as a sample fetch. - Tu：从代理接受请求的时刻到两端连接关闭的时刻，客户端所感知的总估算时间，不包含空闲时间。该指标有助于粗略衡量用户所感知的端到端延迟，避免因请求间持久连接（keep-alive）导致的空闲时间干扰。此计时仅为用户所见时间的估算值，因其假设网络延迟在两个方向上相同。例外情况是当指定 "logasap" 选项时，此时其值仅等于 (Th + TR + Tw + Tc + Tr)，并以加号（+）作为前缀。 该计时器在日志格式中命名为 %Tu，在样本提取中命名为 txn.timer.user。 这些超时计时器可提供关于故障原因的宝贵线索。由于 TCP 协议定义的重传延迟为 3、6、12... 秒，因此可以确定，接近 3 秒倍数的超时计时器几乎总是与网络问题（如线路、协商或拥塞）导致的数据包丢失有关。此外，若 "Ta" 或 "Tt" 接近配置中指定的超时值，通常意味着某一流已因超时而被中止。 最常见的场景： - 若 "Th" 或 "Ti" 接近 3000，表示客户端与代理之间的数据包可能已丢失。在本地网络中这种情况极为罕见，但在客户端位于远端网络且发送大请求时可能发生。有时，即使没有网络原因，此处也可能出现高于正常值的情况。在攻击期间或资源耗尽状况结束后，HAProxy 可能在几毫秒内接受数千个连接。接受这些连接所花费的时间不可避免地会轻微延迟其他连接的处理，因此在一次性接受数千个新连接后，可能会测量到数十毫秒级别的请求耗时。使用任一持久连接模式时，可能会显示更大的空闲时间，因为 "Ti" 测量的是等待额外请求所花费的时间。 - 若 "Tc" 接近 3000，表示在服务器连接阶段，服务器与代理之间可能丢失了数据包。该值应始终非常低，本地网络下约为 1 ms，远程网络下应小于几十毫秒。 - 若 "Tr" 几乎始终低于 3000，仅个别值似乎以 3000 为平均值，代理与服务器之间可能有数据包丢失。 - 若 "Ta" 即使在字节数较小时也较大，通常是因为 HAProxy 以隧道模式运行时，客户端和服务器均未决定关闭连接，且双方已协商使用持久连接模式。为解决此问题，需在前端或后端指定一种 HTTP 选项，以控制持久连接或关闭选项。当使用 "maxconn" 选项对服务器进行连接调控时，保持 'Ta' 或 'Tt' 尽可能小至关重要，因为除非已有连接释放，否则不会向服务器发送新的连接。 其他值得注意的 HTTP 日志情况（'xx' 表示任意需忽略的值）： ```text TR/Tw/Tc/Tr/+Ta The "option logasap" is present on the frontend and the log was emitted before the data phase. All the timers are valid except "Ta" which is shorter than reality. -1/xx/xx/xx/Ta The client was not able to send a complete request in time or it aborted too early. Check the stream termination flags then "timeout http-request" and "timeout client" settings. TR/-1/xx/xx/Ta It was not possible to process the request, maybe because servers were out of order, because the request was invalid or forbidden by ACL rules. Check the stream termination flags. TR/Tw/-1/xx/Ta The connection could not establish on the server. Either it actively refused it or it timed out after Ta-(TR+Tw) ms. Check the stream termination flags, then check the "timeout connect" setting. Note that the tarpit action might return similar-looking patterns, with "Tw" equal to the time the client connection was maintained open. TR/Tw/Tc/-1/Ta The server has accepted the connection but did not return a complete response in time, or it closed its connection unexpectedly after Ta-(TR+Tw+Tc) ms. Check the stream termination flags, then check the "timeout server" setting. ``` ## 8.5. 断开连接时的流状态 {#section-8-5} TCP 和 HTTP 日志在活跃连接数之前提供流终止指示符，位于 "termination_state" 字段中。在 TCP 模式下，该字段长度为 2 个字符；在 HTTP 模式下，长度扩展为 4 个字符，每个字符具有特殊含义： - 在第一个字符上，报告导致流终止的第一个事件的代码： ```text C: the TCP session was unexpectedly aborted by the client. S: the TCP session was unexpectedly aborted by the server, or the server explicitly refused it. P: the stream or session was prematurely aborted by the proxy, because of a connection limit enforcement, because a DENY filter was matched, because of a security check which detected and blocked a dangerous error in server response which might have caused information leak (e.g. cacheable cookie). L: the stream was locally processed by HAProxy. R: a resource on the proxy has been exhausted (memory, sockets, source ports, ...). Usually, this appears during the connection phase, and system logs should contain a copy of the precise error. If this happens, it must be considered as a very serious anomaly which should be fixed as soon as possible by any means. I: an internal error was identified by the proxy during a self-check. This should NEVER happen, and you are encouraged to report any log containing this, because this would almost certainly be a bug. It would be wise to preventively restart the process after such an event too, in case it would be caused by memory corruption. D: the stream was killed by HAProxy because the server was detected as down and was configured to kill all connections when going down. U: the stream was killed by HAProxy on this backup server because an active server was detected as up and was configured to kill all backup connections when going up. K: the stream was actively killed by an admin operating on HAProxy. c: the client-side timeout expired while waiting for the client to send or receive data. s: the server-side timeout expired while waiting for the server to send or receive data. -: normal stream completion, both the client and the server closed with nothing left in the buffers. ``` - 在第二个字符中，流关闭时的 TCP 或 HTTP 流状态： ```text R: the proxy was waiting for a complete, valid REQUEST from the client (HTTP mode only). Nothing was sent to any server. Q: the proxy was waiting in the QUEUE for a connection slot. This can only happen when servers have a 'maxconn' parameter set. It can also happen in the global queue after a redispatch consecutive to a failed attempt to connect to a dying server. If no redispatch is reported, then no connection attempt was made to any server. C: the proxy was waiting for the CONNECTION to establish on the server. The server might at most have noticed a connection attempt. H: the proxy was waiting for complete, valid response HEADERS from the server (HTTP only). D: the stream was in the DATA phase. L: the proxy was still transmitting LAST data to the client while the server had already finished. This one is very rare as it can only happen when the client dies while receiving the last packets. T: the request was tarpitted. It has been held open with the client during the whole "timeout tarpit" duration or until the client closed, both of which will be reported in the "Tw" timer. -: normal stream completion after end of data transfer. ``` - 第三个字符表示持久性 Cookie 是否由客户端提供（仅在 HTTP 模式下）： ```text N: the client provided NO cookie. This is usually the case for new visitors, so counting the number of occurrences of this flag in the logs generally indicate a valid trend for the site frequentation. I: the client provided an INVALID cookie matching no known server. This might be caused by a recent configuration change, mixed cookies between HTTP/HTTPS sites, persistence conditionally ignored, or an attack. D: the client provided a cookie designating a server which was DOWN, so either "option persist" was used and the client was sent to this server, or it was not set and the client was redispatched to another server. V: the client provided a VALID cookie, and was sent to the associated server. E: the client provided a valid cookie, but with a last date which was older than what is allowed by the "maxidle" cookie parameter, so the cookie is consider EXPIRED and is ignored. The request will be redispatched just as if there was no cookie. O: the client provided a valid cookie, but with a first date which was older than what is allowed by the "maxlife" cookie parameter, so the cookie is consider too OLD and is ignored. The request will be redispatched just as if there was no cookie. U: a cookie was present but was not used to select the server because some other server selection mechanism was used instead (typically a "use-server" rule). -: does not apply (no cookie set in configuration). ``` - 最后一个字符报告了对服务器返回的持久性 Cookie 执行的操作（仅限 HTTP 模式）： ```text N: NO cookie was provided by the server, and none was inserted either. I: no cookie was provided by the server, and the proxy INSERTED one. Note that in "cookie insert" mode, if the server provides a cookie, it will still be overwritten and reported as "I" here. U: the proxy UPDATED the last date in the cookie that was presented by the client. This can only happen in insert mode with "maxidle". It happens every time there is activity at a different date than the date indicated in the cookie. If any other change happens, such as a redispatch, then the cookie will be marked as inserted instead. P: a cookie was PROVIDED by the server and transmitted as-is. R: the cookie provided by the server was REWRITTEN by the proxy, which happens in "cookie rewrite" or "cookie prefix" modes. D: the cookie provided by the server was DELETED by the proxy. -: does not apply (no cookie set in configuration). ``` 两个首个标志的组合可提供关于流或会话终止时发生的情况及其终止原因的大量信息。这有助于检测服务器过载、网络问题、本地系统资源耗尽、攻击等情况。 最常见的终止标志组合如下所示。组合按字母顺序排列，小写字母紧接在对应大写字母之后，以便于查找和理解。 标志 说明 -- Normal termination. CC The client aborted before the connection could be established to the server. This can happen when HAProxy tries to connect to a recently dead (or unchecked) server, and the client aborts while HAProxy is waiting for the server to respond or for "timeout connect" to expire. CD The client unexpectedly aborted during data transfer. This can be caused by a browser crash, by an intermediate equipment between the client and HAProxy which decided to actively break the connection, by network routing issues between the client and HAProxy, or by a keep-alive stream between the server and the client terminated first by the client. cD The client did not send nor acknowledge any data for as long as the "timeout client" delay. This is often caused by network failures on the client side, or the client simply leaving the net uncleanly. CH The client aborted while waiting for the server to start responding. It might be the server taking too long to respond or the client clicking the 'Stop' button too fast. cH The "timeout client" stroke while waiting for client data during a POST request. This is sometimes caused by too large TCP MSS values for PPPoE networks which cannot transport full-sized packets. It can also happen when client timeout is smaller than server timeout and the server takes too long to respond. CQ The client aborted while its stream was queued, waiting for a server with enough empty slots to accept it. It might be that either all the servers were saturated or that the assigned server was taking too long a time to respond. CR The client aborted before sending a full HTTP request. Most likely the request was typed by hand using a telnet client, and aborted too early. The HTTP status code is likely a 400 here. Sometimes this might also be caused by an IDS killing the connection between HAProxy and the client. "option http-ignore-probes" can be used to ignore connections without any data transfer. cR The "timeout http-request" stroke before the client sent a full HTTP request. This is sometimes caused by too large TCP MSS values on the client side for PPPoE networks which cannot transport full-sized packets, or by clients sending requests by hand and not typing fast enough, or forgetting to enter the empty line at the end of the request. The HTTP status code is likely a 408 here. Note: recently, some browsers started to implement a "pre-connect" feature consisting in speculatively connecting to some recently visited web sites just in case the user would like to visit them. This results in many connections being established to web sites, which end up in 408 Request Timeout if the timeout strikes first, or 400 Bad Request when the browser decides to close them first. These ones pollute the log and feed the error counters. Some versions of some browsers have even been reported to display the error code. It is possible to work around the undesirable effects of this behavior by adding "option http-ignore-probes" in the frontend, resulting in connections with zero data transfer to be totally ignored. This will definitely hide the errors of people experiencing connectivity issues though. CT The client aborted while its stream was tarpitted. It is important to check if this happens on valid requests, in order to be sure that no wrong tarpit rules have been written. If a lot of them happen, it might make sense to lower the "timeout tarpit" value to something closer to the average reported "Tw" timer, in order not to consume resources for just a few attackers. LC The request was intercepted and locally handled by HAProxy. The request was not sent to the server. It only happens with a redirect because of a "redir" parameter on the server line. LR The request was intercepted and locally handled by HAProxy. The request was not sent to the server. Generally it means a redirect was returned, an HTTP return statement was processed or the request was handled by an applet (stats, cache, Prometheus exported, lua applet...). LH The response was intercepted and locally handled by HAProxy. Generally it means a redirect was returned or an HTTP return statement was processed. SC The server or an equipment between it and HAProxy explicitly refused the TCP connection (the proxy received a TCP RST or an ICMP message in return). Under some circumstances, it can also be the network stack telling the proxy that the server is unreachable (e.g. no route, or no ARP response on local network). When this happens in HTTP mode, the status code is likely a 502 or 503 here. sC The "timeout connect" stroke before a connection to the server could complete. When this happens in HTTP mode, the status code is likely a 503 or 504 here. SD The connection to the server died with an error during the data transfer. This usually means that HAProxy has received an RST from the server or an ICMP message from an intermediate equipment while exchanging data with the server. This can be caused by a server crash or by a network issue on an intermediate equipment. sD The server did not send nor acknowledge any data for as long as the "timeout server" setting during the data phase. This is often caused by too short timeouts on L4 equipment before the server (firewalls, load-balancers, ...), as well as keep-alive sessions maintained between the client and the server expiring first on HAProxy. SH The server aborted before sending its full HTTP response headers, or it crashed while processing the request. Since a server aborting at this moment is very rare, it would be wise to inspect its logs to control whether it crashed and why. The logged request may indicate a small set of faulty requests, demonstrating bugs in the application. Sometimes this might also be caused by an IDS killing the connection between HAProxy and the server. sH The "timeout server" stroke before the server could return its response headers. This is the most common anomaly, indicating too long transactions, probably caused by server or database saturation. The immediate workaround consists in increasing the "timeout server" setting, but it is important to keep in mind that the user experience will suffer from these long response times. The only long term solution is to fix the application. sQ The stream spent too much time in queue and has been expired. See the "timeout queue" and "timeout connect" settings to find out how to fix this if it happens too often. If it often happens massively in short periods, it may indicate general problems on the affected servers due to I/O or database congestion, or saturation caused by external attacks. PC The proxy refused to establish a connection to the server because the process's socket limit has been reached while attempting to connect. The global "maxconn" parameter may be increased in the configuration so that it does not happen anymore. This status is very rare and might happen when the global "ulimit-n" parameter is forced by hand. PD The proxy blocked an incorrectly formatted chunked encoded message in a request or a response, after the server has emitted its headers. In most cases, this will indicate an invalid message from the server to the client. HAProxy supports chunk sizes of up to 2GB - 1 (2147483647 bytes). Any larger size will be considered as an error. PH The proxy blocked the server's response, because it was invalid, incomplete, dangerous (cache control), or matched a security filter. In any case, an HTTP 502 error is sent to the client. One possible cause for this error is an invalid syntax in an HTTP header name containing unauthorized characters. It is also possible but quite rare, that the proxy blocked a chunked-encoding request from the client due to an invalid syntax, before the server responded. In this case, an HTTP 400 error is sent to the client and reported in the logs. Finally, it may be due to an HTTP header rewrite failure on the response. In this case, an HTTP 500 error is sent (see "tune.maxrewrite" and "http-response strict-mode" for more inforomation). PR The proxy blocked the client's HTTP request, either because of an invalid HTTP syntax, in which case it returned an HTTP 400 error to the client, or because a deny filter matched, in which case it returned an HTTP 403 error. It may also be due to an HTTP header rewrite failure on the request. In this case, an HTTP 500 error is sent (see "tune.maxrewrite" and "http-request strict-mode" for more inforomation). PT The proxy blocked the client's request and has tarpitted its connection before returning it a 500 server error. Nothing was sent to the server. The connection was maintained open for as long as reported by the "Tw" timer field. RC A local resource has been exhausted (memory, sockets, source ports) preventing the connection to the server from establishing. The error logs will tell precisely what was missing. This is very rare and can only be solved by proper system tuning. 两个最后标志的组合可提供大量关于客户端、服务器及 HAProxy 如何处理持久性连接的信息。这对排查断连故障至关重要，尤其当用户抱怨需重新认证时。常见的标志包括： ```text -- Persistence cookie is not enabled. NN No cookie was provided by the client, none was inserted in the response. For instance, this can be in insert mode with "postonly" set on a GET request. II A cookie designating an invalid server was provided by the client, a valid one was inserted in the response. This typically happens when a "server" entry is removed from the configuration, since its cookie value can be presented by a client when no other server knows it. NI No cookie was provided by the client, one was inserted in the response. This typically happens for first requests from every user in "insert" mode, which makes it an easy way to count real users. VN A cookie was provided by the client, none was inserted in the response. This happens for most responses for which the client has already got a cookie. VU A cookie was provided by the client, with a last visit date which is not completely up-to-date, so an updated cookie was provided in response. This can also happen if there was no date at all, or if there was a date but the "maxidle" parameter was not set, so that the cookie can be switched to unlimited time. EI A cookie was provided by the client, with a last visit date which is too old for the "maxidle" parameter, so the cookie was ignored and a new cookie was inserted in the response. OI A cookie was provided by the client, with a first visit date which is too old for the "maxlife" parameter, so the cookie was ignored and a new cookie was inserted in the response. DI The server designated by the cookie was down, a new server was selected and a new cookie was emitted in the response. VI The server designated by the cookie was not marked dead but could not be reached. A redispatch happened and selected another one, which was then advertised in the response. ``` ## 8.6. 不可打印字符 {#section-8-6} 为避免在查阅日志时对日志分析工具或终端造成干扰，不可打印字符不会直接写入日志文件，而是转换为对应 ASCII 码的两位十六进制表示，并以字符 '#' 作为前缀。仅 ASCII 码值在 32 至 126（含）之间的字符可直接记录，无需转义。显然，转义字符 '#' 本身也需编码以避免歧义（"#23"）。同理，字符 '"' 被编码为 "#22"，在记录头时，字符 '{'、'|' 和 '}' 也需进行相同处理。 请注意，空格字符（' '）在头中未被编码，这可能导致依赖空格计数来定位字段的工具出现问题。一个包含空格的典型头为 "User-Agent"。 最后，观察到某些 syslog 守护进程（如 syslog-ng）会使用反斜杠（\）转义引号（'"'）。由于日志中其他位置不会出现引号，因此可安全地执行反向操作。 ## 8.7. 捕获 HTTP cookies {#section-8-7} Cookie 捕获可简化对完整用户会话的追踪。可通过在前端中使用 "capture cookie" 语句实现。详细信息请参见 [第 4.2 节](/zh/docs/haproxy/proxies/#section-4-2)。仅可捕获一个 Cookie，该 Cookie 会在请求（"Cookie:" 头）和响应（"Set-Cookie:" 头）中同时被检查。相应值将在 HTTP 日志的 "captured_request_cookie" 和 "captured_response_cookie" 位置报告（有关 HTTP 日志格式的详情请参见 [第 8.2.3 节](/zh/docs/haproxy/configuration-logging/#section-8-2-3)）。若任一 Cookie 未被发现，将用连字符 '-' 替代其值。通过此方式，可轻松检测用户是否切换至新会话，例如服务器为其重新分配了新的 Cookie。也可用于检测服务器是否意外向客户端设置了错误的 Cookie，从而导致会话交叉。 示例： ```shell # capture the first cookie whose name starts with "ASPSESSION" capture cookie ASPSESSION len 32 # capture the first cookie whose name is exactly "vgnvisitor" capture cookie vgnvisitor= len 32 ``` 可以使用 "http-request" 和 "http-response" 规则，将 Cookie 分配至作用域 "txn" 的变量中。随后，可通过 "req.cook" 和 "res.cook" 样本提取函数从请求或响应中提取 Cookie 值（参见 [section 7.3.6](/zh/docs/haproxy/acls-and-samples/#section-7-3-6)），并使用 "set-var" 或 "set-var-fmt" 动作将其赋值给变量（参见 [section 4.3](/zh/docs/haproxy/proxies/#section-4-3)）。自定义日志格式即可在指定位置输出这些变量（参见 [section 8.2.6](/zh/docs/haproxy/configuration-logging/#section-8-2-6)）。 ## 8.8. 捕获 HTTP 头（遗留） {#section-8-8} 头捕获可用于跟踪上游代理设置的唯一请求标识符、虚拟主机名称、用户代理、POST 内容长度、来源地址等信息。在响应中，可搜索关于响应长度、服务器要求缓存行为的信息，或重定向期间的对象位置。 有两种方式执行头捕获。现代方式涉及从待捕获的头中设置变量，或从 "req.hdr_names"、"req.hdrs"、"res.hdr_names"、"res.hdrs" 返回的复合样本中设置变量（详见 [section 7.3.6](/zh/docs/haproxy/acls-and-samples/#section-7-3-6)），这些变量可使用 "txn" 作用域中的 "set-var" 和 "set-var-fmt" 动作，通过 "http-request" 和 "http-response" 规则集进行赋值（详见 [section 4.3](/zh/docs/haproxy/proxies/#section-4-3)），随后可在自定义日志格式中引用（详见 [section 8.2.6](/zh/docs/haproxy/configuration-logging/#section-8-2-6)）。这是捕获 HTTP 头的推荐方式。 此外，还存在一种较早的方法，该方法在引入 http-request 规则和变量之前即已存在，无需调整日志格式，且长期以来一直用于日志记录，同时作为在 HTTP 事务全程中传递请求信息的一种人工手段，使用较旧的 "capture" 规则集。本文所述即为此方法。 使用前端中的“capture request header”和“capture response header”语句执行旧版头捕获。请参阅 [第 4.2 节](/zh/docs/haproxy/proxies/#section-4-2) 以获取更多详细信息。 可以同时包含请求头和响应头。不存在的头字段将记录为空字符串；若某个头字段出现多次，仅记录其最后一次出现的值。请求头按声明顺序用花括号 '{' 和 '}' 包裹，以竖线 '\|' 分隔，中间不加空格。响应头采用相同的表示方式，但显示在请求头块之后，以一个空格分隔。这些头字段块在日志中紧随 HTTP 请求之前显示。 作为特殊情况，可以在 TCP 前端中指定 HTTP 头捕获。其目的是在请求随后被切换至 HTTP 后端时，启用对将被解析的头信息的记录。 示例： ```shell # This instance chains to the outgoing proxy listen proxy-out mode http option httplog option logasap log global server cache1 192.168.1.1:3128 # log the name of the virtual server capture request header Host len 20 # log the amount of data uploaded during a POST capture request header Content-Length len 10 # log the beginning of the referrer capture request header Referer len 20 # server name (useful for outgoing proxies only) capture response header Server len 20 # logging the content-length is useful with "option logasap" capture response header Content-Length len 10 # log the expected cache behavior on the response capture response header Cache-Control len 8 # the Via header will report the next proxy's name capture response header Via len 20 # log the URL location during a redirection capture response header Location len 20 ``` ```text >>> Aug 9 20:26:09 localhost \ haproxy[2022]: 127.0.0.1:34014 [09/Aug/2004:20:26:09] proxy-out \ proxy-out/cache1 0/0/0/162/+162 200 +350 - - ---- 0/0/0/0/0 0/0 \ {fr.adserver.yahoo.co||http://fr.f416.mail.} {|864|private||} \ "GET http://fr.adserver.yahoo.com/" ``` ```text >>> Aug 9 20:30:46 localhost \ haproxy[2022]: 127.0.0.1:34020 [09/Aug/2004:20:30:46] proxy-out \ proxy-out/cache1 0/0/0/182/+182 200 +279 - - ---- 0/0/0/0/0 0/0 \ {w.ods.org||} {Formilux/0.1.8|3495|||} \ "GET http://trafic.1wt.eu/ HTTP/1.1" ``` ```text >>> Aug 9 20:30:46 localhost \ haproxy[2022]: 127.0.0.1:34028 [09/Aug/2004:20:30:46] proxy-out \ proxy-out/cache1 0/0/2/126/+128 301 +223 - - ---- 0/0/0/0/0 0/0 \ {www.sytadin.equipement.gouv.fr||http://trafic.1wt.eu/} \ {Apache|230|||http://www.sytadin.} \ "GET http://www.sytadin.equipement.gouv.fr/ HTTP/1.1" ``` ## 8.9. 日志示例 {#section-8-9} 以下是真实场景中的日志示例，附有说明。部分日志由人工编造。为便于阅读，已移除 syslog 部分。其唯一目的是解释如何解读这些日志。 >>> haproxy[674]: 127.0.0.1:33318 [15/Oct/2003:08:31:57.130] px-http \ px-http/srv1 6559/0/7/147/6723 200 243 - - ---- 5/3/3/1/0 0/0 \ "HEAD / HTTP/1.0" => long request (6.5s) entered by hand through 'telnet'. The server replied in 147 ms, and the session ended normally ('----') >>> haproxy[674]: 127.0.0.1:33319 [15/Oct/2003:08:31:57.149] px-http \ px-http/srv1 6559/1230/7/147/6870 200 243 - - ---- 324/239/239/99/0 \ 0/9 "HEAD / HTTP/1.0" => Idem, but the request was queued in the global queue behind 9 other requests, and waited there for 1230 ms. ```text >>> haproxy[674]: 127.0.0.1:33320 [15/Oct/2003:08:32:17.654] px-http \ px-http/srv1 9/0/7/14/+30 200 +243 - - ---- 3/3/3/1/0 0/0 \ "GET /image.iso HTTP/1.0" ``` => request for a long data transfer. The "logasap" option was specified, so the log was produced just before transferring data. The server replied in 14 ms, 243 bytes of headers were sent to the client, and total time from accept to first data byte is 30 ms. >>> haproxy[674]: 127.0.0.1:33320 [15/Oct/2003:08:32:17.925] px-http \ px-http/srv1 9/0/7/14/30 502 243 - - PH-- 3/2/2/0/0 0/0 \ "GET /cgi-bin/bug.cgi? HTTP/1.0" => the proxy blocked a server response either because of an "http-response deny" rule, or because the response was improperly formatted and not HTTP-compliant, or because it blocked sensitive information which risked being cached. In this case, the response is replaced with a "502 bad gateway". The flags ("PH--") tell us that it was HAProxy who decided to return the 502 and not the server. >>> haproxy[18113]: 127.0.0.1:34548 [15/Oct/2003:15:18:55.798] px-http \ px-http/`` -1/-1/-1/-1/8490 -1 0 - - CR-- 2/2/2/0/0 0/0 "" => the client never completed its request and aborted itself ("C---") after 8.5s, while the proxy was waiting for the request headers ("-R--"). Nothing was sent to any server. >>> haproxy[18113]: 127.0.0.1:34549 [15/Oct/2003:15:19:06.103] px-http \ px-http/`` -1/-1/-1/-1/50001 408 0 - - cR-- 2/2/2/0/0 0/0 "" => The client never completed its request, which was aborted by the time-out ("c---") after 50s, while the proxy was waiting for the request headers ("-R--"). Nothing was sent to any server, but the proxy could send a 408 return code to the client. >>> haproxy[18989]: 127.0.0.1:34550 [15/Oct/2003:15:24:28.312] px-tcp \ px-tcp/srv1 0/0/5007 0 cD 0/0/0/0/0 0/0 => This log was produced with "option tcplog". The client timed out after 5 seconds ("c----"). >>> haproxy[18989]: 10.0.0.1:34552 [15/Oct/2003:15:26:31.462] px-http \ px-http/srv1 3183/-1/-1/-1/11215 503 0 - - SC-- 205/202/202/115/3 \ 0/0 "HEAD / HTTP/1.0" => The request took 3s to complete (probably a network problem), and the connection to the server failed ('SC--') after 4 attempts of 2 seconds (config says 'retries 3'), and no redispatch (otherwise we would have seen "/+3"). Status code 503 was returned to the client. There were 115 connections on this server, 202 connections on this proxy, and 205 on the global process. It is possible that the server refused the connection because of too many already established.