6 minute read     Posted on:     Updated on:     Views: Loading...

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 :x:
VERSION Version 1 用以標示 Syslog Protocol 的版本, 5424 是 1 :x:
TIMESTAMP Timestamp 格式為 RFC 3339 :heavy_check_mark:
HOSTNAME Hostname 格式為 RFC 1034,或是部分資料如 hostname, ip 等 :heavy_check_mark:
APP-NAME Application Name 服務名稱或是 process id,只能是 字母數字 :heavy_check_mark:
PROCID Process ID 只能是 字母數字 :heavy_check_mark:
MSGID Message ID 只能是 字母數字 :heavy_check_mark:
SD-ID Structured Data ID 只能是 字母數字 :x:
SD-PARAM-NAME Structured Data Parameter Name 只能是 字母數字 :x:
SD-PARAM-VALUE Structured Data Parameter Value 只能是 字母數字 :x:
MSG Message log 訊息 :heavy_check_mark:

額外的補充資料是一個 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 中,並沒有規定一定要使用哪一種傳輸協議
所以 TCPUDP 都是可以的
不過標準提到他 必須支援 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 讓我們觀察

神奇了! 居然會過????
你可以看到說,timestamppriority 甚至是 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

References

Leave a comment