系统日志分析
案例3:系统日志分析
3.1 问题
本例要求熟悉Linux系统中的常见日志文件,使用必要的命令工具完成下列任务:
- 列出所有包含关键词8909的系统日志消息
- 查看启动时识别的鼠标设备信息
- 列出最近2条成功/不成功的用户登录消息
- 列出最近10条重要程度在 ERR 及以上的日志消息
- 列出所有与服务httpd相关的消息
- 列出前4个小时内新记录的日志
3.2 方案
常见的系统日志及各自用途:
- /var/log/messages,记录内核消息、各种服务的公共消息
- /var/log/dmesg,记录系统启动过程的各种消息
- /var/log/cron,记录与cron计划任务相关的消息
- /var/log/maillog,记录邮件收发相关的消息
- /var/log/secure,记录与访问限制相关的安全消息
日志消息的优先级(高-->低):
- EMERG(紧急):级别0,系统不可用的情况
- ALERT(警报):级别1,必须马上采取措施的情况
- CRIT(严重):级别2,严重情形
- ERR(错误):级别3,出现错误
- WARNING(警告):级别4,值得警告的情形
- NOTICE(注意):级别5,普通但值得引起注意的事件
- INFO(信息):级别6,一般信息
- DEBUG(调试):级别7,程序/服务调试消息
RHEL7提供的journalctl日志工具的常见用法:
- journalctl | grep 关键词
- journalctl -u 服务名 -p 优先级
- journalctl -n 消息条数
- journalctl --since="yyyy-mm-dd HH:MM:SS" --until="yyyy-mm-dd HH:MM:SS"
3.3 步骤
实现此案例需要按照如下步骤进行。
步骤一:分析系统日志及用户日志
1)列出所有包含关键词8909的系统日志消息
简单模拟一个故障(SELinux阻止Web开放8909端口):
- [root@svr7 ~]# vim /etc/httpd/conf.d/8909.conf //添加开8909端口配置
- Listen 8909
- [root@svr7 ~]# setenforce 1 //开启强制模式
- [root@svr7 ~]# systemctl restart httpd //起服务失败
- Job for httpd.service failed because the control process exited with error code. See "systemctl status httpd.service" and "journalctl -xe" for details.
从日志文件/var/log/messages中检索信息:
- [root@svr7 ~]# grep 8909 /var/log/messages
- Jan 6 17:53:48 svr7 setroubleshoot: SELinux is preventing /usr/sbin/httpd from name_bind access on the tcp_socket port 8909. For complete SELinux messages. run sealert -l 6d37b8f0-ab8a-4082-9295-c784f4f57190
- Jan 6 17:53:48 svr7 python: SELinux is preventing /usr/sbin/httpd from name_bind access on the tcp_socket port 8909.#012#012***** Plugin bind_ports (92.2 confidence) suggests ************************#012#012If you want to allow /usr/sbin/httpd to bind to network port 8909#012Then you need to modify the port type.#012Do#012# semanage port -a -t PORT_TYPE -p tcp 8909#012 where PORT_TYPE is one of the following: http_cache_port_t, http_port_t, jboss_management_port_t, jboss_messaging_port_t, ntop_port_t, puppet_port_t.#012#012***** Plugin catchall_boolean (7.83 confidence) suggests ******************#012#012If you want to allow nis to enabled#012Then you must tell SELinux about this by enabling the \'nis_enabled\' boolean.#012#012Do#012setsebool -P nis_enabled 1#012#012***** Plugin catchall (1.41 confidence) suggests **************************#012#012If you believe that httpd should be allowed name_bind access on the port 8909 tcp_socket by default.#012Then you should report this as a bug.#012You can generate a local policy module to allow this access.#012Do#012allow this access for now by executing:#012# grep httpd /var/log/audit/audit.log | audit2allow -M mypol#012# semodule -i mypol.pp#012
- .. ..
使用完毕记得删除测试配置文件:
- [root@svr7 ~]# rm -rf /etc/httpd/conf.d/8909.conf
- [root@svr7 ~]# systemctl restart httpd
2)查看启动时识别的鼠标设备信息
- [root@svr7 ~]# dmesg | grep -i mouse
- [ 1.020385] mousedev: PS/2 mouse device common for all mice
- [ 1.249422] input: ImPS/2 Generic Wheel Mouse as /devices/platform/i8042/serio1/input/input2
- [ 2.279665] usb 2-1: Product: VMware Virtual USB Mouse
- [ 2.603999] input: VMware VMware Virtual USB Mouse as /devices/pci0000:00/0000:00:11.0/0000:02:00.0/usb2/2-1/2-1:1.0/input/input3
- [ 2.604222] hid-generic 0003:0E0F:0003.0001: input,hidraw0: USB HID v1.10 Mouse [VMware VMware Virtual USB Mouse] on usb-0000:02:00.0-1/input0
3)列出最近2条成功/不成功的用户登录消息
查看成功登录的事件消息:
- [root@svr7 ~]# last -2
- zhsan pts/2 192.168.4.207 Fri Jan 6 18:00 - 18:00 (00:00)
- root pts/2 192.168.4.110 Fri Jan 6 17:26 - 17:59 (00:33)
- wtmp begins Thu Aug 4 00:10:16 2016
查看失败登录的事件消息:
- [root@svr7 ~]# lastb -2
- anonymou ssh:notty 192.168.4.207 Fri Jan 6 18:00 - 18:00 (00:00)
- anonymou ssh:notty 192.168.4.207 Fri Jan 6 18:00 - 18:00 (00:00)
- btmp begins Fri Jan 6 18:00:34 2017
步骤二:使用journalctl日志提取工具
1)列出最近10条重要程度在 ERR 及以上的日志消息
- [root@svr7 ~]# journalctl -p err -n 10
- -- Logs begin at Thu 2017-01-05 15:50:08 CST, end at Fri 2017-01-06 18:01:01 CST. --
- Jan 06 14:56:57 svr7 setroubleshoot[23702]: SELinux is preventing /usr/sbin/vsftpd from getattr access on the file /rhel7/repodata/repomd.xml. For complete SELinux mes
- Jan 06 14:56:57 svr7 setroubleshoot[23702]: SELinux is preventing /usr/sbin/vsftpd from read access on the file repomd.xml. For complete SELinux messages. run sealert
- Jan 06 14:56:57 svr7 setroubleshoot[23702]: SELinux is preventing /usr/sbin/vsftpd from read access on the file repomd.xml. For complete SELinux messages. run sealert
- Jan 06 14:56:57 svr7 setroubleshoot[23702]: SELinux is preventing /usr/sbin/vsftpd from lock access on the file /rhel7/repodata/repomd.xml. For complete SELinux messag
- Jan 06 17:53:48 svr7 setroubleshoot[33743]: Plugin Exception restorecon_source
- Jan 06 17:53:48 svr7 setroubleshoot[33743]: SELinux is preventing /usr/sbin/httpd from name_bind access on the tcp_socket port 8909. For complete SELinux messages. run
- Jan 06 17:53:53 svr7 setroubleshoot[33743]: SELinux is preventing /usr/sbin/httpd from name_connect access on the tcp_socket port 8909. For complete SELinux messages.
- Jan 06 17:53:54 svr7 systemd[1]: Failed to start The Apache HTTP Server.
- .. ..
- lines 1-11/11 (END)
2)列出所有与服务httpd相关的消息
- [root@svr7 ~]# journalctl -u httpd
- -- Logs begin at Thu 2017-01-05 15:50:08 CST, end at Fri 2017-01-06 18:01:01 CST. --
- Jan 06 14:57:16 svr7 systemd[1]: Starting The Apache HTTP Server...
- Jan 06 14:57:16 svr7 httpd[23812]: AH00557: httpd: apr_sockaddr_info_get() failed for svr7
- Jan 06 14:57:16 svr7 httpd[23812]: AH00558: httpd: Could not reliably determine the server\'s fully qualified domain name, using 127.0.0.1. Set the \'ServerName\' directi
- Jan 06 14:57:16 svr7 systemd[1]: Started The Apache HTTP Server.
- Jan 06 17:53:44 svr7 systemd[1]: Stopping The Apache HTTP Server...
- Jan 06 17:53:46 svr7 systemd[1]: Starting The Apache HTTP Server...
- Jan 06 17:53:46 svr7 httpd[33741]: AH00557: httpd: apr_sockaddr_info_get() failed for svr7
- .. ..
3)列出前4个小时内新记录的日志
根据当前日期时间往前推4个小时,确定--since起始和--until结束时刻:
- [root@svr7 ~]# journalctl --since "2017-01-06 14:11" --until "2017-01-06 18:11"
- -- Logs begin at Thu 2017-01-05 15:50:08 CST, end at Fri 2017-01-06 18:10:01 CST. --
- Jan 06 14:20:01 svr7 systemd[1]: Started Session 160 of user root.
- Jan 06 14:20:01 svr7 CROND[22869]: (root) CMD (/usr/lib64/sa/sa1 1 1)
- Jan 06 14:20:01 svr7 systemd[1]: Starting Session 160 of user root.
- Jan 06 14:30:01 svr7 systemd[1]: Started Session 161 of user root.
- Jan 06 14:30:01 svr7 CROND[23028]: (root) CMD (/usr/lib64/sa/sa1 1 1)
- Jan 06 14:31:39 svr7 systemd[1]: Starting Session 162 of user root.
- Jan 06 14:32:17 svr7 sshd[23046]: pam_unix(sshd:session): session closed for user root
- Jan 06 14:31:39 svr7 systemd[1]: Started Session 162 of user root.
- Jan 06 14:31:39 svr7 sshd[23046]: pam_unix(sshd:session): session opened for user root by (uid=0)
- Jan 06 14:31:39 svr7 systemd-logind[985]: New session 162 of user root.
- .. .