Varnish Cache 运维教程 / 第10章：日志与监控

第10章：日志与监控

10.1 日志架构

10.1.1 共享内存日志（VSM）

Varnish 使用共享内存段（Varnish Shared Memory, VSM）存储日志，避免了磁盘 I/O 瓶颈。所有日志工具都从 VSM 读取数据。

┌──────────────────────────────────────────────────────┐
│               共享内存（VSM）                          │
│                                                      │
│  ┌───────────┐  ┌───────────┐  ┌───────────┐       │
│  │ Log Ring  │  │ Stats     │  │ Args      │       │
│  │ Buffer    │  │ Counters  │  │ Workspace │       │
│  └───────────┘  └───────────┘  └───────────┘       │
└──────────────────────────────────────────────────────┘
       │               │               │
       ▼               ▼               ▼
  varnishlog      varnishstat     varnishncsa

10.1.2 日志工具概览

工具	功能	输出
`varnishlog`	详细请求日志	结构化日志
`varnishstat`	统计信息	计数器/仪表盘
`varnishtop`	实时排序	Top-N 排行
`varnishhist`	延迟直方图	ASCII 图形
`varnishncsa`	NCSA 格式日志	Apache/NCSA 格式
`varnishsaas`	日志分析	分析报告

10.2 varnishlog

10.2.1 基本用法

# 查看所有日志
varnishlog

# 按请求分组
varnishlog -g request

# 按会话分组
varnishlog -g session

# 按 VXID 分组
varnishlog -g vxid

# 只显示第一个请求
varnishlog -1

# 限制输出数量
varnishlog -n 100

# 从文件读取
varnishlog -r /var/log/varnish/varnish.log

10.2.2 过滤表达式

# 按请求 URL 过滤
varnishlog -q 'ReqURL ~ "^/api/"'

# 按响应状态码过滤
varnishlog -q 'RespStatus >= 500'

# 按缓存状态过滤
varnishlog -q 'VCL_call ~ "HIT"'

# 按后端过滤
varnishlog -q 'BackendName == "web01"'

# 组合过滤
varnishlog -q 'ReqURL ~ "^/api/" && RespStatus >= 400'

# 按时间过滤
varnishlog -q 'Timestamp:Process[2] > 1.0'

# 显示特定标签
varnishlog -i ReqURL,RespStatus,RespHeader

10.2.3 日志标签

# 常用日志标签

# 请求相关
# ReqMethod     - 请求方法
# ReqURL        - 请求 URL
# ReqHeader     - 请求头部

# 响应相关
# RespStatus    - 响应状态码
# RespHeader    - 响应头部
# RespUnset     - 删除的响应头部

# 后端相关
# Backend       - 后端服务器
# BackendStart  - 后端请求开始
# BackendClose  - 后端连接关闭

# VCL 相关
# VCL_call      - VCL 子程序调用
# VCL_return    - VCL 返回动作
# VCL_Error     - VCL 错误

# 缓存相关
# Hit           - 缓存命中
# TTL           - TTL 设置
# ExpBan        - Ban 导致的过期

# 示例：查看请求方法和 URL
varnishlog -g request -i ReqMethod,ReqURL

# 查看响应状态和缓存状态
varnishlog -g request -i RespStatus,VCL_call

10.2.4 日志输出格式

# 默认输出格式
# VXID Tag   Timestamp 信息
# 1001 ReqURL 2026-05-10T12:00:00 /api/products

# JSON 格式输出
varnishlog -j

# NCSA 格式（类似 Apache access.log）
varnishncsa

# 自定义 NCSA 格式
varnishncsa -F '%h %l %u %t "%r" %s %b "%{Referer}i" "%{User-agent}i"'

10.2.5 日志轮转

# 信号控制
# SIGHUP  - 重新打开日志文件
# SIGUSR1 - 日志轮转

# 配合 logrotate
cat > /etc/logrotate.d/varnish << 'EOF'
/var/log/varnish/varnish.log {
    daily
    rotate 7
    compress
    delaycompress
    missingok
    notifempty
    sharedscripts
    postrotate
        /usr/bin/varnishlog -w /var/log/varnish/varnish.log &
    endscript
}
EOF

10.3 varnishstat

10.3.1 基本用法

# 实时统计仪表盘（默认）
varnishstat

# 单次输出
varnishstat -1

# JSON 格式
varnishstat -j

# 过滤特定计数器
varnishstat -1 -f MAIN.cache_hit -f MAIN.cache_miss

# 更新间隔
varnishstat -1 -V 5

10.3.2 关键计数器

# 主要计数器分类

# MAIN.cache_hit       - 缓存命中次数
# MAIN.cache_miss      - 缓存未命中次数
# MAIN.cache_hitpass   - 命中但 pass 的次数

# 后端相关
# MAIN.backend_conn    - 后端连接数
# MAIN.backend_unhealthy - 不健康后端请求数
# MAIN.backend_fail    - 后端连接失败数
# MAIN.backend_recycle  - 后端连接复用数

# 线程相关
# MAIN.threads         - 当前线程数
# MAIN.threads_created - 创建的线程总数
# MAIN.threads_limited - 因线程限制被拒绝的请求数
# MAIN.thread_queue_len - 线程队列长度

# 请求相关
# MAIN.client_req      - 客户端请求总数
# MAIN.client_req_400  - 400 错误请求数
# MAIN.client_req_500  - 500 错误请求数

# 会话相关
# MAIN.sess_conn       - 会话连接数
# MAIN.sess_drop       - 丢弃的会话数
# MAIN.sess_fail       - 失败的会话数

# 存储相关
# SMA.n_object         - 存储对象数量
# SMA.n_vary           - Vary 变体数量
# SMA.bereq_bodybytes  - 后端响应体字节数
# SMA.bereq_hdrbytes   - 后端响应头字节数

# BAN 相关
# MAIN.bans            - 当前 ban 数量
# MAIN.bans_completed  - 已完成的 ban 数量
# MAIN.bans_obj        - 对象匹配 ban 次数

10.3.3 计算缓存命中率

#!/bin/bash
# cache-hitrate.sh - 计算缓存命中率

while true; do
    # 获取计数器值
    HIT=$(varnishstat -1 -f MAIN.cache_hit | awk '{print $2}')
    MISS=$(varnishstat -1 -f MAIN.cache_miss | awk '{print $2}')

    # 计算命中率
    if [ $((HIT + MISS)) -gt 0 ]; then
        RATE=$(echo "scale=2; $HIT * 100 / ($HIT + $MISS)" | bc)
        echo "Cache Hit Rate: ${RATE}% (HIT: ${HIT}, MISS: ${MISS})"
    fi

    sleep 60
done

10.3.4 监控脚本

#!/bin/bash
# varnish-monitor.sh - Varnish 监控脚本

LOG_FILE="/var/log/varnish/monitor.log"

log_metric() {
    echo "$(date '+%Y-%m-%d %H:%M:%S') $1" >> "$LOG_FILE"
}

while true; do
    # 获取统计信息
    STATS=$(varnishstat -j)

    # 提取关键指标
    CACHE_HIT=$(echo "$STATS" | jq '.MAIN.cache_hit // 0')
    CACHE_MISS=$(echo "$STATS" | jq '.MAIN.cache_miss // 0')
    CLIENT_REQ=$(echo "$STATS" | jq '.MAIN.client_req // 0')
    THREADS=$(echo "$STATS" | jq '.MAIN.threads // 0')
    BANS=$(echo "$STATS" | jq '.MAIN.bans // 0')

    # 计算命中率
    TOTAL=$((CACHE_HIT + CACHE_MISS))
    if [ $TOTAL -gt 0 ]; then
        HITRATE=$(echo "scale=2; $CACHE_HIT * 100 / $TOTAL" | bc)
    else
        HITRATE=0
    fi

    # 记录指标
    log_metric "cache_hitrate=$HITRATE"
    log_metric "client_req=$CLIENT_REQ"
    log_metric "threads=$THREADS"
    log_metric "bans=$BANS"

    # 告警检查
    if (( $(echo "$HITRATE < 70" | bc -l) )); then
        log_metric "ALERT: Cache hit rate below 70%"
    fi

    if [ $THREADS -gt 400 ]; then
        log_metric "ALERT: Thread count above 400"
    fi

    sleep 60
done

10.4 varnishtop

10.4.1 基本用法

# 按请求 URL 排序（默认）
varnishtop -i ReqURL

# 按响应状态码排序
varnishtop -i RespStatus

# 按后端排序
varnishtop -i Backend

# 按 VCL 调用排序
varnishtop -i VCL_call

# 按请求头排序
varnishtop -i ReqHeader:User-Agent

# 使用查询过滤
varnishtop -q 'RespStatus >= 500'

# 限制输出行数
varnishtop -n 10

10.4.2 常用命令

# 查看最常访问的 URL
varnishtop -i ReqURL

# 查看响应最慢的请求
varnishtop -q 'VCL_call == "MISS"' -i ReqURL

# 查看缓存命中最多的 URL
varnishtop -q 'VCL_call == "HIT"' -i ReqURL

# 查看后端负载分布
varnishtop -i BackendName

# 查看错误请求
varnishtop -q 'RespStatus >= 400' -i ReqURL

# 查看请求来源
varnishtop -i ReqHeader:X-Forwarded-For

10.5 varnishhist

10.5.1 延迟直方图

# 基本延迟直方图
varnishhist

# 只显示 cache hit
varnishhist -q 'VCL_call == "HIT"'

# 只显示 cache miss
varnishhist -q 'VCL_call == "MISS"'

# 图形说明
# |  = 请求
# 每列代表一个延迟区间
# 左侧 = 快（<1ms）
# 右侧 = 慢（>10s）

10.6 varnishncsa

10.6.1 NCSA 日志格式

# 默认 NCSA 格式
varnishncsa

# 输出到文件
varnishncsa -w /var/log/varnish/access.log

# 自定义格式
varnishncsa -F '%h %l %u %t "%r" %s %b "%{Referer}i" "%{User-agent}i" %D'

# 格式占位符：
# %h - 客户端 IP
# %l - 用户标识（通常 -）
# %u - 用户名（通常 -）
# %t - 时间戳
# %r - 请求行
# %s - 响应状态码
# %b - 响应字节数
# %D - 处理时间（微秒）
# %{Referer}i - Referer 头部
# %{User-agent}i - User-Agent 头部

# JSON 格式
varnishncsa -F '{"ip":"%h","time":"%t","method":"%m","url":"%U","status":%s,"bytes":%b,"duration":%D}'

10.6.2 日志分析

# 分析 NCSA 日志

# 最常访问的 URL
awk '{print $7}' /var/log/varnish/access.log | sort | uniq -c | sort -rn | head -20

# 状态码分布
awk '{print $9}' /var/log/varnish/access.log | sort | uniq -c | sort -rn

# 5xx 错误统计
awk '$9 >= 500 {print $7}' /var/log/varnish/access.log | sort | uniq -c | sort -rn | head -20

# 平均响应时间（微秒）
awk '{sum+=$NF; count++} END {print "Avg: " sum/count/1000 "ms"}' /var/log/varnish/access.log

10.7 自定义日志标签

10.7.1 VCL 中添加自定义标签

import std;

sub vcl_recv {
    # 记录自定义日志标签
    std.log("request-type:" + req.method);
    std.log("client-ip:" + client.ip);

    if (req.url ~ "^/api/") {
        std.log("api-version:v1");
    }
}

sub vcl_backend_response {
    # 记录后端响应时间
    std.log("backend-time:" + beresp.ttl);
}

sub vcl_deliver {
    # 记录缓存状态
    if (obj.hits > 0) {
        std.log("cache-status:HIT");
        std.log("cache-hits:" + obj.hits);
    } else {
        std.log("cache-status:MISS");
    }
}

10.7.2 查询自定义标签

# 查询自定义标签
varnishlog -g request -q 'VCL_Log ~ "cache-status:HIT"'
varnishlog -g request -q 'VCL_Log ~ "api-version:v1"'
varnishlog -g request -q 'VCL_Log ~ "client-ip:192.168.1.100"'

10.8 Prometheus 监控集成

10.8.1 varnish-exporter 安装

# 使用 Go 实现的 varnish_exporter
# https://github.com/jonnenauha/prometheus_varnish_exporter

# 下载并安装
wget https://github.com/jonnenauha/prometheus_varnish_exporter/releases/latest/download/prometheus_varnish_exporter-linux-amd64.tar.gz
tar xzf prometheus_varnish_exporter-linux-amd64.tar.gz
sudo mv prometheus_varnish_exporter /usr/local/bin/

# 启动 exporter
prometheus_varnish_exporter -web.listen-address ":9131"

# 验证
curl http://localhost:9131/metrics

10.8.2 Prometheus 配置

# prometheus.yml
scrape_configs:
  - job_name: 'varnish'
    static_configs:
      - targets: ['localhost:9131']
    scrape_interval: 15s
    metrics_path: /metrics

10.8.3 Grafana 仪表盘

{
  "dashboard": {
    "title": "Varnish Cache",
    "panels": [
      {
        "title": "Cache Hit Rate",
        "targets": [{
          "expr": "rate(varnish_main_cache_hit[5m]) / (rate(varnish_main_cache_hit[5m]) + rate(varnish_main_cache_miss[5m])) * 100"
        }]
      },
      {
        "title": "Request Rate",
        "targets": [{
          "expr": "rate(varnish_main_client_req[5m])"
        }]
      },
      {
        "title": "Thread Count",
        "targets": [{
          "expr": "varnish_main_threads"
        }]
      },
      {
        "title": "Backend Health",
        "targets": [{
          "expr": "varnish_backend_healthy"
        }]
      }
    ]
  }
}

10.9 日志分析脚本

10.9.1 每日报告脚本

#!/bin/bash
# daily-report.sh - Varnish 每日报告

DATE=$(date '+%Y-%m-%d')
REPORT_FILE="/var/log/varnish/report-${DATE}.txt"

{
    echo "=== Varnish Daily Report: ${DATE} ==="
    echo ""

    echo "--- Cache Statistics ---"
    varnishstat -1 | grep -E "MAIN.cache_hit|MAIN.cache_miss|MAIN.client_req"
    echo ""

    echo "--- Top 20 URLs ---"
    varnishtop -1 -i ReqURL -n 20
    echo ""

    echo "--- Error Status Codes ---"
    varnishtop -1 -q 'RespStatus >= 400' -i RespStatus -n 10
    echo ""

    echo "--- Slowest Requests ---"
    varnishlog -g request -q 'Timestamp:Process[2] > 1.0' -i ReqURL,Timestamp:Process 2>/dev/null | head -20
    echo ""

    echo "--- Backend Errors ---"
    varnishlog -g request -q 'RespStatus >= 500' -i ReqURL,RespStatus,Backend 2>/dev/null | head -20

} > "$REPORT_FILE"

echo "Report saved to: ${REPORT_FILE}"

10.9.2 实时告警脚本

#!/bin/bash
# alert-monitor.sh - Varnish 实时告警

ALERT_EMAIL="[email protected]"
HITRATE_THRESHOLD=70
ERROR_THRESHOLD=100
THREAD_THRESHOLD=400

while true; do
    STATS=$(varnishstat -j)

    CACHE_HIT=$(echo "$STATS" | jq -r '.MAIN.cache_hit // 0')
    CACHE_MISS=$(echo "$STATS" | jq -r '.MAIN.cache_miss // 0')
    THREADS=$(echo "$STATS" | jq -r '.MAIN.threads // 0')
    ERRORS=$(echo "$STATS" | jq -r '.MAIN.client_req_500 // 0')

    TOTAL=$((CACHE_HIT + CACHE_MISS))
    if [ $TOTAL -gt 0 ]; then
        HITRATE=$(echo "scale=0; $CACHE_HIT * 100 / $TOTAL" | bc)

        if [ $HITRATE -lt $HITRATE_THRESHOLD ]; then
            echo "ALERT: Cache hit rate is ${HITRATE}%" | \
                mail -s "Varnish Alert: Low Hit Rate" "$ALERT_EMAIL"
        fi
    fi

    if [ $THREADS -gt $THREAD_THRESHOLD ]; then
        echo "ALERT: Thread count is ${THREADS}" | \
            mail -s "Varnish Alert: High Thread Count" "$ALERT_EMAIL"
    fi

    if [ $ERRORS -gt $ERROR_THRESHOLD ]; then
        echo "ALERT: 500 errors count is ${ERRORS}" | \
            mail -s "Varnish Alert: High Error Rate" "$ALERT_EMAIL"
    fi

    sleep 60
done

10.10 注意事项

重要
共享内存日志有大小限制，高流量场景需要调整 -l 参数
varnishlog 默认输出非常详细，生产环境使用过滤器
日志文件需要定期轮转，避免磁盘空间耗尽
监控告警阈值需要根据实际业务调整
JSON 格式的 varnishstat 输出便于与监控系统集成
使用 varnishlog -r 读取历史日志进行离线分析

Varnish Cache 运维教程 / 第10章：日志与监控

第10章：日志与监控

10.1 日志架构

10.1.1 共享内存日志（VSM）

10.1.2 日志工具概览

10.2 varnishlog

10.2.1 基本用法

10.2.2 过滤表达式

10.2.3 日志标签

10.2.4 日志输出格式

10.2.5 日志轮转

10.3 varnishstat

10.3.1 基本用法

10.3.2 关键计数器

10.3.3 计算缓存命中率

10.3.4 监控脚本

10.4 varnishtop

10.4.1 基本用法

10.4.2 常用命令

10.5 varnishhist

10.5.1 延迟直方图

10.6 varnishncsa

10.6.1 NCSA 日志格式

10.6.2 日志分析

10.7 自定义日志标签

10.7.1 VCL 中添加自定义标签

10.7.2 查询自定义标签

10.8 Prometheus 监控集成

10.8.1 varnish-exporter 安装

10.8.2 Prometheus 配置

10.8.3 Grafana 仪表盘

10.9 日志分析脚本

10.9.1 每日报告脚本

10.9.2 实时告警脚本

10.10 注意事项

10.11 扩展阅读