在 Linux 中使用日志來(lái)排錯(cuò)
人們創(chuàng)建日志的主要原因是排錯(cuò)。通常你會(huì)診斷為什么問(wèn)題發(fā)生在你的 Linux 系統(tǒng)或應(yīng)用程序中。錯(cuò)誤信息或一系列的事件可以給你提供找出根本原因的線索,說(shuō)明問(wèn)題是如何發(fā)生的,并指出如何解決它。這里有幾個(gè)使用日志來(lái)解決的樣例。
登錄失敗原因
如果你想檢查你的系統(tǒng)是否安全,你可以在驗(yàn)證日志中檢查登錄失敗的和登錄成功但可疑的用戶。當(dāng)有人通過(guò)不正當(dāng)或無(wú)效的憑據(jù)來(lái)登錄時(shí)會(huì)出現(xiàn)認(rèn)證失敗, 這通常發(fā)生在使用 SSH 進(jìn)行遠(yuǎn)程登錄或 su 到本地其他用戶來(lái)進(jìn)行訪問(wèn)權(quán)時(shí)。這些是由插入式驗(yàn)證模塊(PAM)來(lái)記錄的。在你的日志中會(huì)看到像 Failed password 和 user unknown 這樣的字符串。而成功認(rèn)證記錄則會(huì)包括像 Accepted password 和 session opened 這樣的字符串。
失敗的例子:
- pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=10.0.2.2
- Failed password for invalid user hoover from 10.0.2.2 port 4791 ssh2
- pam_unix(sshd:auth): check pass; user unknown
- PAM service(sshd) ignoring max retries; 6 > 3
成功的例子:
- Accepted password for hoover from 10.0.2.2 port 4792 ssh2
- pam_unix(sshd:session): session opened for user hoover by (uid=0)
- pam_unix(sshd:session): session closed for user hoover
你可以使用 grep 來(lái)查找哪些用戶失敗登錄的次數(shù)最多。這些都是潛在的攻擊者正在嘗試和訪問(wèn)失敗的賬戶。這是一個(gè)在 ubuntu 系統(tǒng)上的例子。
- $ grep "invalid user" /var/log/auth.log | cut -d ' ' -f 10 | sort | uniq -c | sort -nr
- 23 oracle
- 18 postgres
- 17 nagios
- 10 zabbix
- 6 test
由于沒(méi)有標(biāo)準(zhǔn)格式,所以你需要為每個(gè)應(yīng)用程序的日志使用不同的命令。日志管理系統(tǒng),可以自動(dòng)分析日志,將它們有效的歸類(lèi),幫助你提取關(guān)鍵字,如用戶名。
日志管理系統(tǒng)可以使用自動(dòng)解析功能從 Linux 日志中提取用戶名。這使你可以看到用戶的信息,并能通過(guò)點(diǎn)擊過(guò)濾。在下面這個(gè)例子中,我們可以看到,root 用戶登錄了 2700 次之多,因?yàn)槲覀兒Y選的日志僅顯示 root 用戶的嘗試登錄記錄。
日志管理系統(tǒng)也可以讓你以時(shí)間為做坐標(biāo)軸的圖表來(lái)查看,使你更容易發(fā)現(xiàn)異常。如果有人在幾分鐘內(nèi)登錄失敗一次或兩次,它可能是一個(gè)真正的用戶而忘記 了密碼。但是,如果有幾百個(gè)失敗的登錄并且使用的都是不同的用戶名,它更可能是在試圖攻擊系統(tǒng)。在這里,你可以看到在3月12日,有人試圖登錄 Nagios 幾百次。這顯然不是一個(gè)合法的系統(tǒng)用戶。
重啟的原因
有時(shí)候,一臺(tái)服務(wù)器由于系統(tǒng)崩潰或重啟而宕機(jī)。你怎么知道它何時(shí)發(fā)生,是誰(shuí)做的?
關(guān)機(jī)命令
如果有人手動(dòng)運(yùn)行 shutdown 命令,你可以在驗(yàn)證日志文件中看到它。在這里,你可以看到,有人從 IP 50.0.134.125 上作為 ubuntu 的用戶遠(yuǎn)程登錄了,然后關(guān)閉了系統(tǒng)。
- Mar 19 18:36:41 ip-172-31-11-231 sshd[23437]: Accepted publickey for ubuntu from 50.0.134.125 port 52538 ssh
- Mar 19 18:36:41 ip-172-31-11-231 23437]:sshd[ pam_unix(sshd:session): session opened for user ubuntu by (uid=0)
- Mar 19 18:37:09 ip-172-31-11-231 sudo: ubuntu : TTY=pts/1 ; PWD=/home/ubuntu ; USER=root ; COMMAND=/sbin/shutdown -r now
內(nèi)核初始化
如果你想看看服務(wù)器重新啟動(dòng)的所有原因(包括崩潰),你可以從內(nèi)核初始化日志中尋找。你需要搜索內(nèi)核類(lèi)(kernel)和 cpu 初始化(Initializing)的信息。
- Mar 19 18:39:30 ip-172-31-11-231 kernel: [ 0.000000] Initializing cgroup subsys cpuset
- Mar 19 18:39:30 ip-172-31-11-231 kernel: [ 0.000000] Initializing cgroup subsys cpu
- Mar 19 18:39:30 ip-172-31-11-231 kernel: [ 0.000000] Linux version 3.8.0-44-generic (buildd@tipua) (gcc version 4.6.3 (Ubuntu/Linaro 4.6.3-1ubuntu5) ) #66~precise1-Ubuntu SMP Tue Jul 15 04:01:04 UTC 2014 (Ubuntu 3.8.0-44.66~precise1-generic 3.8.13.25)
檢測(cè)內(nèi)存問(wèn)題
有很多原因可能導(dǎo)致服務(wù)器崩潰,但一個(gè)常見(jiàn)的原因是內(nèi)存用盡。
當(dāng)你系統(tǒng)的內(nèi)存不足時(shí),進(jìn)程會(huì)被殺死,通常會(huì)殺死使用最多資源的進(jìn)程。當(dāng)系統(tǒng)使用了所有內(nèi)存,而新的或現(xiàn)有的進(jìn)程試圖使用更多的內(nèi)存時(shí)就會(huì)出現(xiàn)錯(cuò) 誤。在你的日志文件查找像 Out of Memory 這樣的字符串或類(lèi)似 kill 這樣的內(nèi)核警告信息。這些信息表明系統(tǒng)故意殺死進(jìn)程或應(yīng)用程序,而不是允許進(jìn)程崩潰。
例如:
[33238.178288] Out of memory: Kill process 6230 (firefox) score 53 or sacrifice child
[29923450.995084] select 5230 (docker), adj 0, size 708, to kill
你可以使用像 grep 這樣的工具找到這些日志。這個(gè)例子是在 ubuntu 中:
$ grep “Out of memory” /var/log/syslog
[33238.178288] Out of memory: Kill process 6230 (firefox) score 53 or sacrifice child
請(qǐng)記住,grep 也要使用內(nèi)存,所以只是運(yùn)行 grep 也可能導(dǎo)致內(nèi)存不足的錯(cuò)誤。這是另一個(gè)你應(yīng)該中央化存儲(chǔ)日志的原因!
定時(shí)任務(wù)錯(cuò)誤日志
cron 守護(hù)程序是一個(gè)調(diào)度器,可以在指定的日期和時(shí)間運(yùn)行進(jìn)程。如果進(jìn)程運(yùn)行失敗或無(wú)法完成,那么 cron 的錯(cuò)誤出現(xiàn)在你的日志文件中。具體取決于你的發(fā)行版,你可以在 /var/log/cron,/var/log/messages,和 /var/log/syslog 幾個(gè)位置找到這個(gè)日志。cron 任務(wù)失敗原因有很多。通常情況下,問(wèn)題出在進(jìn)程中而不是 cron 守護(hù)進(jìn)程本身。
默認(rèn)情況下,cron 任務(wù)的輸出會(huì)通過(guò) postfix 發(fā)送電子郵件。這是一個(gè)顯示了該郵件已經(jīng)發(fā)送的日志。不幸的是,你不能在這里看到郵件的內(nèi)容。
Mar 13 16:35:01 PSQ110 postfix/pickup[15158]: C3EDC5800B4: uid=1001 from=<hoover>
Mar 13 16:35:01 PSQ110 postfix/cleanup[15727]: C3EDC5800B4: message-id=<20150310110501.C3EDC5800B4@PSQ110>
Mar 13 16:35:01 PSQ110 postfix/qmgr[15159]: C3EDC5800B4: from=<hoover@loggly.com>, size=607, nrcpt=1 (queue active)
Mar 13 16:35:05 PSQ110 postfix/smtp[15729]: C3EDC5800B4: to=<hoover@loggly.com>, relay=gmail-smtp-in.l.google.com[74.125.130.26]:25, delay=4.1, delays=0.26/0/2.2/1.7, dsn=2.0.0, status=sent (250 2.0.0 OK 1425985505 f16si501651pdj.5 - gsmtp)
你可以考慮將 cron 的標(biāo)準(zhǔn)輸出記錄到日志中,以幫助你定位問(wèn)題。這是一個(gè)你怎樣使用 logger 命令重定向 cron 標(biāo)準(zhǔn)輸出到 syslog的例子。用你的腳本來(lái)代替 echo 命令,helloCron 可以設(shè)置為任何你想要的應(yīng)用程序的名字。
*/5 * * * * echo ‘Hello World’ 2>&1 | /usr/bin/logger -t helloCron
它創(chuàng)建的日志條目:
Apr 28 22:20:01 ip-172-31-11-231 CRON[15296]: (ubuntu) CMD (echo 'Hello World!' 2>&1 | /usr/bin/logger -t helloCron)
Apr 28 22:20:01 ip-172-31-11-231 helloCron: Hello World!
每個(gè) cron 任務(wù)將根據(jù)任務(wù)的具體類(lèi)型以及如何輸出數(shù)據(jù)來(lái)記錄不同的日志。
希望在日志中有問(wèn)題根源的線索,也可以根據(jù)需要添加額外的日志記錄。