1 開發環境問題... 5
1.1 SuSe下vi亂碼問題... 5
1.2 Vi技巧... 5
1.3 轉義轉義... 5
1.4 令人頭疼的^M(/r) 7
1.5 Tcpdump誤區... 7
1.6 date詳解... 9
1.7 找回被删除檔案的方法... 10
2 編譯連結問題... 11
2.1 變量名或者函數找不到... 11
2.2 連結順序問題/函數找不到... 11
2.3 宏定義的文法錯誤... 12
3 運作時問題... 12
3.1 無法執行... 12
3.2 CORE定位... 12
3.3 記憶體洩漏... 15
3.4 頭檔案和實作庫不比對... 19
3.5 運作狀态分析工具清單... 19
4 網絡問題... 19
4.1 Broken pipe. 19
4.2 消息隊列阻塞... 20
5 線程、程序問題... 20
5.1 非線程安全的api(或不可重入) 20
5.2 多個線程問題... 21
5.3 加鎖之殇... 21
5.4 各種程序線程模式... 21
6 資料庫使用問題... 22
6.1 公司資料庫安裝指導... 22
6.2 慢查詢(耗時查詢)... 23
6.3 存儲過程(mysql) 23
6.4 資料連接配接... 24
6.5 Mysql編碼問題(ZZ自未知作者)... 24
7 Web開發問題... 25
8 ACE使用問題... 26
8.1 事件處理器 ACE_Event_Handler 26
8.2 dev poll / epoll 模式使用... 26
8.3 mysql5.0.45版本資料庫的沖突問題... 27
8.4 調整ACE預設的時間格式%D的說明... 27
9 C++是促進腦死亡的最佳方式... 29
9.1 注意參數的型别和函數參數的比對... 29
9.2 雪崩效應造成處理阻塞... 30
9.3 dlsvrd日志時間出錯... 32
10 設計規範... 35
10.1 函數... 35
10.2 日志... 36
11 後記... 36
11.1 作者介紹... 36
11.2 參考文檔... 36
11.3 緻謝... 36
序
你是否曾經因為某個問題徹夜難眠,加班定位問題到很晚?
你是否曾經因為某個問題茶飯不思,該吃飯的時間還想着要解決這個問題?
你是否曾經因為某個問題導緻項目延遲?
……
一直以來,就想整理一下四年來工作中所遇到的所有(維護,開發方面)問題,對這些問題進行總結,探讨某類問題處理的通用方法和解決思路,使得過去的經驗能夠沉澱下來,給自己(也希望給别人)能帶來點好處,在以後的工作中少走彎路,簡化工作中遇到的問題,提高工作效率,能夠把更多的時間用于……
衆裡尋他千百度,蓦然回首……
1 開發環境問題
本文主要介紹一下man手冊講解的不夠詳細或者baidu搜尋不到的内容。一般的問題大家還是先用man幫助處理,或者網上搜尋一下,一般都能很容易得到解決。
1.1 SuSe下vi亂碼問題
案例一 2008-06-15 TC營運環境的特例
現象描述:有時候編輯檔案時看到螢幕上有亂碼,修改某行之後,vi再次打開發現剛才修改的内容沒有生效。
原因說明:這個通常可能是因為亂碼導緻你修改的行并不是你看到的行,是以重新vi編輯發現想修改的行沒有任何變化。
解決辦法:
/etc/sysconfig # vi /etc/sysconfig /language
RC_LANG="zh_CN.UTF-8" 改成 “en_US.ISO-8859-1”
RC_LC_ALL=”” 改成 "en-US"
兩個變量的作用域不太一樣,可以仔細看看文檔裡面的詳細說明
重新登入或者 source /etc/sysconfig/language 檔案使得配置生效
1.2 Vi技巧
基本的技巧請看vi的手冊,這裡講述幾個很有用,但是很少有手冊講到的技巧。
J合并行
d+[[ 删除第一行到目前行
d+]] 删除目前行到最後行
1.3 轉義轉義
“” ‘’ `` 這些引用各有各的含義,轉義的方式也不一樣。在開發運維使用中很容易出現一些意想不到的問題。
案例一 grep 的問題 2008-07-18
MNET…abs> grep HEADMARK ./res/Web.list.log | awk –F//t ‘$5==”NTPDATE_CHK_WRONG”’ | wc –l
2
MNET…abs>temp=` grep HEADMARK ./res/Web.list.log | awk –F//t ‘$5==”NTPDATE_CHK_WRONG”’ | wc –l `
MNET…abs>echo $temp
從上面看出``執行之後的結果和不用``執行的結果不同。
問題原因:
反引号在取指令的時候,需要解析一個/,然後awk執行的時候,也會解析一個/,是以temp=`***`這樣會解析掉2個/,這樣在指令真正執行的時候,就把awk -F//t 變成了 awk -Ft,改成 awk -F///t就好了。
案例二 awk輸出單引号等特殊字元的問題 2008-10-28
為了把xls的内容(有中文文本等)生成sql語句,把相關資訊導入資料庫。(本人比較土,不會用xls直接導入資料庫mysql),是以打算用awk處理一下,但是要生成的sql語句在有字元串的時候必須帶單引号’’,用單引号引起來,不然文法會有問題,是以遇到了如下問題:
1.怎麼把shell環境變量傳遞給awk
2.怎麼在awk裡面輸出單引号’’
第一個問題相對簡單,很多書籍應該都有awk接收外部參數這方面的說明,第二個問題網上和書籍上資料相對較少。樣例代碼如下:
init_data.sh
GAME_TYPE=$1
FILE_NAME=$2
cat $FILE_NAME | awk '{
mid=0;
if ( $5==1 || $6==1 || $7==1) mid='"$GAME_TYPE"'*10000+$1;
print "insert into dbHonor.tbEventCfg values " "(" '"$GAME_TYPE"'*10000+$1 ", '"$GAME_TYPE"', 1, " mid ", " $2 "," "'/''"$3"'/''" "," "'/''"$4"'/''" ");";
if ( $5==1 ) {rank=1;name="黃金徽章";}
if ( $6==1 ) {rank=2;name="白銀徽章";}
if ( $7==1 ) {rank=3;name="青銅徽章";}
if ( $5==1 || $6==1 || $7==1) print "insert into dbHonor.tbMedalCfg values " "(" '"$GAME_TYPE"'*10000+$1 "," "'/''"name"'/''" "," '"$GAME_TYPE"' "," rank "," "'/''""'/''" "," "'/''""'/''" ");";
}' > init_data.sql
此段代碼涉及到了awk的相對複雜的邏輯代碼,分段,邏輯判斷,數學運算操作,變量,特殊字元轉義等(比如單引号’’ $等特殊字元, / 轉義不需要再雙重應用"//"即可),是以儲存下來作為将來參考使用。
1.4 令人頭疼的^M(/r)
^M(/r)這個win和linux平台存在差異的特殊字元給開發和運維都帶來很多意想不到的問題。令人十分頭疼。如果你從win上傳遞到linux系統的檔案不能正常執行,awk grep sed等linux下的這些指令執行異常,或者本來好好的程式無法正常編譯連接配接,那麼你可以毫不猶豫的先懷疑它,誰叫它長的醜令人讨厭呢。(^M說:長的醜又不是我的錯。我說:沒錯,但是你不要總出來吓人嘛J)
案例一:2008-8-29 一位同僚在開發中遇到如下的提示資訊
../include/pet_error_code_function_implement.h:185: stray '/' in program
正常來說提示 stray 的問題都是因為有特殊字元,但是這個提示根本沒提示有什麼字元,不是很明顯,是以比較奇怪。
根據以往的經驗,估計是有不可見字元了,然後用vim看了一下檔案,發現果然是有^M了,截圖如下
解決方法:傳遞檔案時采用ascii方式傳遞,或者把檔案進行dos2uinx轉換(比如:cat file.txt | tr -d '/r')。
經驗總結:用gcc 2.95版本編譯程式時時,如果程式檔案中存在這些特殊字元會導緻無法進行正常編譯。需要去掉才能正常編譯。gcc高版本3.3.4以上好像不受影響。
1.5 Tcpdump誤區
有時候按照tcpdump的手冊和網上很多資料進行監控時可能監控不到資訊,比如:
在172.16.225.110執行監控(期望監聽本地的5694端口):
tcpdump -vv host 172.16.225.110 and port 5694
預設監聽的是eth1網卡(接口)上的資料,如果是本地和本地的網絡通信,則監聽不到任何消息。必須用 -i 參數指定 lo 接口,比如:
tcpdump -vv -ilo host 172.16.225.110 and port 5694
tcpdump 的輸出結果介紹
下面我們介紹幾種典型的tcpdump指令的輸出資訊
(1) 資料鍊路層頭資訊
使用指令#tcpdump --e host ice
ice 是一台裝有linux的主機,她的MAC位址是0:90:27:58:AF:1A
H219是一台裝有SOLARIC的SUN工作站,它的MAC位址是8:0:20:79:5B:46;上一條指令的輸出結果如下所示:
21:50:12.847509 eth0 < 8:0:20:79:5b:46 0:90:27:58:af:1a ip 60: h219.33357 > ice.telnet 0:0(0) ack 22535 win 8760 (DF)
分析:21:50:12是顯示的時間, 847509是ID号,eth0 <表示從網絡接口eth0 接受該
資料包,eth0 >表示從網絡接口裝置發送資料包, 8:0:20:79:5b:46是主機H219的MAC位址,它
表明是從源位址H219發來的資料包. 0:90:27:58:af:1a是主機ICE的MAC位址,表示該資料包的
目的位址是ICE . ip 是表明該資料包是IP資料包,60 是資料包的長度, h219.33357 > ice.
telnet 表明該資料包是從主機H219的33357端口發往主機ICE的TELNET(23)端口. ack 22535
表明對序列号是222535的包進行響應. win 8760表明發送視窗的大小是8760.
(2) ARP包的TCPDUMP輸出資訊
使用指令#tcpdump arp 得到的輸出結果是:
22:32:42.802509 eth0 > arp who-has route tell ice (0:90:27:58:af:1a)
22:32:42.802902 eth0 < arp reply route is-at 0:90:27:12:10:66 (0:90:27:58:af:1a)
分析: 22:32:42是時間戳, 802509是ID号, eth0 >表明從主機發出該資料包, arp表明是
ARP請求包, who-has route tell ice表明是主機ICE請求主機ROUTE的MAC位址。 0:90:27:5
8:af:1a是主機ICE的MAC位址。
(3) TCP包的輸出資訊
用TCPDUMP捕獲的TCP包的一般輸出資訊是:
src > dst: flags data-seqno ack window urgent options
src > dst:表明從源位址到目的位址, flags是TCP包中的标志資訊,S 是SYN标志, F (F
IN), P (PUSH) , R (RST) "." (沒有标記); data-seqno是資料包中的資料的順序号, ack是下次期望的順序号, window是接收緩存的視窗大小, urgent表明資料包中是否有緊急指針. Options是選項.
(4) UDP包的輸出資訊
用TCPDUMP捕獲的UDP包的一般輸出資訊是:
route.port1 > ice.port2: udp lenth
UDP十分簡單,上面的輸出行表明從主機ROUTE的port1端口發出的一個UDP資料包到主機ICE的port2端口,類型是UDP, 包的長度是lenth
1.6 date詳解
曾經有不少人問到過shell裡面用date怎麼獲得一天前(兩天後)等的時間,
今天正好要做一個有關監控的東西需要用的時間,是以順便總結一下
也許有不少人知道可以使用類似
date --date='yesterday' "+%Y-%m-%d %H:%M:%S"
等格式,但是yesterday的yesterday 呢?再往前一天呢?
前一天何其多,英文單詞都有表示嗎?
也許又有人知道可以使用類似
date -d "1 days ago" +"%Y-%m-%d"
date -d "1 hours" "+%Y-%m-%d %H:%M:%S"
等格式,不錯,這樣差不多就能解決所有的時間顯示問題了,但是總感覺不是很好
man date 的時候大家應該都見過這一行
-d, --date=STRING
display time described by STRING, not `now'
雖然是這樣的簡單一行說明,但是有多少人能真正了解這個背後所隐藏的秘密呢?下面聽筆者詳細道來:)
STRING 的格式有幾種?都可以用那些形式表示?
據說沒有人知道,因為知道的人都沒有把它記錄下來
據本人的了解除了上面的之外,最好的一種就事這樣
("+/- num unit")/{1,/}
/{1,/} 表示前面()裡面的格式比對一次以上(不是很标準的表示)
+表示将來的時間 -表示過去的時間
num 是你想要的數目
unit 是時間機關,具體可以取那些值?告訴你,可以取從年到秒的常用的時間機關
year/years
month/months
week/weeks
day/days
hour/hours
minute/minutes/min
second/seconds/sec
因為系統本身的限制,到了1901和2038之外的年份可能就無效,大家可要注意哦,不要到時候說沒提醒:)
下面為舉例說明:
1 1個月零10天後(40天後)的時間:
[email protected]:/usr/local/ipgw# date -d "+1month +10day" "+%Y-%m-%d %H:%M:%S"
2006-07-25 11:07:03
[email protected]:/usr/local/ipgw# date -d "+40day" "+%Y-%m-%d %H:%M:%S"
2006-07-25 11:08:33
2 明年昨日的時間
[email protected]:/usr/local/ipgw# date -d "+1year -1day" "+%Y-%m-%d %H:%M:%S"
2007-06-14 11:10:02
其實應該還有很多秘密是沒有了解到的,希望有興趣的有心人能指點一二:)
date -d "+%Y-%m-%d %H:%M:%S"
通過timestamp計算時間
date -d "1970-1-1 +1190858275sec"
顯示時間蹉 %s
date "+%s"
1.7 找回被删除檔案的方法
(前提是該檔案必須被使用)
1、lsof | grep delete,可以看到删除的檔案名,以及被哪個程序鎖定
2、ps axu | grep "程序名"
3、cd /proc/"pid"/fd/,找到相應的檔案cp回原目錄即可
2 編譯連結問題
2.1 變量名或者函數找不到
系統告訴你找不到那就是找不到,找不到的原因可以有很多,但是肯定是找不到,一定要相信編譯器告訴你的資訊。
案例一:2008年07月29日 一位同僚在編譯程式時出現這樣的提示
supper_user.cpp:15: error: syntax error before `*' token
supper_user.cpp:17: error: syntax error before `*' token
supper_user.cpp:28: error: syntax error before `::' token
supper_user.cpp:36: error: syntax error before `::' token
supper_user.cpp:42: error: ISO C++ forbids declaration of `prevPos' with no
從提示字面了解是*分割符的文法錯誤,這種錯誤比較明确可以判斷是因為*前面的資料類型找不到定義,然後編譯器認為文法錯誤了。經過确認之後是因為cpp檔案中沒包含需要的.h頭檔案的資料結構聲明,加入.h頭檔案之後此問題解決。
案例二:no matching function
2.2 連結順序問題/函數找不到
案例一:
2005年06月13日 因為互娛支付中心的開發,使用到公司的portal api,此api中使用的庫自帶了tlib庫,用其他的庫可能不相容,此非重點,重點的是連接配接庫的時候總提示某個函數找不到,用nm之類的工具檢視,明明指定連接配接的庫裡面有這個函數,甚是迷惑,調試了半天,問了一下導師,才知道原來是其中的兩個庫之間存在依賴關系,被依賴的庫放錯了順序,放到了前面了。順序調換之後問題解決。
案例二:
2008年07月09日 編譯商城svr的程式,編譯商城svr ace5.6版本的程式,連結時出現類似這樣的提示
../../easyace//libeasyace5.6.a(ace_app.o)(.text+0x12e0): In function `ACEApp::init_log(int)':
/usr/local/ace_using/easyace/ace_app.cpp:263: undefined reference to `ACE_Logging_Strategy::ACE_Logging_Strategy[in-charge]()'
../../easyace//libeasyace5.6.a(sys_conf.o)(.text+0xcd): In function `SysConf::load_conf(std::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)':
/usr/local/ace_using/easyace/sys_conf.cpp:19: undefined reference to `ACE_Configuration_Heap::ACE_Configuration_Heap[in-charge]()'
../../easyace//libeasyace5.6.a(sys_conf.o)(.text+0x12e):/usr/local/ace_using/easyace/sys_conf.cpp:20: undefined reference to `ACE_Configuration_Heap::open(unsigned)'
提示ACE裡面的一些庫找不到,ACE的庫理論上是正常的,nm之類的工具檢視了一下确實有這些函數,出現這個提示明顯可以判斷是因為庫的順序放錯了,如下
LIBS= -static … -lACE -leasyace5.6 -lnsl -lm -lz -lc -ldl -lpthread -lrt –lepoll
上面的easyace5.6的庫是基于ACE的庫産生的,因為被依賴的需要放在後面,把ACE和easyace5.6的庫順序調換之後,問題解決。
2.3 宏定義的文法錯誤
3 運作時問題
3.1 無法執行
無法執行的情況主要有以下幾個方面:
1 是否有執行權限,如果沒有,用 chmod +x 之類的指令加上
2 是否是二進制檔案,如果可執行程式通過win傳遞,傳遞方式采用了ascii方式的話,那就會導緻程式無法執行了,因為格式會變化。
3 傳輸的檔案是否完整,如果傳輸格式沒問題,也有可執行權限,如果還是無法執行,可能檔案本身不完整了,可以采用md5sum進行檔案校驗
3.2 CORE定位
出現core的情況,比較常見的觸發原因有幾個,下面進行簡單的介紹。
SIGSEGV 段錯誤(信号11),說白了就是通路了非法記憶體位址,無論是超出程序範圍的(位址越界)還是系統不存在的記憶體通路(指針指向空)
SIGABRT 檢測異常(信号6) 調用了abort()函數導緻,最常見的是對釋放的記憶體(free())再次進行釋放,或者記憶體配置設定失敗等原因的時候會觸發
SIGBUS 本意是指總線錯誤(信号7),一般出現在當你通路一段非法位址,并且這段位址實體上是不存在的。它類似于SIGSEGV,後者也是通路非法位址,但是這個位址是虛拟位址空間的位址,SIGBUS正好相反,由于某些機器上,實體空間存在不連續的情況,通路到這些hole時,就會産生這個信号。硬體故障。
SIGILL 一般是硬體方面的問題,比如用%s格式直接輸出string類型的(沒有通過c_str()轉換)一般會導緻這個信号并退出程序(一般編譯時就會提示cannot pass objects of non-POD type …call will abort at runtime)。
具體的信号檢視方式請使用 kill -l 指令(對于信号的問題請詳細檢視《unix環境進階程式設計》的介紹)。
[[email protected]~]# kill –l
1) SIGHUP 2) SIGINT 3) SIGQUIT 4) SIGILL
5) SIGTRAP 6) SIGABRT 7) SIGBUS 8) SIGFPE
9) SIGKILL 10) SIGUSR1 11) SIGSEGV 12) SIGUSR2
13) SIGPIPE 14) SIGALRM 15) SIGTERM 16) SIGSTKFLT
17) SIGCHLD 18) SIGCONT 19) SIGSTOP 20) SIGTSTP
21) SIGTTIN 22) SIGTTOU 23) SIGURG 24) SIGXCPU
25) SIGXFSZ 26) SIGVTALRM 27) SIGPROF 28) SIGWINCH
29) SIGIO 30) SIGPWR 31) SIGSYS 34) SIGRTMIN
35) SIGRTMIN+1 36) SIGRTMIN+2 37) SIGRTMIN+3 38) SIGRTMIN+4
39) SIGRTMIN+5 40) SIGRTMIN+6 41) SIGRTMIN+7 42) SIGRTMIN+8
43) SIGRTMIN+9 44) SIGRTMIN+10 45) SIGRTMIN+11 46) SIGRTMIN+12
47) SIGRTMIN+13 48) SIGRTMIN+14 49) SIGRTMIN+15 50) SIGRTMAX-14
51) SIGRTMAX-13 52) SIGRTMAX-12 53) SIGRTMAX-11 54) SIGRTMAX-10
55) SIGRTMAX-9 56) SIGRTMAX-8 57) SIGRTMAX-7 58) SIGRTMAX-6
59) SIGRTMAX-5 60) SIGRTMAX-4 61) SIGRTMAX-3 62) SIGRTMAX-2
63) SIGRTMAX-1 64) SIGRTMAX
案例一:告警平台曾經出現過這樣的core資訊
[email protected]:/usr/local/alarmplat/bin# gdb alarmplatd core.6288
GNU gdb 6.3
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i486-slackware-linux"...Using host libthread_db library "/lib/libthread_db.so.1".
Core was generated by `40]iptables中發現非法udp規則32770'.
Program terminated with signal 11, Segmentation fault.
#0 0x0815becf in memcpy ()
(gdb) bt
#0 0x0815becf in memcpy ()
#1 0x08057f07 in CAlarmRecvHandle::processMsg (this=0x40300fd8) at OS_NS_string.inl:35
#2 0xd673656c in ?? ()
#3 0xcfa2b7d0 in ?? ()
從上面的資訊可以看出是因為信号11出現程式終止,出現這個信号的原因是通路越界,從堆棧資訊可以看出大概是processMsg函數裡面的memcpy存在通路越界的問題,找到代碼中此行确實沒有判斷拷貝的消息長度是否超過szContent記憶體的大小限制。
memcpy(szContent, szMsgRcvBuf_ + PROTOCOL_HEADER_LENGTH, iCurrentMsgLen_ - 12);
修改加上判斷之後,問題解決。
案例二:
2008-7-30 有個同僚編譯程式時看到提示如下
make: warning: Clock skew detected. Your build may be incomplete.
程式一執行就出現core down的情況,這個提示的意思是因為檔案可能比作業系統現在的時間還新,導緻時鐘錯亂,編譯不一定順利完成。也就是說你的聲明檔案的資料結構和實作(定義)的資料結構或者函數位址可能是不比對的。這樣程式一旦執行,很有可能就異常退出。
make clean 一次程式,然後重新編譯連接配接你的應用,問題應該能解決。
案例三:檔案過大的問題,信号25
防沉迷有一天出現coredown,檢視core資訊如下:
[[email protected]]#gdb aas_connect /data/corefile/core_aas_connect_1246686328.24608
GNU gdb 6.6
Copyright (C) 2006 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i586-suse-linux"...
Using host libthread_db library "/lib/libthread_db.so.1".
Core was generated by `aas_connect'.
Program terminated with signal 25, File size limit exceeded.
#0 0x08073acd in write ()
(gdb) where
#0 0x08073acd in write ()
#1 0x08136a00 in ?? ()
#2 0x0806601f in _IO_new_file_write ()
#3 0x0806550e in new_do_write ()
#4 0x080654b6 in _IO_new_do_write ()
#5 0x08065007 in _IO_new_file_close_it ()
#6 0x08061828 in fclose ()
#7 0x0804abb5 in Log (pstLogFile=0xbf8b73cc, iLogTime=1, sFormat=0x80a6d46 "listen IP=%s, port=%d, fd=%d") at oi_log.c:111
#8 0x0804a477 in main (argc=1, argv=0xbf9364e4) at aas_connect.c:988
3.3 記憶體洩漏
記憶體是否有洩漏是比較容易确認的,比較高端的系統本身有記憶體洩漏檢測工具,比如valgrind等,其實沒有這些工具我們一樣可以輕松定位記憶體洩漏的問題,借助top,vmstat等系統自帶的工具即可。
案例一:2008-06 前不久dnf商城svr的應用的問題。
程序資訊(top檢視) top -p 7377
程序資訊截圖說明運作的程式占用了太多記憶體(因為記憶體洩漏)。
然後再看了一下開發環境的代碼,果然看到在業務邏輯處理的代碼中存在資源沒釋放的問題,比如:
1 MYSQL_RES* game_res = NULL;
2 ret_ = db_access_->exec_query(sql, game_res);
3 if(0 != ret_)
4 {
5 ACE_DEBUG((LM_INFO, "[%D] Warnning: execute sql=%s failed, ret=%d/n", sql, ret_));
6 return ret_;
7 }
8 int row_num = mysql_num_rows(game_res);
9 if(0 == row_num)
10 {
11 ACE_DEBUG((LM_INFO, "[%D] Warnning: get res num rows, row_num=%d/n", row_num));
12 sprintf(ack, "level=0");
13 return ret_; //沒角色資料
14 }
...
擷取結果成功之後的第13行ret傳回時沒有把資源給釋放掉,缺少 mysql_free_result(game_res); 調用,會存在mysql結果集的記憶體資源沒有釋放。
away把這些情況跟bwar說了一下之後,bwar按照建議把這些地方都補好了,然後更新到營運環境裡面,本就以為萬事大吉了,也沒太注意看其他地方是否有記憶體洩漏的可能。
第二天2008-7-17下午上班後,找bwar再了解了一下商城svr目前的情況,得知37 39兩台機器還是有可當,存在記憶體洩漏時,納悶了一會,核對了資料庫操作的每段代碼,确實經過bwar修改之後資料庫操作的部分應該不會存在記憶體洩漏的可能。然後聊天如下:
awayfang(方學維) 14:12:26
今天商城svr還有問題嗎?調試一下看看什麼問題
…
bwarliao(廖寶華) 14:24:11
剛發現一個問題,好像隻有36、37、39這三台server會經常core,尤其是37和39,這兩台server都是做了插入操作,其它的都隻是查詢,但通路量相差并不是十分大的
bwarliao(廖寶華) 14:28:18
隻做查詢的server 38 幾乎沒core過
awayfang(方學維) 14:29:43
top看看分别占用多大
…
awayfang(方學維) 14:34:36
37 39 都有記憶體洩漏啊,看看top就知道了
awayfang(方學維) 14:34:58
37 39 也都是最新版本嗎?
awayfang(方學維) 14:35:07
和38,功能上有什麼差别?
bwarliao(廖寶華) 14:35:07
37 39 都用了這個函數int DNFDbOper::send_item(QModeMsg &req, char* ack)
awayfang(方學維) 14:36:26
if (iconv(cd,&pin, &inlen, &pout, &outlen)==-1)
{
return errno;
}
iconv_close(cd);
估計你這裡有問題,出錯時,沒close
awayfang(方學維) 14:36:59
cd = iconv_open(to_charset,from_charset);
這個好像是配置設定資源的
…
…
bwarliao(廖寶華) 14:57:36
37更新了,似乎沒有記憶體增長的迹象
那個函數alex用了好久了,我直接拿過來都沒怎麼細看
typedef void *iconv_t; 确實是個記憶體操作,比較隐蔽
bwarliao(廖寶華) 14:59:05
看來寫server和寫一般的程式差別還是很大啊,這個記憶體洩漏在我們跑一段時間就停下來的程式确實不容易發現,也幾乎不會有什麼問題
awayfang(方學維) 14:59:15
那應該沒什麼大問題了
awayfang(方學維) 14:59:59
做svr程式可是長久的事情,普通程式,功能沒問題就行了,記憶體洩漏沒關系,程序退出什麼事都沒了(資源自動被作業系統回收),svr程式可不能有任何問題。
至此,DNF商城svr出現可當的問題應該算是徹底解決了,多謝bwar提供了很多有用的資訊,才能這麼順利解決。
問題總結:
正常情況下,架構本身占用的常駐記憶體(RES)資源從10M-20M左右不等,連接配接數越多,處理連接配接的處理器對象越多,記憶體占用越大,但不可能達到上百M。
正常的截圖如下
在DNF商城的某個機器(37)上看到的情況是這樣的
這個結果看來是明顯有記憶體洩漏了,不然一個程序怎麼會占用603M的常駐記憶體。
記憶體洩漏的具體原因也不難定位,有指針的地方就可能會有記憶體配置設定,你不動态配置設定記憶體空間,不代表别人(你調用的api接口)不動态配置設定,是以程式設計時一定要仔細檢查,判斷是否有問題的方法也簡單,程式運作之後看看資源占用情況即可。
例如:
iconv_t cd;
memset(outbuf,0,outlen);
char *pin = const_cast<char *>(inbuf);
char *pout = const_cast<char *>(outbuf);
cd = iconv_open(to_charset,from_charset);
if (cd==0) return errno;
if (iconv(cd,&pin, &inlen, &pout, &outlen)==-1)
{
return errno;
}
iconv_close(cd);
這段文本轉換的函數,之前也沒有用過,看到前面有open操作,後面有close操作,根據經驗判斷猜想應該是有資源配置設定的,是以推測應該是這裡的問題,iconv轉換失敗的時候沒有進行close操作,導緻記憶體洩漏。
3.4 頭檔案和實作庫不比對
如果頭檔案的資料結構的同名字段和實作檔案的(或lib)裡面的長度不比對(比如char數組的長度)就會導緻程式一啟動執行到這個地方就出現core的情況。
3.5 運作狀态分析工具清單
程式運作時我們怎麼分析系統是否正常,具體都有哪些常用的工具呢?
gdb attach
strace 檢視程序執行到了哪個系統調用
例如:
strace /usr/local/nginx/sbin/im_fcgi 可以檢視到運作的im_fcgi具體正在執行哪些系統調用
ltrace 檢視庫的系統調用情況
例如:
4 網絡問題
網絡問題産生的原因是因為對網絡知識沒有徹底了解造成的,建議好好學習一下《Unix Network Programing》,吃透這本書(建議至少好好看三遍)才真正能說懂得網絡程式設計了。
4.1 Broken pipe
現象:螢幕出現broken pipe的提示,程式被終止(core down)。
原因:向對端(讀端)已經關閉連接配接的socket管道寫入資料造成的,系統錯誤号為32(EPIPE)。這個産生的可能很大部分是因為對端(讀端)可能已經關閉了這個socket(調用了close函數),但是你還是繼續向這個socket句柄send資料,這樣就會導緻這種情況的發生。
案例一:2008年10月份,一位同僚做的網絡程式,有段代碼如下
while (-1 == peer_.send_n(mblk->rd_ptr(), ACE_OS::strlen(mblk->rd_ptr())))
{
peer_.close(); // 關閑原連結
if (-1 == reconnect())
{
ACE_DEBUG ((LM_ERROR,
"@Error[%D](%N,%l) I can't REconnect ! /n"));
return -1;
}
}
peer_ 是 ACE_SOCK_Stream的類,封裝了socket裡面資料流的概念,可以用來操作收發消息(send,recv),此代碼一開始就發送資料,如果是對端已經關閉的連接配接則會導緻broken pipe問題的發生。ACE中也可以用MSG_NOSIGNAL辨別來防止程式因為這個原因退出。
4.2 消息隊列阻塞
netstat 可以檢視消息隊列的阻塞情況。具體參考相關的man手冊
5 線程、程序問題
線程,程序的安全問題說起來簡單,有過相關經驗的人都知道是怎麼回事,可是哪些系統api是線程安全的,哪些不是并不是每個人都能知道的,也不是那麼容易知道的。自己的多線程模式,沒有處理好一不小心就掉了下去,下面分别從幾個方面說明一下線程的安全。
5.1 非線程安全的api(或不可重入)
Linux/Unix系統裡面不少api是非線程安全的,如果不了解api實作原理很難知道是否是線程安全的,但是既然從原理上推斷不了結論,那麼我們就從現象上推斷結論。一般來說,現在的系統api如果對應的函數不是線程安全的,都會有一個_r的線程安全函數與其對應。是以從這點來看,隻要我們 man 這個函數看到有同名_r的函數,那麼可以判斷這個函數是非線程安全的。
比如man localtime發現有這樣的函數
char *asctime(const struct tm *tm);
char *asctime_r(const struct tm *tm, char *buf);
char *ctime(const time_t *timep);
char *ctime_r(const time_t *timep, char *buf);
struct tm *gmtime(const time_t *timep);
struct tm *gmtime_r(const time_t *timep, struct tm *result);
struct tm *localtime(const time_t *timep);
struct tm *localtime_r(const time_t *timep, struct tm *result);
由此我們可以斷定以上的不帶_r的函數都不是線程安全的。
注:庫的線程安全性也可以類推
有些是不可重入的(可重入的函數在unix環境進階程式設計一書的10.6章節有詳細說明)。這樣對多線程程式設計存在很大的安全隐患。
案例一:
5.2 多個線程問題
下面舉一個例子:2008年7月,有個同僚在測試時,發現正常測試時,系統正常運作,但是一旦很大的壓力,程式就會出現core down的情況,很納悶,找了比較久都沒找到原因。檢視core檔案,大概說明core的位置點如下:
// put receive message to module: Logp_Logging_Task
if (Logp_Logging_Task::instance()->put (host_name_mblk) == -1)
{
// release all the contination ACE_Message_Block
host_name_mblk->release ();
ACE_DEBUG ((LM_ERROR,"@Err [%N,%l] call Logp_Logging_Task::instance()->put() error!/n"));
return 0;
}
ACE_DEBUG((LM_DEBUG, "@Deb [%l] received message from:[%s]/n", host_name_mblk->rd_ptr()));
線程模式簡單介紹一下:Logp_Logging_Task 是工作線程,主線程調用其 put 函數把消息放到其内部的消息隊列中,然後工作線程會對主線程放進來的消息進行主動處理。
這個地方的問題就在紅色部分的代碼,單看起來是不會有什麼問題的,
5.3 加鎖之殇
一旦談到線程,程序安全就必然涉及到程序鎖,線程鎖,保證多程序,多線程通路有限資源時,對有限資源進行的串行通路保護機制。
經常聽到有人抱怨,這個程式怎麼挂死,沒什麼反應了,程序還在,就是沒有任何本來應該有的輸出了。這種原因很可能是因為你的程序内部代碼産生了死鎖了。
避免某個鎖釋放之前再次調用擷取該鎖的函數。
盡量晚加鎖,讓鎖的生命周期盡量縮短。
5.4 各種程序線程模式
在Slackware 10.1.0上的測試
THR_NEW_LWP
THR_SCOPE_PROCESS (the old M:N model) has gone extinct.
沒有啟動線程池
THR_SCOPE_SYSTEM
在SUSE Linux Enterprise Server 10 (i586)
THR_NEW_LWP
6 資料庫使用問題
6.1 公司資料庫安裝指導
1.獲得二進制安裝包,一般放到/usr/local/目錄,解包
2.建立mysql使用者,并建立如下目錄,修改相關的屬主
mkdir -p /data/mysqldata/innodb/log/
mkdir -p /data/mysqldata/innodb/data/
mkdir -p /data/mysqllog/binlog
chown -R mysql /data/mysql*
chgrp -R mysql /data/mysql*
3.從現網環境擷取 my.cnf, 存放在/etc/,修改 bind-address=xxxx 指定自己的伺服器 ip 即可
4.執行安裝
./scripts/mysql_install_db --user=mysql
5.啟動 mysql
./bin/safe_mysqld --user=mysql &
6.因為資料空間建立需要時間,等半個小時左右吧,即完成安裝
6.2 慢查詢(耗時查詢)
資料庫的全量查詢或者like等文本内容比對的查詢都是性能很差的慢查詢,随着資料量越大,耗時會越久。比如告警平台的系統裡面有一段這樣的代碼:
snprintf(szSqlBuf, MAX_SQL_BUF_LEN - 1,
"select count(*) from %s.%s where desuser = '%s' and content = '%s' /
and (unix_timestamp(NOW()) - unix_timestamp(gettime)) between 0 and %d;",
szAPlatDbName_, szAPlatTblAlarm_, stAlarm.szDesUser,
stAlarm.szContent, iRepeatTime
);//最近多少天保持不重複
這個資料庫語句用到了文本的比對處理,并且是對資料庫内容的全量資料進行操作,随着資料量的增大,這個性能的消耗将是非常可觀的。對系統的性能影響會很大。
6.3 存儲過程(mysql)
Mysql支援存儲過程從5.0版本才開始,是以之前的老版本是沒有這麼“進階”的特性的。在連接配接模式上多了兩種模式:
CLIENT_MULTI_STATEMENTS 通知伺服器,用戶端可能在單個字元串内發送多條語句(由‘;’隔開)。如果未設定該标志,将禁止多語句執行。
CLIENT_MULTI_RESULTS 通知伺服器,用戶端能夠處理來自多語句執行或存儲程式的多個結果集。如果設定了CLIENT_MULTI_STATEMENTS,将自動設定它。
mysql_next_result() 解決存儲過程多結果集的問題。
案例一:2009-03-31
問題描述:mysql存儲過程執行的問題,有些執行正常,換成另外一個就有問題了,提示大概如下:
Error:mysql_query failed PROCEDURE wgdb_s1.pro_gm_activity_exp_interface can't return a result set in the given context SQL:call wgdb_s1.pro_gm_activity_exp_interface(5,'2009-03-31','2009-04-01',15,23,@ret)
解決辦法:mysql_..._connect(...)最後一個參數是設定連接配接标志的,取值寫上 CLIENT_MULTI_RESULTS 即可
問題原因:未知,從解決結果看可能是結果集的問題,這個sp傳回了多個結果集,導緻連接配接模式不比對提示錯誤。
6.4 資料連接配接
案例一:
問題現象:
Tencent:~ # mysql
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/data/mysqldata/mysql.sock' (2)
Tencent:/data # mysql -h172.27.130.48 -uroot
ERROR 2003 (HY000): Can't connect to MySQL server on '172.27.130.48' (111)
6.5 Mysql編碼問題(ZZ自未知作者)
最近遇到mysql著名的編碼問題,經過一番追究和官方文檔幫助,終于解決,并總結出些經驗:)
一.原理
影響mysql亂碼的問題的根本原因包含字元集和校驗規則
mysql編碼和校驗規則分為四個級别:伺服器級、資料庫級、表級和連接配接級
這四個級别的編碼和校驗規則都有兩個值:預設值和使用者設定值
伺服器級:預設值在my.cnf中确定,這是由編譯安裝時配置定下來的
設定值是在運作mysql時通過 --default-character-set修改
資料庫:預設值繼承自伺服器級 設定值在create database中指定
表級:預設值繼承自資料庫級,設定中在create table中指定
連接配接級:預設值由配置檔案[mysql]節點配置值決定,設定在set names(set character_set_connection x)中指定.
mysql的查詢或者更新或者插入過程如下:
1.客戶段用character_set_client的字元集發送sql
2.伺服器接收到sql語句後用character_set_connection的編碼轉換sql語句,并執行
3.将結果以character_set_results的編碼傳回給用戶端
是以如果用set names xxxz将這三個編碼統一到xxxx,基本上可以避免大部分的亂碼問題.
二.遇到的問題
A Database Error Occurred
Error Number: 1267
Illegal mix of collations (latin1_swedish_ci,IMPLICIT) and (utf8_general_ci,COERCIBLE) for operation 'like'
select * from HostBase where ServiceArr like '%QQ幻想%'
這是一個查詢報錯,由mysql的api報出.查詢前set names utf8了。
為啥會出現這個問題呢?從報錯來看,可以知道預設的校驗規則latin1_swedish_ci和設定的規則utf8_general_ci發生沖突。從sql語句來說,問題肯定出現在中文的"幻想"的校驗規則上,因為英文字母無論是latin1和utf8都是一樣。這個資料庫表的編碼是latin1,而ServiceArr沒指定編碼,是以繼承表的編碼latin1,是以校驗規則必然是latin1_swedish_ci,對于sql語句中的'幻想',mysql有如下的規定,如果字元串沒指定編碼,那麼編碼繼承自character_set_connectio,也就是utf8,由校驗規則的優先級原理,ServiceArr like '%QQ幻想%'用的是ServiceArr的校驗規則latin1_swedish_ci.一個字元集上的校驗規則是不能用在其他字元集上的,是以發生以上錯誤。
三.解決辦法
知道原理和問題産生的原因,解決起來就比較容易了
隻需将sql轉換為latin1,然後在set names latin1即可:)
四,總結
mysql的編碼比較複雜,但對使用而言,隻要保證如下兩點可以解決大多數問題
1.我們傳給mysql伺服器的編碼和從mysql伺服器中取出來的編碼是一緻的
也就是set namse xxxx;
2.應用程式編碼最好也和第一步中的xxxxx一緻。
7 Web開發問題
案例一:http頭部問題
HTTP 1.0 … 缺少導緻用戶端解析異常
8 ACE使用問題
8.1 事件處理器 ACE_Event_Handler
案例一: 2008-6 非時間驅動的處理器(網絡IO事件處理器等)
有位同僚在實作udp的一個網絡伺服器模型時,網絡通信子產品的時間處理器直接基于ACE_Event_Handler實作,模型完成之後發現用戶端發送的消息,此udp伺服器無法響應任何消息,
經過定位之後發現原來是因為這個時間處理器的類沒有實作下面的這個函數。
virtual ACE_HANDLE get_handle (void) const;
總結:非時間驅動的處理器必須要重載get_handle()函數(c++網絡程式設計這本書裡面有明确的說明,大家平時看書還是要仔細體會J),不然事件回調函數handle_...之類的函數無法被Reactor架構正常回調。
案例二:2009-5-12 dynamic_cast 轉換異常
ISGWIntf* intf = dynamic_cast<ISGWIntf*>(eh);
動态編譯的時候遇到的問題,此問題暫時沒解決。
8.2 dev poll / epoll 模式使用
案例一:
2008年7月18日 slackware下商城svr架構要支援epoll模式,通過編譯好支援epoll的ACE庫之後,連結應用程式時正常,啟動後會出現如下提示:
ACE_Dev_Poll_Reactor::open failed inside ACE_Dev_Poll_Reactor::CTOR: Invalid argument
ISGWApp init ACE_Dev_Poll_Reactor failed, errno:22|Invalid argument, ret=0
經過和sailzeng的讨論,發現slackware這個作業系統很特殊(好在及時咨詢,不然要搞死),作業系統裡面特别有個epoll庫(/usr/lib/libepoll.a),連接配接程式時需要明确指定連接配接進來才行,在makefile檔案中加入 -lepoll 進行連結問題解決(不使用ace,直接使用epoll,在slackware10.1下面仍然是需要另外連結這個庫的)。
案例二:
2008年7月23日 有位同僚在slackware10.1作業系統上使用ACE的epoll模式時,一切按照正常的使用方式使用,其他幾個作業系統開發使用都沒問題,唯獨這台機器(gcc3.3.4),運作時仍然出現core的情況,core資訊如下
#0 0x00000000 in ?? ()
#1 0x080787d5 in ACE_Dev_Poll_Reactor::schedule_timer (this=0x8204ed8, event_handler=0x82059e8, arg=0x0, [email protected], [email protected])
at Timer_Queue_T.inl:205
#2 0x0808f742 in ACE_Reactor::schedule_timer (this=0xbfd19138, event_handler=0x82059e8, arg=0x0, [email protected], [email protected])
at ../../ace/Reactor.cpp:689
#3 0x08084222 in ACE_Logging_Strategy::init (this=0x82059e8, argc=9, argv=0x8205918) at Time_Value.inl:81
#4 0x0805bd28 in ACEApp::init_log (this=0xbfd19630, log_num=-1) at ace_app.cpp:263
#5 0x0805b164 in ACEApp::init (thi
s=0xbfd19630, argc=1, argv=0xbfd19974) at ace_app.cpp:146
#6 0x08058a2e in main (argc=1, argv=0xbfd19974) at iigw_svrd.cpp:22
此問題比較特别,可能跟作業系統版本有關,因為沒有時間也沒有特意去看,是以此問題最終什麼原因還沒搞清楚。
8.3 mysql5.0.45版本資料庫的沖突問題
案例一: 前段時間業務在使用我們的ACE svr架構時,因為資料庫版本的問題導緻編譯連結無法完成,提示資訊如下
/usr/local/mysql/lib/libmysqlclient.a(ssl.o):(.gnu.linkonce.d.__vt_Q25yaSSL7Message+0x8): undefined reference to `__pure_virtual'
/usr/local/mysql/lib/libmysqlclient.a(ssl.o):(.gnu.linkonce.d.__vt_Q25yaSSL7Message+0xc): undefined reference to `__pure_virtual'
/usr/local/mysql/lib/libmysqlclient.a(ssl.o):(.gnu.linkonce.d.__vt_Q25yaSSL7Message+0x10): undefined reference to `__pure_virtual'
/usr/local/mysql/lib/libmysqlclient.a(ssl.o):(.gnu.linkonce.d.__vt_Q25yaSSL7Message+0x14): undefined reference to `__pure_virtual'
…
此問題暫時未解決,可能和mysql的庫編譯相關。
8.4 調整ACE預設的時間格式%D的說明
ACE預設的日志格式為 [Thu Dec 10 2009 16:17:17.897167]
看起來會比較别扭,不舒服,如果不修改ACE庫的源碼好像沒什麼好辦法能夠解決,運維同僚一直感覺不爽,
是以最近就對ACE的源碼進行了修改,并重新編譯了新的ACE相關庫,具體修改說明如下:
ACE的日期格式是在ACE.cpp的ACE::timestamp函數中實作的,為了不對ACE産生大的影響,隻是簡單了加了一段宏定義,如下:
#if defined (WIN32)
// Emulate Unix. Win32 does NOT support all the UNIX versions
// below, so DO we need this ifdef.
…
return &date_and_time[15 + (return_pointer_to_first_digit != 0)];
#elif defined (ACE_USE_MY_TIMESTAMP) //add by awayfang 2009-12-11
ACE_Time_Value cur_time = ACE_OS::gettimeofday ();
ACE_Date_Time date_time(cur_time);
ACE_OS::sprintf (date_and_time,
ACE_TEXT ("%04d-%02d-%02d %02d:%02d:%02d.%06d"),
date_time.year(),
date_time.month(),
date_time.day(),
date_time.hour(),
date_time.minute(),
date_time.second(),
cur_time.usec ()
);
return &date_and_time[10 + (return_pointer_to_first_digit != 0)];
#else
…
因為用到了ACE_Date_Time,是以ace.cpp檔案頭部需要增加 #include "ace/Date_Time.h" //add by awayfang 2009-12-11
按照編譯ACE庫的流程,修改 ace/config.h ,增加 #define ACE_USE_MY_TIMESTAMP 進行make & make install 操作即可
修改後的日志格式為:
[2009-12-11 13:45:36.369405] init app succeed
[2009-12-11 13:45:36.369420] write pid file ./isgw_svrd.pid
[2009-12-11 13:45:36.369520] write pid file succeed
[2009-12-11 13:45:36.369535] enter daemon main pid: 24067
[2009-12-11 13:45:36.369549] within daemon main pid: 24067
9 C++是促進腦死亡的最佳方式
此章節是專門用來整理一位朋友sailzeng(曾星)給我們共享的一些經驗,本章節内容全部為sailzeng編寫或者整理,如有轉載請說明
9.1 注意參數的型别和函數參數的比對
檢查COMMLIB部分,發現GCS部分一個告警。
pet_gcs_interface.cpp:212: warning: passing NULL to non-pointer argument 3 of 'ssize_t ACE_SOCK_Stream::send_n(const void*, size_t, int, const ACE_Time_Value*, size_t*) const'
檢查代碼。報告告警的地方在。
petappframe->FrameHeadEncode();
ret = client_stream.send_n((void *)petappframe,len,NULL);
跳過去檢查了一下send_n函數的重載函數,發現了問題。ACE的send_n有兩個重載函數,
/// Try to send exactly @a len bytes from @a buf to the connection socket.
ssize_t send_n (const void *buf,
size_t len,
int flags,
const ACE_Time_Value *timeout = 0,
size_t *bytes_transferred = 0) const;
/// Try to send exactly @a len bytes from @a buf to the connected socket.
ssize_t send_n (const void *buf,
size_t len,
const ACE_Time_Value *timeout = 0,
size_t *bytes_transferred = 0) const;
對于ret = client_stream.send_n((void *)petappframe,len,NULL); 這個調用,上面兩個函數都可以比對,是以對編譯器要麼無法正确編譯,要麼要選擇一個。(其實無法編譯應該更好)。原來的開放者希望比對的函數應該是ssize_t send_n (const void *buf,size_t len, const ACE_Time_Value *timeout = 0,size_t *bytes_transferred = 0) const。但是由于使用了NULL,這個可愛的參數,(#define NULL 0),第3個參數被當作了int參數。實際比對的函數成了ssize_t send_n (const void *buf,size_t len,int flags, const ACE_Time_Value *timeout = 0,size_t *bytes_transferred = 0) const;。
這個代碼應該改為。明确這個指針的類型,避免編譯錯誤。
ACE_Time_Value *time_wait = NULL;
ret = client_stream.send_n((void *)petappframe,len,time_wait);
Effect C++裡面應該有一節講過這個問題。
問題教訓和總結:
注意參數的型别和函數參數的比對,
對于重載函數的參數要精心設計,避免出現這樣參數,ACE這兩個函數的設計就會導緻這個問題,是以它的參數設計其實是失敗。
對于NULL是什麼要有清楚人數,NULL在C++中往往就是被定義為0,而不是((void *)0),是以格外要當心。
9.2 雪崩效應造成處理阻塞
昨天發現ogre4a(一個比較适應通用的通訊協定的伺服器,依靠PIPE和業務程序通訊)發送資料感覺速度慢,(就像有阻塞),伺服器重新開機動一段時間後,就會出現後端伺服器進城将發送管道寫滿的情況。前端的使用者請求無法正常處理。
業務伺服器的日志如下,每次處理都是管道阻塞。
Apr 23 19:00:42.771 [email protected][email protected]_PIPE Pipe is full or data small?,Some data can't put to pipe. Please increase and check.
Apr 23 19:00:42.771 [email protected][email protected]:1234 deque_begin=2707885,deque_end=2813817
Apr 23 19:00:42.771 [email protected][email protected] frame to pipe.len:1437 i:0
Apr 23 19:00:42.771 [email protected][email protected] push_end node->sizeofnode:1437 deque_begin=2521517,deque_end=2521457
Apr 23 19:00:42.771 [email protected][email protected]_PIPE Pipe is full or data small?,Some data can't put to pipe. Please increase and check.
Apr 23 19:00:42.771 [email protected][email protected]:1429 deque_begin=2709119,deque_end=2813817
從OGRE4A的日志來看。
Apr 23 19:32:44.406 [email protected][email protected]:1437 deque_begin=3063266,deque_end=3058935
Apr 23 19:32:44.406 [email protected][email protected]'t find svchanle info. svrinfo IP|Port:[58.44.83.95|24812] .
Apr 23 19:32:44.406 [email protected][email protected] 767 peer want to close. Please wait. ACE that is accursed.
從日志和配置檔案,代碼定位看到情況如下:
1.發送PIPE的管道不長,隻有5M。但是這個問題應該不足以引發問題,隻是錯誤的一個誘因。
2.INFOSVRD發送的資料比較長,一個使用者就有1.6K左右。結合前面的問題,目前的管道隻能處理大約3000個請求。但這還是一個誘因。
3.根據日志觀察,每次OGRE都隻從管道取出一個資料發送,但是卻找不到發送目标對應句柄,由于是WEB業務,這個伺服器的用戶端可能經常斷開。
5.檢查OGRE的代碼,在發送資料時如果出現錯誤(包括找不到對端)就退出從PIPE取資料的循環。如果正常,這個循環會一次取多達1024個發送資料。而錯誤情況,隻處理一個資料。
6.每次處理的時間片間隔有點長,達到0.05s。
由于上面這些原因和錯誤,一個雪崩效果就造成了。
由于用戶端可能經常吊線,結果造成每次從PIPE隻能取一個資料出來,是以找不到原來對應的端口。然後處理退出循環,繼續等,然後由于等待時間很長,更多的端口肯定斷掉了,結果隻有惡性循環了。是以資料一直發送不出去。
修正問題
核心問題應該還是處理循環的問題,将代碼修改為出現錯誤時,繼續處理,測試,用戶端得到正常請求。其他幾個問題調整後修正。
9.3 dlsvrd日志時間出錯
現象:
由于anna MM反映無法更新pet_def.db3檔案,于是到dlsvrd上跟了一把日志。發現輸出的日志時間不太對,也沒有太在意,以為可能是誰把dlsvrd停了,ps一把,發現dlsvrd程序還在,而且是幾天以前了,感覺有點奇怪,于是重新開機了dlsvrd,發現時間又正常了,于是讓anna再測一次,猛然發現正确的時間突然又不對了,而且正好和現在的時間相差8小時,日志時間從09:48倒回到01:48。Date發現,系統時鐘仍然是09:48,有意思。初步認為是程式中的什麼地方将時區進行了修改。
定位:
根據日志打出的上下文去查代碼,發現在此期間隻有format_gmt_time一個函數進行了實際的操作,函數代碼如下:
size_t DlsvrTask::format_gmt_time(time_t timestamp, char *buff, size_t buflen)
{
struct tm tm;
gmtime_r(×tamp, &tm);
return strftime(buff, buflen, "%a, %d %b %Y %X GMT", &tm);
}
Gmtime_r:将timestamp解析成GMT然後将結果儲存到tm中,線程安全(dlsvrd采用了多線程)。
Strftime:将tm已指定的格式和長度輸入到buff中。
理論上來說,這兩個函數都沒有可能去修改時區,由于該函數位于子線程中,是以sail認為可能和多線程有關系,于是将這段代碼單獨移到主循環中(線程初始化之後),發現仍然會出現這個問題。同時分别将這兩個函數進行屏蔽,發現當屏蔽strftime時不會出現此現象,斷定是由于strftime造成的時區變化。
但是sail單獨寫了一段測試代碼發現,無論怎麼調strftime和gmtime_r,都不會産生時區變化,于是又懷疑是多線程的原因,将gmtime_r和strftime移到線程初始化之前,發現問題依舊,無語。但無意間将這兩個函數移到InitInstance的最開始,發現沒有出現時區變化的問題,神了。那麼從InitInstance的最開始到線程初始化之間的代碼和strftime共同作用的結果,且存在順序問題。
無奈,隻好老老實實、一個一個比較測試程式和InitInstance的最開始到線程初始化之間代碼的差異。
發現将strftime和gmtime_r移到下面一段代碼之前和之後,輸出結果明顯不同,同時,執行和不執行strftime,也會影響時區(也難怪sail在windows在調了半天dlsvrd也沒有重制這個問題)
#ifndef WIN32
//chroot
ret = chroot(InstOfDlsvrSvrConfig::instance()->root_path_.c_str());
if (ret != 0)
{
ACE_DEBUG((LM_ERROR,"chroot failed: %u | %s/n", ACE_OS::last_error(), strerror(ACE_OS::last_error())));
return ret;
}
#endif
于是自己寫了一段測試代碼(見附件),發現是由chroot和strftime一起調用引起的問題。
原因:
strftime在《The Single UNIX ® Specification, Version 2 Copyright © 1997 The Open Group》有如下一段解釋:
“Local timezone information is used as though strftime() called tzset().”
即strftime會通過tzset來擷取時區的資訊。
在man tzset中有這樣一段解釋:
“If the TZ variable does not appear in the environment, the tzname variable is initialized with the best approximation of local wall clock time, as specified by the tzfile(5)-format file localtime found in the system timezone directory (see below). (One also often sees /etc/localtime used here, a symlink to the right file in the system timezone directory.)”
簡單來說,就是tzset是通過TZ環境變量或是/etc/localtime來設定timezone,而我們目前沒有設定TZ變量,是以實際是通過/etc/localtime來設定的。由于我們沒有在InstOfDlsvrSvrConfig::instance()->root_path_下設定/etc目錄,是以在chroot後在調用strftime,tzset會找不到localtime,是以将timezone設定成0.這樣,日志的時間就從原來的CST變成了GMT。
修改
方案一:簡單的方法是在InstOfDlsvrSvrConfig::instance()->root_path_下cp一個/etc/localtime,但是由于這個變量是從配置檔案裡讀的,那麼改一次配置需要cp一次,麻煩。
方案二:由于dlsvrd已經對字元”..”進行了屏蔽,那麼其實chroot也就不那麼必要了,初步考慮是将chroot去掉。
思考
Q:為什麼strftime會調用tzset?
A:因為strftime有一個參數%Z,用于格式化時區,而其無法通過tm參數來獲得時區的資訊,是以必須通過tzset來獲得timezone,這個是可以了解。但是我們在程式中其實并沒有用到%Z這個參數, 那麼理論上來說,不應該去調tzset,這個有點想不通。
Q:linux下的3個時間檔案的作用
A:/etc/sysconfig/clock - this is a short text file that defines the timezone, whether or not the hardware clock is using UTC, and an ARC option that is only relevant to DEC systems.
/etc/localtime - this is a symbolic link to the appropriate time zone file in /usr/share/zoneinfo
/usr/share/zoneinfo - this directory contains the time zone files that were compiled by zic. These are binary files and cannot be viewed with a text viewer. The files contain information such as rules about DST. They allow the kernel to convert UTC UNIX time into appropriate local dates and times.
如果隻關注timezone的話,簡單而言,3個檔案作用如下:
/etc/sysconfig/clock 是定義timezone的文本檔案
/etc/localtime 是zoneinfo下一個檔案的硬連接配接,這個檔案由/etc/sysconfig/clock中的ZONE選項指定
/usr/share/zoneinfo 這個目錄下存儲了各個時區與UTC轉換的相關規則和資訊。
那麼,為什麼需要三個這樣的檔案呢?兩個應該是完全夠用的。如果沒有clock,那麼程式每次到localtime去查詢轉換規則即可,如果沒有localtime,那麼每次到clock去查詢ZONE選項,再通過ZONE去定位/usr/share/zoneinfo目錄下的相關檔案,查詢轉換規則,這樣也是可以的。由此可以感覺到/etc/sysconfig/clock和/etc/localtime至少有一個是多餘的,不知道為什麼會設計如此。Google了很久,未果,待續……
10 設計規範
這裡的設計規範不從宏觀上怎麼講解設計,用什麼設計模式解決系統的可擴充性,降低系統的耦合性,提高系統的性能等等。隻從一般的開發中可具體操作的細節方面指導一些編碼或者設計需要主要的事項,使得代碼更清晰可讀,營運維護更友善。
10.1 函數
類内的流程控制函數不能直接調用外部提供的接口,最好隻調用類内部的函數,在函數内部調用外部的函數,避免流程受外部接口的影響。
10.2 日志
1 頻繁被調用的函數不要記錄日志,除非是業務要求的流水。
2 子產品直接的消息接收和發送必須要有日志,以便營運維護友善定位問題。
3 如果日志量太大,以上規則要适當調整,至少是有日志開關
4 以上規則要兼顧性能上的問題,用曾總的話說“平衡是道中之道”
11 後記
11.1 作者介紹
11.2 參考文檔
《Thinking in C++》
《Advanced Programing in Unix Envirement》
《Unix Network Programing》
《Design Patterns》
《C++ Network Programing》
《POSA》 V1 V2 V3
11.3 緻謝
誠摯的謝意獻給為本文檔提供過相關貢獻的騰訊同僚或者朋友,他們或者為文檔裡面提到的内容提供來源,或者為相關問題提供解決方案。具體名單如下(排名不分先後以及貢獻大小,按字母順序排序): anselyang campingliu jeffli bwarliao clarkli kylemao sandypan sailzeng