小规模的日志处理和分析的教程

263 阅读8分钟

偶尔你需要处理一些HTTP服务器日志并从中提取分析数据。可能发生的情况是,你没有可用的企业级日志处理管道,知道如何使用已有的或容易引导的工具,手动处理和提取日志中的数据,是一件好事。

在讨论细节之前,有两个时刻你应该注意。

存储空间

日志通常被严重压缩,解压后会在你的硬盘上占用大量空间。例如,如果你有一个包含日志的10GiB归档文件,预计解压后会占用多达5-7倍的空间。而考虑到这种处理方法可能需要额外的空间,我宁愿拥有比压缩日志多7-10倍的自由空间。

这里的规则很简单--你的空间越小,处理日志所需的时间和精力就越多。也有一个选项可以即时解压日志,但会比处理未压缩的文件要慢。

存储速度

读取大量的日志时,这都是关于I/O的问题--存储速度越快越好。如果你的笔记本或电脑没有固态硬盘,而你打算处理几十G的日志,就会花费很多时间。

要测量你在Linux环境下的存储速度,你可以使用dd 命令(在我的例子中,是macOS上coreutilsgdd )。这些数字可以告诉你可能的最佳处理速度。

gdd if=/dev/zero bs=1024k of=testfile count=1024 oflag=dsync && \\
  gdd if=testfile bs=1024k of=/dev/null count=1024 oflag=dsync && \\
  rm testfile

1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB, 1.0 GiB) copied, 0.987115 s, 1.1 GB/s // Writing
1024+0 records in
1024+0 records out
1073741824 bytes (1.1 GB, 1.0 GiB) copied, 0.147887 s, 7.3 GB/s // Reading

日志格式

在野外有很多不同的日志格式。其中最普遍的是通用日志格式(CLF),它是Apache和Nginx HTTP服务器的默认日志格式。它是一种纯文本的固定格式,每个字段的位置由服务器的配置来定义。虽然这种格式很紧凑,但在不熟悉的情况下不容易阅读,或者服务器的配置与默认值不一样。它也很难被机器读取。下面是一个Nginx服务器配置和它产生的日志的例子。

log_format combined '$remote_addr - $remote_user [$time_local] '
                    '"$request" $status $body_bytes_sent '
                    '"$http_referer" "$http_user_agent"';

...

127.0.0.1 - - [19/Nov/2021:14:32:11 +0000] "GET / HTTP/1.1" 200 1664 "-" "curl/7.77.0"
127.0.0.1 - - [19/Nov/2021:14:32:11 +0000] "GET /teapot HTTP/1.1" 418 0 "-" "curl/7.77.0"
127.0.0.1 - - [19/Nov/2021:14:32:11 +0000] "GET /foo HTTP/1.1" 404 153 "-" "curl/7.77.0"

你可能遇到的另一种格式是JSON格式的结构化日志。这种格式对人类和机器来说都很容易阅读。它也可以被大多数编程语言所解析。Nginx配置和JSON格式的日志实例。

log_format combined-json escape=json
  '{'
      '"remote_addr":"$remote_addr",'
      '"remote_user":"$remote_user",'
      '"time_local":"$time_local",'
      '"request":"$request",'
      '"status": "$status",'
      '"body_bytes_sent":"$body_bytes_sent",'
      '"http_referrer":"$http_referer",'
      '"http_user_agent":"$http_user_agent"'
  '}';

...

{"remote_addr":"127.0.0.1","remote_user":"","time_local":"19/Nov/2021:14:31:28 +0000","request":"GET / HTTP/1.1","status": "200","body_bytes_sent":"1664","http_referrer":"","http_user_agent":"curl/7.77.0"}
{"remote_addr":"127.0.0.1","remote_user":"","time_local":"19/Nov/2021:14:31:28 +0000","request":"GET /teapot HTTP/1.1","status": "418","body_bytes_sent":"0","http_referrer":"","http_user_agent":"curl/7.77.0"}
{"remote_addr":"127.0.0.1","remote_user":"","time_local":"19/Nov/2021:14:31:28 +0000","request":"GET /foo HTTP/1.1","status": "404","body_bytes_sent":"153","http_referrer":"","http_user_agent":"curl/7.77.0"}

命令行工具

当你需要从日志中提取和计算一些数据时,首先想到的是Linux命令行工具。这些工具(或实用程序)并不是专门为处理日志而创建的,但结合起来就非常灵活和强大。而且,最方便的是--它们已经有了。下面是一些例子,说明如何使用像grep,awk ,以及其他工具。

查找日志文件中有多少405方法不允许的响应。

time grep "\\" 405 " access.log | wc -l
   11305

________________________________________________________
Executed in   58.56 secs    fish           external
   usr time   57.02 secs    0.27 millis   57.02 secs
   sys time    1.22 secs    1.32 millis    1.22 secs

注意405周围的额外字符--因为CLF缺乏结构,该模式指定了值,但也试图限制在字符串中寻找它。同样的grep但没有限制会返回不同的结果,这是不正确的。

外壳

grep "405" access.log | wc -l # Wrong result!
    8824

计算每个状态代码在一个文件中的数量,按计数降序排序。输出也显示了CLF的另一个问题--按空格分割并不总是像预期的那样,你可以在输出中得到一些垃圾。但对于大多数情况,这应该是可以的。

外壳

time awk '{print $9}' access.log | sort | uniq -c | sort -nr
21510839 404
889766 200
115696 400
14718 304
11305 405
8777 206
3948 416
3146 403
2908 411
1097 HTTP/1.0\\" # Looks like log lines contained space in $remote_user field!
  26 /vicidial/admin.php
  26 /scripts/admin.php
  26 /cgi-bin/admin.php
  26 /admin.php
   7 499
   4 412

________________________________________________________
Executed in   24.48 secs    fish           external
   usr time   30.88 secs    0.39 millis   30.88 secs
   sys time    1.99 secs    1.68 millis    1.99 secs

正如你所看到的,一个选择和汇总数据的命令很快变得越来越复杂。它也变得难以调试,而且有些命令需要很长时间才能完成。总之,在处理少量的日志时,对于简单的一次性查询来说,这是一个很好的方法。

但是,如果你要看10多个GiB的日志,并且想运行相当复杂的查询,有一个更好的方法--将半结构化的数据转换成结构良好的数据,并使用数据库来运行查询。

数据库

数据库是一个处理数据的伟大工具。

  • 它与结构良好的数据一起工作,所以结果中不再有垃圾。
  • 大多数数据库使用相同的老式SQL来检索数据。
  • 在非生产环境中,数据库的设置相当容易。
  • 由于数据的存储方式,查询的运行速度一般比从磁盘上读取文件要快。

大多数开发人员都熟悉MySQL和PostgreSQL。它们是很好的RDBMS,可以用来运行有一些限制的分析查询。只是大多数关系型数据库不是为运行数千万行的查询而设计的。然而,有一些数据库专门为这种情况进行了优化--面向列的DBMS。这种数据库的一个很好的例子是ClickHouse。让我们试试吧。

为了将日志加载到数据库中,它们需要采用数据库能够理解的结构化格式。这意味着JSON格式的日志可以直接加载到数据库中。CLF日志需要转换为CSV格式。我发现,最好的方法是使用perl 和正则表达式。

Shell

perl -ne 'print if s/^(.*?) - .*? \\[([^:]*?):(.*?) .*?\\] "(.*?) (.*?) (HTTP\\/.*?)" (.*?) (.*?) "(.*?)" "(.*?)"$/$1,"$2 $3",$4,"$5",$6,$7,$8,"$9","$10"/g' < access.log > access.csv

要在你的笔记本电脑上运行一些分析性查询,你不需要投入大量的精力来配置数据库服务器--只需下载服务器并从命令行中运行。

# MacOS x86_64
curl -O 'https://builds.clickhouse.com/master/macos/clickhouse' && chmod a+x ./clickhouse

# Create directory for ClickHouse data files/directories
mkdir data

# ClickHouse will use the current directory to create files
cd data

# Start the server
./../clickhouse server
Processing configuration file 'config.xml'.
There is no file 'config.xml', will use embedded config.
Logging trace to console
2021.12.31 19:49:27.682457 [ 3587768 ] {} <Information> : Starting ClickHouse 21.12.1.8928 with revision 54457, no build id, PID 14099

在新的控制台连接到服务器,为我们的日志文件创建一个数据库和表。

./clickhouse client --multiline
ClickHouse client version 21.12.1.8928 (official build).
Connecting to localhost:9000 as user default.
Connected to ClickHouse server version 21.12.1 revision 54451.

:) CREATE DATABASE IF NOT EXISTS logs;

CREATE DATABASE IF NOT EXISTS logs

Query id: 3c376c00-1969-41df-af0c-099174e2e32b

Ok.

0 rows in set. Elapsed: 0.002 sec.

:) CREATE TABLE IF NOT EXISTS logs.access
:-] (
:-]     remote_addr String,
:-]     time_local DateTime,
:-]     request_method String,
:-]     request_uri String,
:-]     http_version String,
:-]     status Int32,
:-]     body_bytes_sent Int64,
:-]     http_referrer String,
:-]     http_user_agent String
:-] )
:-] ENGINE = MergeTree()
:-] ORDER BY tuple();

CREATE TABLE IF NOT EXISTS logs.access
(
    `remote_addr` String,
    `time_local` DateTime,
    `request_method` String,
    `request_uri` String,
    `http_version` String,
    `status` Int32,
    `body_bytes_sent` Int64,
    `http_referrer` String,
    `http_user_agent` String
)
ENGINE = MergeTree
ORDER BY tuple()

Query id: 501fa6b3-a16e-4c97-bb40-2d7d58b997ba

Ok.

0 rows in set. Elapsed: 0.005 sec.

:) ^C
:) Bye.

现在让我们加载我们的数据并运行一些查询。

壳牌

# Load data to logs.access table from csv file
./clickhouse client --date_time_input_format='best_effort' --query="INSERT INTO logs.access FORMAT CSV" < access.csv

查找有多少个405方法不允许的响应

:) SELECT count() FROM logs.access WHERE status=405;

SELECT count()
FROM logs.access
WHERE status = 405

Query id: 76b40738-354c-4ad0-a815-6bf9e211fb54

┌─count()─┐
│   11305 │
└─────────┘

1 rows in set. Elapsed: 0.037 sec. Processed 22.56 million rows, 90.25 MB (607.73 million rows/s., 2.43 GB/s.)

计算每个状态代码有多少个,按计数降序排序。

SQL

:) SELECT count(), status FROM logs.access GROUP BY status ORDER BY count() DESC;

SELECT
    count(),
    status
FROM logs.access
GROUP BY status
ORDER BY count() DESC

Query id: f9d01465-54ca-4e73-a961-be2f695ded91

┌──count()─┬─status─┐
│ 21512196404 │
│   889766200 │
│   115800400 │
│    14718304 │
│    11305405 │
│     8777206 │
│     3948416 │
│     3146403 │
│     2908411 │
│        7499 │
│        4412 │
└──────────┴────────┘

11 rows in set. Elapsed: 0.045 sec. Processed 22.56 million rows, 90.25 MB (502.02 million rows/s., 2.01 GB/s.)

现在你可以玩玩数据了,不用无休止地等待每个查询的完成。享受一下吧!