玩轉 Syslog 第一次就上手
Introduction to Syslog
任何運行中的系統都會有 Log,主要是為了方便除錯、監控以及分析等等的
可以說沒有 Log 的系統是沒有辦法運作的
在 網頁程式設計三兩事 - Logging 最佳實踐 | Shawn Hsu 中我們已經知道說針對 application 怎麼設計良好的 Log 系統
而光是擁有 application log 其實是不足的
你可能會需要更底層的 Log 來幫助你監控整體系統
比方說你也需要知道 Kernel 的 Log, 更甚至是 Router 的 Log
也就是說,擁有一個統整的 Log 系統在某些時候是重要的
Syslog 的概念就是,我擁有一個統一的系統,可以處理不同來源的 Log
將它統一收集,封存(audit 相關)起來,方便後續的分析與追蹤
這個統一的系統由於需要跨網路收集,因此是屬於 client-server
的架構
Syslog Server 負責接收 Client 的 Log 並做後續處理
Background
我個人覺得 Syslog 的歷史其實滿曲折的
當初是在 University of California, BSD TCP/IP 的系統上實作的
在後來 Syslog 的標準被廣泛的系統採納並支持,逐漸成為行業的標準
話雖如此,該 “標準” 其實並沒有正式成為 IETF 的標準
RFC 3164 中僅僅只是記錄了當時的實作方式
所以你可以看到 Category 歸類為
Informational
而真正納入 IETF 標準的是 RFC 5424
不過由於 RFC 3164 是當時的實作方式,為了相容性,現今仍然兩者並存居多
RFC 3164
1
<PRI>TIMESTAMP HOSTNAME TAG: MESSAGE
當時為了能夠區分哪一種資訊是 Syslog,因此他們刻意了定義了上述的格式
只要看到這種格式的資料,哦你就可以確定說他是 Syslog 這樣
整個 Log 分三段,分別是 PRI
, HEADER
, MESSAGE
-
PRI
是 Priority Value,可以參考 Syslog Priority -
HEADER
,包含TIMESTAMP
(format:MMM DD hh:mm:ss
),HOSTNAME
-
MESSAGE
,包含TAG
(service name 或是 process id),CONTENT
Section | Field | Description |
---|---|---|
PRI | Priority Value | 可參考 Syslog Priority |
HEADER | TIMESTAMP | 格式: MMM DD hh:mm:ss
|
HEADER | HOSTNAME | 只能是 hostname , ipv4 或是 ipv6 ,不能是 domain name
|
MESSAGE | TAG | 服務名稱或是 process id,只能是 字母數字
|
MESSAGE | CONTENT | 有用的資訊 |
舉例來說一個合法的 RFC 3164 的 Log 是這樣
1
<34>Oct 11 22:14:15 mymachine su: 'su root' failed for lonvick on /dev/pts/8
可以看到說,上述的 Message Tag 為 su
因為他只能包含字母數字,所以 :
會被歸類在 content 裡面
RFC 5424
我們提到 RFC 3164 僅僅只是個紀錄,他其實不算是一個標準
非標準的壞處就是大家各自有各自的實作方式,久而久之其實就會有相容性的問題
RFC 5424 的出現旨在淘汰舊的實作方式,並提供業界一套標準的格式
除了更改格式,RFC 5424 抽離了對 transport protocol 的依賴
在 RFC 3164 中,預設是走 UDP 傳輸
而這大大的限縮了 Syslog 的應用場景 應該說不夠彈性
RFC 5424 中,並沒有規定一定要使用哪一種傳輸協議
但是為了相容性,他還是支持 UDP 的傳輸方式
因為 RFC 3164 的格式其實能夠表達的東西不夠多
改良後的格式為
1
<PRI> VERSION TIMESTAMP HOSTNAME APP-NAME PROCID MSGID [SD-ID * (SD-PARAM-NAME="SD-PARAM-VALUE")] MSG
Section | Field | Description | Nil Value |
---|---|---|---|
PRI | Priority Value | 可參考 Syslog Priority | ![]() |
VERSION | Version |
1 用以標示 Syslog Protocol 的版本, 5424 是 1
|
![]() |
TIMESTAMP | Timestamp | 格式為 RFC 3339 | ![]() |
HOSTNAME | Hostname | 格式為 RFC 1034,或是部分資料如 hostname, ip 等 | ![]() |
APP-NAME | Application Name | 服務名稱或是 process id,只能是 字母數字
|
![]() |
PROCID | Process ID | 只能是 字母數字
|
![]() |
MSGID | Message ID | 只能是 字母數字
|
![]() |
SD-ID | Structured Data ID | 只能是 字母數字
|
![]() |
SD-PARAM-NAME | Structured Data Parameter Name | 只能是 字母數字
|
![]() |
SD-PARAM-VALUE | Structured Data Parameter Value | 只能是 字母數字
|
![]() |
MSG | Message | log 訊息 | ![]() |
額外的補充資料是一個 array 的結構,本身可以是空的
1
[exampleSDID@32473 iut="3" eventSource="Application" eventID="1011"][examplePriority@32473 class="high"]
比方說上述擁有兩個部分 exampleSDID@32473
以及 examplePriority@32473
分組的用意在於說他底下的 key-value pair 都是屬於該區段的,給予較高的可讀性
舉例來說一個合法的 RFC 5424 的 Log 是這樣
1
<34>1 2025-06-20T01:27:42Z myhostname myapp 12345 99 - [exampleSDID@32473 iut="1" eventSource="application" eventID="1011"] Test message content
Syslog Priority
Priority Value 是由 Facility
以及 Severity
組成
這個欄位的用意是告訴你這個 Log 的優先程度,哪個服務,有多嚴重這樣
你可以透過 PRI 的數值決定你的 Syslog 要怎麼處理
針對服務的數值,如果你沒有一個可以選,他有 reserved facility 可以使用,是
16 ~ 23
問題是,兩個數字怎麼組合起來
公式是 (Facility * 8) + Severity
所以你會得到一個 0 ~ 191
的數值
這個數值就是 PRI 的值
Facility | Numerical Code | Severity | Numerical Code | |
---|---|---|---|---|
0 | kernel messages | 0 | emergency | |
1 | user-level messages | 1 | alert | |
2 | mail system | 2 | critical | |
3 | system daemons | 3 | error | |
4 | security/authorization messages | 4 | warning | |
5 | messages generated internally by syslogd | 5 | notice | |
6 | line printer subsystem | 6 | informational | |
7 | network news subsystem | 7 | debug | |
8 | UUCP subsystem | |||
9 | clock daemon | |||
10 | security/authorization messages | |||
11 | FTP daemon | |||
12 | NTP subsystem | |||
13 | log audit | |||
14 | log alert | |||
15 | clock daemon | |||
16 ~ 23 | local use |
Syslog Transport
既然他是 client-server 的架構,並且需要跨網路收集,很明顯傳輸是一項重要的事情
RFC 3164 中提到說,預設是走 UDP 傳輸
預設是 514
的 port,然後建議 server 以及 client 都使用這個 port
ref: RFC 5426(Transmission of Syslog Messages over UDP)
至於 RFC 5424 中,並沒有規定一定要使用哪一種傳輸協議
所以 TCP 或 UDP 都是可以的
不過標準提到他 必須支援 TLS-based
的傳輸方式(ref: RFC 5425)
但他只說要支援,你也可以 不要使用 TLS
的傳輸方式
ref: RFC 6587(Transmission of Syslog Messages over TCP)
Acknowledgment and Reliability
Syslog 本身是一個相對簡單的 protocol
所以它本身其實沒有任何關於 Acknowledgement 的機制
可靠性傳輸實際上是依靠上層傳輸協議的實作而定
如果不依賴 TCP 之類的,他其實是沒有辦法保證傳輸的可靠性
比如說 legacy 的 Syslog protocol 指定使用 UDP 傳輸
除此之外,數據正確性也是沒有保障的
即使擁有 Checksum 機制,由於 hash 碰撞的特性,同樣的 Checksum 也無法保證相同資料
Data Fragmentation
凡事碰到網路傳輸,我們其實最害怕的就是掉資料
Syslog 其實也會遇到這種問題,而前面提過說他實際上是依賴上層傳輸協議的實作
Syslog protocol 本身並沒有提供任何的機制來保證傳輸的可靠性
為了應對這種辦法,RFC 3164 中提到說
你應該盡量將資料縮小,建議的大小是 1024 bytes
(在很古老的 Syslog 系統下小於 1024 會出問題)
雖然 UDP 理論上可以吃到 65535 bytes
不過他會遇到 Fragmentation 的問題
傳統 Syslog server/receiver 需要能夠處理 480 ~ 2048 bytes 的資料
UDP 是 IP 層以上的傳輸協議,他底層依賴於 IP 層的機制
雖然 UDP 可以一次送 65535 bytes 的資料
但是 IP 層會有 MTU 的限制,也就是說太大的資料本質上會被拆成很多小份資料傳輸
這其實會對 Syslog 有一定的影響,因為 會掉資料
還是要強調 Syslog 是很簡單的協定,他也不希望為了處理這種事情而變得複雜
不想掉資料又想要在一定程度上保持簡潔,所以他會建議每一筆的資料大小限制在 1024 bytes
這個大小是需要調整的,跨網路傳輸要設定成 網路上最小的 MTU 大小(因為要大家都能傳,所以是最小)
一次只傳一筆,一筆資料剛好是路徑上最小的 MTU 大小
這可以在最大程度上避免 Fragmentation 的問題
多筆資料也是不建議的,雖然 Syslog 本身有 Timestamp,不過如果遇到相同時間戳記仍然會有問題
也無法保證順序
那 TCP 呢?
Syslog 將所有他不想做的事情外包給 TCP 處理
事實上他也做得挺好的
UDP 是 message based 的傳輸協議,也就是傳一筆收一筆
TCP 則是 stream based 的傳輸協議,也就是傳一坨收一坨
你需要有一個辦法分別他的斷點在哪,常見的就是使用 換行
區隔
稱為 Non-transparent Framing
Non-transparent Framing
採用換行符號來區隔不同的資料實務上會有問題
因為傳統上那些特殊字元是沒有跳脫的
導致接收端在處理的時候會錯誤
比如說如果一筆資料裡面有多個換行符號
他就會被誤拆成多筆資料
Octet Counting
怎麼解決 Non-transparent Framing 的問題其實也滿簡單的
既然換行符號不嚴謹,我是不是能夠告訴你這個資料長度,然後再給你開頭
無論資料裡面是啥,都能夠正確處理?
具體來說就只是在開頭加上資料長度
而這出乎意料的好用,並且簡單
syslog-ng
接下來就讓我們使用 syslog-ng 把 Server 架設起來觀察
syslog-ng 預設的 config 是使用 default-network-drivers
(可參考 syslog-ng Open Source Edition 3.16 - Release Notes)
長這樣
注意到你不需要額外撰寫 config, 這是預設的
阿如果要更改也一樣是改/etc/syslog-ng/syslog-ng.conf
這個檔案
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
@version: 4.8
@include "scl.conf"
source s_local {
internal();
};
source s_network {
default-network-drivers(
# NOTE: TLS support
#
# the default-network-drivers() source driver opens the TLS
# enabled ports as well, however without an actual key/cert
# pair they will not operate and syslog-ng would display a
# warning at startup.
#
#tls(key-file("/path/to/ssl-private-key") cert-file("/path/to/ssl-cert"))
);
};
destination d_local {
file("/var/log/messages");
file("/var/log/messages-kv.log" template("$ISODATE $HOST $(format-welf --scope all-nv-pairs)\n") frac-digits(3));
};
log {
source(s_local);
source(s_network);
destination(d_local);
};
要使用
default-network-drivers
需要有@include "scl.conf"
這行
這個 default-network-drivers 可以接收來自以下的設定
跑起來就會是這樣
注意到同一個 port 可以 forward TCP 以及 UDP
1
2
3
4
5
6
7
$ docker run -d \
--name syslog-ng-server \
-p 514:514/tcp \
-p 515:514/udp \
-p 601:601 \
balabit/syslog-ng:latest \
--no-caps
Everything Compatible with RFC 3164?
測試基本的 3164 格式
1
$ echo "<34>Oct 11 22:14:15 mymachine su: 'su root' failed for lonvick on /dev/pts/8" | nc localhost 514
可以看到說他有被正確的讀取為 3164 的格式 TCP
然後各個欄位都有正確的被解析
可以看到 UDP 也是妥妥的
然後我就很好奇,如果只傳一個 hello world
過去會發生什麼事情
為了觀察沒有給定 PRI 的資料,config 要稍微更改一下
1
$ISODATE $PRI $HOST $(format-welf --scope all-nv-pairs)\n
多加一個 \$PRI
讓我們觀察
神奇了! 居然會過????
你可以看到說,timestamp
、priority
甚至是 hostname
都有被正確的指派
這肯定是我們漏掉了什麼
其實 RFC 3164 中提到說,如果沒有給定以上三者的資料 他會自己幫你補齊
-
hostname
會填自己的 hostname(而192.168.215.1
正是我的 container 的 IP) -
timestamp
會填現在的時間(你可以看到資料時間其實是早於 Syslog connection accepted 的時間) -
priority
會填13
(user-level + notice)
取得 container 的 IP 可以用
$ docker inspect <container_id>
也就是說,其實你隨便打都會過 3164 的格式
因為他會幫你自動帶入這些資料
所以其實不是不會驗格式,是他會幫你補齊
Invalid Frame Header with RFC 5424?
1
$ echo "<34>1 2025-06-20T01:27:42Z myhostname myapp 12345 99 - [exampleSDID@32473 iut="1" eventSource="application" eventID="1011"] Test message content" | nc localhost 601
恩? Invalid Frame Header
這其實是因為稍早我們提過的 Non-transparent Framing 的問題
所以我們要新增長度方便進行切割(i.e. Octet Counting)
上述資料長度可以透過以下指令取得
1
2
$ echo "<34>1 2025-06-20T01:27:42Z myhostname myapp 12345 99 - [exampleSDID@32473 iut="1" eventSource="application" eventID="1011"] Test message content" | wc -c
139
所以完整的指令會是
1
$ echo -n "139 <34>1 2025-06-20T01:27:42Z myhostname myapp 12345 99 - [exampleSDID@32473 iut="1" eventSource="application" eventID="1011"] Test aessage content" | nc localhost 601
Leave a comment