调试 OpenWRT 网络组件和用户软件时,需要通过日志信息的分析,来解决系统问题;产品上线质量跟踪也需要日志信息来分析产品bug,因此系统日志使用非常重要,本篇记录 OpenWRT-19.07 版本日志开启和日志自动上报至服务器的过程。
1. 运行环境说明
- 服务器端 采用 ubuntu-16.04 系统自动安装的 rsyslog 组件;
- OpenWRT -19.07 系统移植 syslog 组件;
- 客户端 采用 mtk7621 路由器。
2. 服务端 ubuntu16 系统 rsyslog 参数配置
2.1 rsyslog的参数配置文件 etc/rsyslog.conf
# /etc/rsyslog.conf Configuration file for rsyslog.
#
# For more information see
# /usr/share/doc/rsyslog-doc/html/rsyslog_conf.html
#
# Default logging rules can be found in /etc/rsyslog.d/50-default.conf
module(load="imuxsock") # provides support for local system logging
module(load="imklog") # provides kernel logging support
#module(load="immark") # provides --MARK-- message capability
# provides UDP syslog reception
module(load="imudp")
input(type="imudp" port="514") # 打开服务端udp监听端口
# provides TCP syslog reception
module(load="imtcp")
input(type="imtcp" port="514") # 打开服务端tcp监听端口
# Enable non-kernel facility klog messages
$KLogPermitNonKernelFacility on
###########################
#### GLOBAL DIRECTIVES ####
###########################
#
# Use traditional timestamp format.
# To enable high precision timestamps, comment out the following line.
#
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
# Filter duplicated messages
$RepeatedMsgReduction on
#
# Set the default permissions for all log files.
#
$FileOwner syslog
$FileGroup adm
$FileCreateMode 0640
$DirCreateMode 0755
$Umask 0022
$PrivDropToUser syslog
$PrivDropToGroup syslog
#
# Where to place spool and state files
#
$WorkDirectory /var/spool/rsyslog # 服务器端接收的日志内容存储路径
#
# Include all config files in /etc/rsyslog.d/
#
$IncludeConfig /etc/rsyslog.d/*.conf # rsyslog 配置文件集的路径,用户可补充自定义日志存储、打包、删除规则
2.2 配置日志文件存储规则
在 /etc/rsyslog.d/ 新建 router.conf 配置文件,配置接收日志文件的文件名,内容如下:
root@ubuntu:/# cat /etc/rsyslog.d/router.conf
#
:FROMHOST-IP,startswith, "192.168.90." /var/spool/rsyslog/%fromhost-ip%-%HOSTNAME%-%$YEAR%-%$MONTH%-%$DAY%.log
:fromhost-ip,isequal,"192.168.1.1" /var/spool/rsyslog/%fromhost-ip%-%HOSTNAME%-%$YEAR%-%$MONTH%-%$DAY%.log
&~ #表示接收日志不用写入本地日志文件
2.3 重启 rsyslog 服务、检测服务开启状态
sudo service rsyslog restart
sudo netstat -tulpn | grep rsyslog
root@ubuntu:/# netstat -tulpn|grep rsyslog
tcp 0 0 0.0.0.0:514 0.0.0.0:* LISTEN 8778/rsyslogd
tcp6 0 0 :::514 :::* LISTEN 8778/rsyslogd
udp 0 0 0.0.0.0:514 0.0.0.0:* 8778/rsyslogd
udp6 0 0 :::514 :::* 8778/rsyslogd
3. 客户端 OpenWRT系统syslog 移植和参数配置
3.1 配置syslog 组件
make menuconfig 选择 syslog 组件,路径如
Base system
busybox… Core utilities for embedded Linux
System Logging Utilities
选择内容
[*] syslogd (13 kb) │ │
[*] Rotate message files │ │
[*] Remote Log support │ │
[*] Support -D (drop dups) option │ │
[*] Support syslog.conf │ │
(256) Read buffer size in bytes │ │
[*] Circular Buffer support │ │
(4) Circular buffer size in Kbytes (minimum 4KB) │ │
[*] Linux kernel printk buffer support
编译烧写到 mtk7621 路由器。
3.2 开启路由器日志
- 第一种方法:通过uci set 命令配置syslog的参数,内容如下:
例:
uci set system.system.log_file=/tmp/syslog
配置后的内容如下:
config system
option hostname 'OpenWrt'
option ttylogin '0'
option log_size '64'
option urandom_seed '0'
# 以下内容是 syslog 配置参数
option log_ip '192.168.90.180' #日志上报的服务器端地址
option log_file '/tmp/syslog' #本地日志文件存储位置
option conloglevel '7'
option cronloglevel '8'
option log_proto 'udp' #上报采用udp通讯
# 以下时区配置信息
option zonename 'Asia/Shanghai'
option timezone 'CST-8'
- 第二种方法: 通过 openWRT 的 WEB 管理界面配置
登录配置界面后,配置页面路径: 系统 ->> 系统 ->> 日志。
4. 验证客户端 syslog 本地日志
查看本地日志文件root@eCloud:~# cat /tmp/syslog,内容如下:
Thu Jun 17 08:10:47 2021 daemon.info logread[10237]: Logread connected to 192.168.90.180:514
Thu Jun 17 08:12:27 2021 daemon.warn zabbix_agentd[17566]: active check configuration update from [172.16.29.171:10051] started to fail (ZBX_TCP_READ() timed out)
Thu Jun 17 08:13:14 2021 daemon.err uhttpd[4723]: luci: accepted login on / for root from 192.168.90.29
Thu Jun 17 08:13:27 2021 daemon.warn zabbix_agentd[17566]: active check configuration update from [172.16.29.171:10051] is working again
Thu Jun 17 08:16:00 2021 daemon.err netdata[6426]: PROCFILE: Cannot open file '/proc/sysvipc/shm'
Thu Jun 17 08:16:42 2021 daemon.info dnsmasq[3711]: read /etc/hosts - 4 addresses
Thu Jun 17 08:16:42 2021 daemon.info dnsmasq[3711]: read /tmp/hosts/odhcpd - 0 addresses
Thu Jun 17 08:16:42 2021 daemon.info dnsmasq[3711]: read /tmp/hosts/dhcp.cfg01411c - 0 addresses
Thu Jun 17 08:16:42 2021 daemon.err netdata[6426]: PROCFILE: Cannot open file '/proc/sysvipc/shm'
此日志是 OpenWRT 虚拟机的本地日志内容,日志显示 ZABBIX 客户端启动失败,因为 Cannot open file ‘/proc/sysvipc/shm’ 这个文件。
5. 验证服务器端 rsyslog 远程日志内容
查看服务器端的远程上报日志,root@ubuntu:/# cat var/spool/rsyslog/r-network.log |head -n 80
内容如:
Jun 17 06:33:22 ixe pppd[23653]: sent [LCP EchoRep id=0x83 magic=0xffaaa8e9]
Jun 17 06:33:31 ixe dnsmasq[4030]: read /etc/hosts - 4 addresses
Jun 17 06:33:31 ixe dnsmasq[4030]: read /tmp/hosts/odhcpd - 1 addresses
Jun 17 06:33:31 ixe dnsmasq[4030]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Jun 17 06:33:31 ixe dnsmasq-dhcp[4030]: read /etc/ethers - 0 addresses
Jun 17 14:33:52 ixe pppd[23653]: rcvd [LCP EchoReq id=0x84 magic=0x6cf92d34]
Jun 17 14:33:52 ixe pppd[23653]: sent [LCP EchoRep id=0x84 magic=0xffaaa8e9]
Jun 17 14:34:09 ixe pppd[23653]: Terminating on signal 15
Jun 17 14:34:09 ixe pppd[23653]: Connect time 194.1 minutes.
Jun 17 14:34:09 ixe pppd[23653]: Sent 152 bytes, received 0 bytes.
Jun 17 14:34:09 ixe pppd[23653]: MPPE disabled
Jun 17 14:34:09 ixe pppd[23653]: Overriding mtu 1500 to 1400
Jun 17 14:34:09 ixe pppd[23653]: PPPoL2TP options: debugmask 0
Jun 17 14:34:09 ixe pppd[23653]: Overriding mru 1500 to mtu value 1400
Jun 17 14:34:09 ixe pppd[23653]: sent [LCP TermReq id=0x4 "MPPE disabled"]
Jun 17 14:34:09 ixe pppd[23653]: Overriding mtu 1500 to 1400
Jun 17 14:34:09 ixe pppd[23653]: PPPoL2TP options: debugmask 0
Jun 17 14:34:09 ixe pppd[23653]: Overriding mru 1500 to mtu value 1400
Jun 17 14:34:09 ixe pppd[23653]: sent [LCP TermReq id=0x5 "MPPE disabled"]
Jun 17 14:34:12 ixe pppd[23653]: sent [LCP TermReq id=0x6 "MPPE disabled"]
Jun 17 14:34:12 ixe pppd[23653]: Connection terminated.
Jun 17 14:34:12 ixe pppd[23653]: Modem hangup
Jun 17 14:34:12 ixe pppd[23653]: Exit.
Jun 17 14:34:33 ixe pppd[27050]: Plugin pppol2tp.so loaded.
Jun 17 14:34:33 ixe pppd[27050]: pppd 2.4.7 started by root, uid 0
Jun 17 14:34:33 ixe pppd[27050]: using channel 3
Jun 17 14:34:33 ixe pppd[27050]: Using interface ppp0
Jun 17 14:34:33 ixe pppd[27050]: Connect: ppp0 <-->
Jun 17 14:34:33 ixe pppd[27050]: Overriding mtu 1500 to 1400
Jun 17 14:34:33 ixe pppd[27050]: PPPoL2TP options: debugmask 0
Jun 17 14:34:33 ixe pppd[27050]: Overriding mru 1500 to mtu value 1400
Jun 17 14:34:33 ixe pppd[27050]: sent [LCP ConfReq id=0x1 <mru 1400> <asyncmap 0x0> <magic 0x7d73ba8d>]
Jun 17 14:34:33 ixe pppd[27050]: rcvd [LCP ConfReq id=0x1 <auth chap MS-v2> <mru 1450> <magic 0xfb92c32>]
Jun 17 14:34:33 ixe pppd[27050]: sent [LCP ConfAck id=0x1 <auth chap MS-v2> <mru 1450> <magic 0xfb92c32>]
Jun 17 14:34:33 ixe pppd[27050]: rcvd [LCP ConfRej id=0x1 <asyncmap 0x0>]
Jun 17 14:34:33 ixe pppd[27050]: sent [LCP ConfReq id=0x2 <mru 1400> <magic 0x7d73ba8d>]
Jun 17 14:34:33 ixe pppd[27050]: rcvd [LCP ConfAck id=0x2 <mru 1400> <magic 0x7d73ba8d>]
Jun 17 14:34:33 ixe pppd[27050]: PPPoL2TP options: debugmask 0
Jun 17 14:34:33 ixe pppd[27050]: rcvd [CHAP Challenge id=0x1 <5570fcc24838fe7fa186d6a7f2688529>, name = "CHR-GZ-DY-Router003-MGT-1"]
Jun 17 14:34:33 ixe pppd[27050]: added response cache entry 0
Jun 17 14:34:33 ixe pppd[27050]: sent [CHAP Response id=0x1 <ea6f73fb3f10a92293b903f0b9ad13d40000000000000000f31a83726597822671b76789c9079504f9d054bf654db79b00>, name = "test02"]
Jun 17 14:34:33 ixe pppd[27050]: rcvd [CHAP Success id=0x1 "S=9DCD53371E49AE8C63FEF51C461FCD90329C8978"]
Jun 17 14:34:33 ixe pppd[27050]: response found in cache (entry 0)
Jun 17 14:34:33 ixe pppd[27050]: CHAP authentication succeeded
Jun 17 14:34:33 ixe pppd[27050]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0>]
Jun 17 14:34:33 ixe pppd[27050]: rcvd [CCP ConfReq id=0x1 <mppe +H -M +S -L -D -C>]
Jun 17 14:34:33 ixe pppd[27050]: sent [CCP ConfReq id=0x1 <mppe -H -M -S -L -D -C>]
Jun 17 14:34:33 ixe pppd[27050]: sent [CCP ConfNak id=0x1 <mppe -H -M +S -L -D -C>]
Jun 17 14:34:33 ixe pppd[27050]: rcvd [proto=0x8281] 01 01 00 04
Jun 17 14:34:33 ixe pppd[27050]: Unsupported protocol 0x8281 received #此处有未支持的协议
Jun 17 14:34:33 ixe pppd[27050]: sent [LCP ProtRej id=0x3 82 81 01 01 00 04]
Jun 17 14:34:33 ixe pppd[27050]: rcvd [IPCP ConfReq id=0x1 <addr 172.20.156.1>]
Jun 17 14:34:33 ixe pppd[27050]: sent [IPCP ConfAck id=0x1 <addr 172.20.156.1>]
Jun 17 14:34:33 ixe pppd[27050]: rcvd [IPCP ConfNak id=0x1 <addr 172.20.156.3>]
Jun 17 14:34:33 ixe pppd[27050]: sent [IPCP ConfReq id=0x2 <addr 172.20.156.3>]
Jun 17 14:34:33 ixe pppd[27050]: rcvd [CCP ConfNak id=0x1 <mppe +H -M +S -L -D -C>]
Jun 17 14:34:33 ixe pppd[27050]: sent [CCP ConfReq id=0x2 <mppe +H -M +S -L -D -C>]
Jun 17 14:34:33 ixe pppd[27050]: rcvd [CCP ConfReq id=0x2 <mppe -H -M +S -L -D -C>]
Jun 17 14:34:33 ixe pppd[27050]: sent [CCP ConfAck id=0x2 <mppe -H -M +S -L -D -C>]
Jun 17 14:34:33 ixe pppd[27050]: rcvd [IPCP ConfAck id=0x2 <addr 172.20.156.3>]
Jun 17 14:34:33 ixe pppd[27050]: local IP address 172.20.156.3
Jun 17 14:34:33 ixe pppd[27050]: remote IP address 172.20.156.1
日志信息有 l2tp 链接和心跳信息报;和 有未支持的协议。
完善 互联网 NAT后的日志远程上报
通过日志文件可以快速发现系统运行存在的问题,提升查找问题的效率。目前 rsyslog 配置中,系统运行还有点问题。
问题1. 配置日志文件名产生规则不正确
如下:
root@ubuntu:/# ls var/spool/rsyslog/
%fromhost-ip%-%HOSTNAME%-%$YEAR%-%$MONTH%-%$DAY%.log r-network.log
此处文件名并没有获取客户端ip地址和日期信息。
问题2 设备通过互联网上报,日志文件命名规则
如果设备通过互联网方式、接入云端服务器,设备地址经过NAT地址,主机名出厂设置都是相同;如何区别不同设备的日志信息呢,此问题待后期落实解决办法。
如您有什么好的方法,请留言,谢谢。