研究室内の共有ログサーバを公開してから1ヶ月が経過しました．この記事ではログサーバの現状とログを分析してみます．
Syslogの分析
過去1ヶ月のログサーバにSyslogプロトコルで転送されたログ件数を送信元のホスト別で集計した積み上げ折れ線グラフが以下です．X軸は時間軸で横軸の各点は12時間ごとに存在します．Y軸はログ件数をあらわします．凡例はホスト名をあらわし，それぞれ以下の役割があります．
- Synology NAS: tapioca, natadecoco
- Wi-Fiルータ: TUF-AX-5400-DFD8-AA..
- VMware ESXi: plum, violet, rose, lotus, jasmine, mint, lily
ピーク時には，12時間あたりに140万件をこえるログが出力されています．これまで1ヶ月に受信したログ件数は43,233,192でした．特にVMWare ESXiのsyslogが全体の中では件数が多いです．
以下はSyslogプロトコルでログサーバに転送されたログの1ヶ月分をプログラム名ごとに集計した折れ線グラフです．X軸は時間軸をあらわし12時間ごとに各点が存在します．Y軸はログ件数をあらわします．凡例はSyslogのprogramnameフィールドごとに上位5種類とそれ以外(Other)をあらわします．このグラフではenvoyによるログの件数が最も多く，次にHostdによるログが次に多いです．これらはVMware ESXiから出力されているもので，EnvoyはPrometheusのvmware-exporterによるヘルスチェックに伴って出力されていました．
以下はSyslogプロトコルでログサーバに転送されたログの1ヶ月分を重大度ごとに集計した折れ線グラフです．X軸は時間軸をあらわし12時間ごとに各点が存在します．Y軸はログ件数をあらわします．凡例は重大度をあわらします．このグラフの結果から重大度がInformationalのログ件数が最も多いことを示しています．ほかの重大度のログはErrorがInformationalの次に多く存在しました．Informationalのログが大部分をしめており，収集するログレベルの見直しが必要だと感じました．
以下の表は過去1ヶ月分のSyslogをログメッセージごとに件数を集計した結果(上位20件)です．上位2件は，base64でエンコードされたログでエンコードするとGlibvmacore.soやPRRxlibpthread.so.0?Rlibc.so.6といった文字列が得られました．集計結果の後半では DHCPACK from 192.168.100.35 のように常にDHCPクライアントから出力されているログがありました．
| ログメッセージ | ログ件数(1ヶ月) |
| –> [context]zKq7AVICAgAAACWJdAEJaG9zdGQAAOPJR2xpYnZtYWNvcmUuc28AAL4fPQBLLywAlDIsAB7bLADg/ywAO1BSAVJ4AGxpYnB0aHJlYWQuc28uMAACP1IPbGliYy5zby42AA==[/context] | 362,059 |
| –> [context]zKq7AVICAgAAAP////8Jc2FuZGJveGQAAOPJR2xpYnZtYWNvcmUuc28AAL4fPQBLLywAlDIsAB7bLADg/ywAO1BSAVJ4AGxpYnB0aHJlYWQuc28uMAACP1IPbGliYy5zby42AA==[/context] | 290,569 |
| [Originator@6876 sub=PluginLauncher] Peak requested reservation (MB): 40, Peak requested reservation of children groups (MB): 40 | 219,509 |
| [Originator@6876 sub=PluginLauncher] 0 subgroups present in group 711 | 206,235 |
| VMWARE-ENV-MIB offline extract from ipmi failed | 88,885 |
| open_dev: open device ‘/dev/ipmi0’ failed 2 No such file or directory, device sensors offline | 88,833 |
| DHCPACK from 192.168.100.35 | 42,420 |
| DHCPREQUEST on vmk0 to 192.168.100.35 port 67 | 42,412 |
| new_dhcp_rebinding_time=400 | 38,642 |
| new_dhcp_renewal_time=300 | 38,642 |
| dhcp_renew_handler reason: RENEW | 38,640 |
| new_dhcp_message_type=5 | 38,640 |
| new_dhcp_server_identifier=192.168.100.35 | 38,640 |
| new_domain_name_servers=192.168.100.35 10.200.70.35 | 38,640 |
| new_routers=192.168.100.1 | 38,638 |
| new_dhcp_lease_time=600 | 38,637 |
| new_broadcast_address=192.168.100.255 | 38,635 |
| new_subnet_mask=255.255.255.0 | 38,635 |
| new_network_number=192.168.100.0 | 38,633 |
| old_dhcp_rebinding_time=400 | 37,764 |
おわりに
今回はSyslogプロトコルで共有ログサーバに転送されていたログを集計してみました．今後はBeatsやWebアクセスログの分析も引き続き取り組んでいきたいと思います．こうしたデータセットをうまく学外にも提供していきたいです．ご興味があればコンタクトフォームよりご連絡ください．