隨著項(xiàng)目越來(lái)越依賴Erlang，碰到的問(wèn)題也隨之增加。前段時(shí)間線上系統(tǒng)碰到內(nèi)存高消耗問(wèn)題，記錄一下troubleshooting的分析過(guò)程。線上系統(tǒng)用的是Erlang R16B02版本。
問(wèn)題描述
有幾臺(tái)線上系統(tǒng)，運(yùn)行一段時(shí)間，內(nèi)存飆升。系統(tǒng)模型很簡(jiǎn)單，有網(wǎng)絡(luò)連接，pool中找新的process進(jìn)行處理。top命令觀察，發(fā)現(xiàn)內(nèi)存都被Erlang進(jìn)程給吃完了，netstat命令查看網(wǎng)絡(luò)連接數(shù)，才區(qū)區(qū)幾K。問(wèn)題應(yīng)該是Erlang內(nèi)存泄漏了。
分析方法
Erlang系統(tǒng)有個(gè)好處，可以直接進(jìn)入線上系統(tǒng)，在生產(chǎn)現(xiàn)場(chǎng)分析問(wèn)題。我們系統(tǒng)是通過(guò)Rebar管理的，可以用不同方法進(jìn)入線上系統(tǒng)。
本機(jī)登錄
可以直接登錄到線上機(jī)器，然后通過(guò)以下命令attach到Erlang系統(tǒng)里面
復(fù)制代碼 代碼如下:
$ cd /path/to/project
$ rel/xxx/bin/xxx attach
(node@host)>
通過(guò)remote shell
獲取Erlang系統(tǒng)的cookie
復(fù)制代碼 代碼如下:
$ ps -ef |grep beam %%找到參數(shù) --setcookie
新開(kāi)一個(gè)shell，使用同樣的cookie，不同的nodename
復(fù)制代碼 代碼如下:
$ erl --setcookie cookiename -name test@127.0.0.1
用start remote shell進(jìn)入系統(tǒng)
復(fù)制代碼 代碼如下:
Erlang R16B02 (erts-5.10.3) [source] [64-bit] [smp:2:2] [async-threads:10] [hipe] [kernel-poll:false]
Eshell V5.10.3 (abort with ^G)
(test1@127.0.0.1)1> net_adm:ping('node@127.0.0.1').
pong
(test1@127.0.0.1)2> nodes().
['node@127.0.0.1']
(test1@127.0.0.1)3>
User switch command
--> h
c [nn] - connect to job
i [nn] - interrupt job
k [nn] - kill job
j - list all jobs
s [shell] - start local shell
r [node [shell]] - start remote shell
q - quit erlang
? | h - this message
--> r 'node@127.0.0.1'
--> j
1 {shell,start,[init]}
2* {'node@127.0.0.1',shell,start,[]}
--> c 2
分析流程
Erlang有很多工具，可以分析系統(tǒng)信息，比如appmon，webtool。但是系統(tǒng)內(nèi)存嚴(yán)重不足，已經(jīng)沒(méi)有辦法啟動(dòng)這些工具了，幸好還有Erlang shell。
Erlang shell自帶了很多有用的命令，可以用help()方法查看
復(fù)制代碼 代碼如下:
> help().
Erlang系統(tǒng)內(nèi)存消耗情況
top結(jié)果顯示，是內(nèi)存問(wèn)題，所以第一步可以先看看Erlang的系統(tǒng)內(nèi)存消耗情況
復(fù)制代碼 代碼如下:
> erlang:memory().
memory()可以看到Erlang emulator分配的內(nèi)存，有總的內(nèi)存，atom消耗的內(nèi)存，process消耗的內(nèi)存等等。
Erlang process創(chuàng)建數(shù)量
線上系統(tǒng)發(fā)現(xiàn)主要內(nèi)存消耗都在process上面，接下來(lái)要分析，是process內(nèi)存泄漏了，還是process創(chuàng)建數(shù)量太多導(dǎo)致。
復(fù)制代碼 代碼如下:
> erlang:system_info(process_limit). %%查看系統(tǒng)最多能創(chuàng)建多少process
> erlang:system_info(process_count). %%當(dāng)前系統(tǒng)創(chuàng)建了多少process
system_info()返回當(dāng)前系統(tǒng)的一些信息，比如系統(tǒng)process，port的數(shù)量。執(zhí)行上面命令，大吃一驚，只有2，3k的網(wǎng)絡(luò)連接，結(jié)果Erlang process已經(jīng)有10多w了。系統(tǒng)process創(chuàng)建了，但是因?yàn)榇a或者其它原因，堆積沒(méi)有釋放。
查看單個(gè)process的信息
既然是因?yàn)閜rocess因?yàn)槟撤N原因堆積了，只能從process里找原因了
先要獲取堆積process的pid
復(fù)制代碼 代碼如下:
> i(). %%返回system信息
> i(0,61,886). %% (0,61,886)是pid
看到有很多process hang在那里，查看具體pid信息，發(fā)現(xiàn)message_queue有幾條消息沒(méi)有被處理。下面就用到強(qiáng)大的erlang:process_info()方法，它可以獲取進(jìn)程相當(dāng)豐富的信息。
復(fù)制代碼 代碼如下:
> erlang:process_info(pid(0,61,886), current_stacktrace).
> rp(erlang:process_info(pid(0,61,886), backtrace)).
查看進(jìn)程的backtrace時(shí)，發(fā)現(xiàn)下面的信息
復(fù)制代碼 代碼如下:
0x00007fbd6f18dbf8 Return addr 0x00007fbff201aa00 (gen_event:rpc/2 + 96)
y(0) #Ref0.0.2014.142287>
y(1) infinity
y(2) {sync_notify,{log,{lager_msg,[], ..........}}
y(3) 0.61.886>
y(4) 0.89.0>
y(5) []
process在處理Erlang第三方的日志庫(kù)lager時(shí)，hang住了。
問(wèn)題原因
查看lager的文檔，發(fā)現(xiàn)以下信息
復(fù)制代碼 代碼如下:
Prior to lager 2.0, the gen_event at the core of lager operated purely in synchronous mode. Asynchronous mode is faster, but has no protection against message queue overload. In lager 2.0, the gen_event takes a hybrid approach. it polls its own mailbox size and toggles the messaging between synchronous and asynchronous depending on mailbox size.
{async_threshold, 20}, {async_threshold_window, 5}
This will use async messaging until the mailbox exceeds 20 messages, at which point synchronous messaging will be used, and switch back to asynchronous, when size reduces to 20 - 5 = 15.
If you wish to disable this behaviour, simply set it to 'undefined'. It defaults to a low number to prevent the mailbox growing rapidly beyond the limit and causing problems. In general, lager should process messages as fast as they come in, so getting 20 behind should be relatively exceptional anyway.
原來(lái)lager有個(gè)配置項(xiàng)，配置message未處理的數(shù)量，如果message堆積數(shù)超出，則會(huì)用 同步 方式處理！
當(dāng)前系統(tǒng)打開(kāi)了debug log，洪水般的log把系統(tǒng)給沖垮了。
老外也碰到類似問(wèn)題，這個(gè)thread給我們的分析帶來(lái)很多幫助，感謝一下。
總結(jié)
Erlang提供了豐富的工具，可以在線進(jìn)入系統(tǒng)，現(xiàn)場(chǎng)分析問(wèn)題，這個(gè)非常有助于高效、快速的定位問(wèn)題。同時(shí)，強(qiáng)大的Erlang OTP讓系統(tǒng)有更穩(wěn)定的保證。我們還會(huì)繼續(xù)挖掘Erlang，期待有更多的實(shí)踐分享。
