Varnishslog

varnishslog 读取 Varnish Cache VSL (二进制) 日志流，并生成结构化日志记录（JSON 格式）。

varnishslog 读取 Varnish VSL (二进制) 日志流，并构建访问会话模型

然后，这些数据将被扁平化并序列化为如下 JSON 格式

{
  "record_type": "client_request",
  "vxid": 32802,
  "remote_address": {
    "ip": "127.0.0.1",
    "port": 38650
  },
  "session_timestamp": 1476361595.724506,
  "start_timestamp": 1476361595.724543,
  "end_timestamp": 1476361595.869836,
  "handling": "miss",
  "request": {
    "protocol": "HTTP/1.1",
    "method": "GET",
    "url": "/",
    "headers": {
      "User-Agent": [
        "curl/7.40.0"
      ],
      "Accept": [
        "*/*"
      ],
      "Host": [
        "foo.net"
      ],
      "X-Forwarded-For": [
        "127.0.0.1"
      ]
    }
  },
  "response": {
    "status": 200,
    "reason": "OK",
    "protocol": "HTTP/1.1",
    "headers": {
      "Content-Type": [
        "text/html; charset=utf-8"
      ],
      "Date": [
        "Thu, 13 Oct 2016 12:26:35 GMT"
      ],
      "Etag": [
        "W/\"57973331\""
      ],
      "Vary": [
        "Accept-Encoding, Cookie, User-Agent"
      ],
      "Cache-Control": [
        "no-cache"
      ],
      "Accept-Ranges": [
        "bytes"
      ],
      "Transfer-Encoding": [
        "chunked"
      ],
      "Connection": [
        "keep-alive"
      ]
    }
  },
  "backend_access": {
    "vxid": 32803,
    "start_timestamp": 1476361595.724695,
    "end_timestamp": 1476361595.869323,
    "handling": "fetch",
    "request": {
      "protocol": "HTTP/1.1",
      "method": "GET",
      "url": "/",
      "headers": {
        "User-Agent": [
          "curl/7.40.0"
        ],
        "Accept": [
          "*/*"
        ],
        "Host": [
          "foo.net"
        ],
        "Accept-Encoding": [
          "gzip"
        ]
      }
    },
    "response": {
      "status": 200,
      "reason": "OK",
      "protocol": "HTTP/1.1",
      "headers": {
        "Cache-Control": [
          "private, must-revalidate, s-maxage=3644"
        ],
        "Content-Type": [
          "text/html; charset=utf-8"
        ],
        "Vary": [
          "X-Accept-Encoding"
        ],
        "Content-Encoding": [
          "gzip"
        ],
        "Etag": [
          "\"57973331\""
        ],
        "Content-Length": [
          "183806"
        ],
        "Accept-Ranges": [
          "bytes"
        ],
        "Date": [
          "Thu, 13 Oct 2016 12:26:35 GMT"
        ],
        "Age": [
          "0"
        ],
        "Connection": [
          "keep-alive"
        ],
        "Via": [
          "1.1 varnish (Varnish)"
        ]
      }
    },
    "send_duration": 0.000744,
    "wait_duration": 0.138199,
    "ttfb_duration": 0.138943,
    "fetch_duration": 0.144628,
    "sent_header_bytes": 539,
    "sent_body_bytes": 0,
    "sent_total_bytes": 539,
    "recv_header_bytes": 509,
    "recv_body_bytes": 183806,
    "recv_total_bytes": 184315,
    "retry": 0,
    "backend_connection": {
      "fd": 30,
      "name": "boot.origin_primary",
      "remote_address": {
        "ip": "10.1.1.333",
        "port": 80
      },
      "local_address": {
        "ip": "10.1.1.222",
        "port": 53964
      }
    },
    "cache_object": {
      "storage_type": "file",
      "storage_name": "s0",
      "ttl_duration": 3644.0,
      "grace_duration": 259200.0,
      "keep_duration": 0.0,
      "since_timestamp": 1476361596.0,
      "origin_timestamp": 1476361596.0,
      "fetch_mode": "length",
      "fetch_streamed": true,
      "response": {
        "status": 200,
        "reason": "OK",
        "protocol": "HTTP/1.1",
        "headers": {
          "Cache-Control": [
            "private, must-revalidate, s-maxage=3644"
          ],
          "Content-Type": [
            "text/html; charset=utf-8"
          ],
          "Vary": [
            "Accept-Encoding"
          ],
          "Content-Encoding": [
            "gzip"
          ],
          "Etag": [
            "\"57973331\""
          ],
          "Content-Length": [
            "183806"
          ],
          "Date": [
            "Thu, 13 Oct 2016 12:26:35 GMT"
          ],
          "Via": [
            "1.1 varnish (Varnish)"
          ]
        }
      }
    },
    "compression": {
      "operation": "Gunzip-test",
      "bytes_in": 183806,
      "bytes_out": 489611
    },
    "log": {
      "vars": {
        "decision": "Cacheable",
        "esi_parsed": "false",
        "compressable": "false",
        "cache_class": "Cache-Control"
      },
      "messages": [],
      "acl_matched": [],
      "acl_not_matched": []
    }
  },
  "process_duration": 0.0,
  "fetch_duration": 0.139311,
  "ttfb_duration": 0.139434,
  "serve_duration": 0.145293,
  "recv_header_bytes": 106,
  "recv_body_bytes": 0,
  "recv_total_bytes": 106,
  "sent_header_bytes": 283,
  "sent_body_bytes": 489611,
  "sent_total_bytes": 489894,
  "esi_count": 0,
  "compression": {
    "operation": "Gunzip",
    "bytes_in": 183806,
    "bytes_out": 489611
  },
  "restart_count": 0,
  "log": {
    "vars": {
      "client_device": "D",
      "client_country": "Unknown",
      "request_id": "rid-32802",
    },
    "messages": [
      "geoip2.lookup: No entry for this IP address (127.0.0.1)",
      "RES_MODE 48"
    ],
    "acl_matched": [
      "trusted_networks",
      "unthrottled_clients"
    ],
    "acl_not_matched": [
      "forbidden_clients"
    ]
  }
}

它还可以在前面加上 NCSA 类似的日志行，使其更兼容标准访问日志处理工具。

有关使用 serde 将数据反序列化为 Rust 类型的信息，请参阅 varnishslog-types。

兼容性

varnishslog 不会与 Varnish v3 兼容，因为与 v4 相比，VSL 存在显著差异。由于 v3 已停止使用，我目前没有计划支持 v3。

varnishslog v0.4.x 及以前的版本与 Varnish v4.1.3 进行了测试。

varnishslog v0.5.x 与 Varnish v5.2.1 进行了测试。

varnishslog v0.6.x 与 Varnish v6.1.1 进行了测试。请注意，Varnish v6.1.0 存在 VSL 兼容性错误，并且 varnishslog 与该特定版本的 Varnish 不会正确工作。此外，请注意，Varnish 从现在开始默认禁用了缓存对象响应的记录。要恢复 "cached_object"."response" 数据，请将 -p vsl_mask=+ObjProtocol,+ObjStatus,+ObjReason,+ObjHeader 添加到 varnishd 参数中。

varnishslog v0.7.0 与 Varnish v6.1.1（HTTP/2 和 PROXY v2（hitch）协议）进行了测试。

varnishslog v0.7.1 与 Varnish v6.2.0 进行了测试。

varnishslog v0.8.0 与 Varnish v6.6.1 进行了测试。修复了 PIPE 请求日志处理。

使用方法

要安装，您需要一个最新的 Rust 编译器（在 rustc 1.50.0 上进行了测试）：cargo install varnishslog

从源代码运行：cargo run --release

运行：varnishlog -g raw -w /dev/stdout | varnishslog > access.log

输出选项很少，并且对日志消息和索引的控制也很有限

Varnish Structured Logger 0.4.0
Jakub Pastuszek <jpastuszek@gmail.com>
Reads Varnish VSL (binary) log stream and emits JSON log entries to standard output

USAGE:
    varnishslog [FLAGS] [OPTIONS] [<VSL_FILE>]

FLAGS:
    -h, --help                  Prints help information
    -I, --keep-raw-headers      Keep raw header name/value pairs; any indices are moved to top level
    -L, --keep-raw-log          Include raw log messages
    -i, --no-header-indexing    Do not make indices of request and response headers with normalized header names
    -l, --no-log-processing     Do not process VSL log into vars, messages and ACL matches
    -V, --version               Prints version information

OPTIONS:
    -d, --log-sepc <LOG_LEVEL_SPEC>                    Logging level specification, e.g: info [default: info]
    -o, --output-format <output>                       Format of the output [default: NcsaJson]  [values: Log, LogDebug,
                                                       RecordDebug, SessionDebug, Json, JsonPretty, NcsaJson]
    -s, --stat-epoch-interval <stat-epoch-interval>
            Log store stats every epoch interval (~seconds) on record insert [default: 600]
        --evict-factor <evict-factor>
            Remove that many records at a time when doing expiration or nucking (ratio to max-record-slots) [default: 0.01]
        --max-epoch-diff <max-epoch-diff>
            Consider record being built or correlated as stale after that many epoch (~seconds) elapsed [default: 14410]
        --max-record-slots <max-record-slots>
            Maximum number of records being built or correlated at the same time [default: 4000]
        --stream-buffer-size <stream-buffer-size>
            Size of stream buffer in bytes - must be bigger than biggest VSL record [default: 262144]

ARGS:
    <VSL_FILE>    VSL file to process (read from standard input if not specified)

基准测试结果

使用13480个VSL记录（包括211个访问记录、86个会话和86个客户端访问记录）进行测试，大约每条输出客户端访问记录有157条VSL记录（benches/varnish20160816-4093-1xh1jbx808a493d5e74216e5.vsl）。该测试在MacBook Air（13英寸，2013年中期）上运行，使用rustc 1.14.0构建。

test log_session_record_ncsa_json ... bench:  14,940,553 ns/iter (+/- 4,323,366)
test log_session_record_json      ... bench:  15,029,912 ns/iter (+/- 3,922,717)
test log_session_record_json_raw  ... bench:   7,898,497 ns/iter (+/- 1,309,983)
test session_state                ... bench:   4,832,503 ns/iter (+/- 1,322,579)
test default_buffer_from_file     ... bench:     323,345 ns/iter (+/- 366,780)

• 5.8 K/s JSON记录（已索引）或902 K/s VSL记录处理成序列化输出
• 10.9 K/s JSON记录（原始）或1668 K/s VSL记录处理成序列化输出
• 17.8 K/s会话记录（关联访问记录）或2789 K/s VSL记录处理（不序列化）
• 41.6 M/s VSL记录从二进制流中提取（消息未解析）