smartFox錯誤記載發生session create, session remove問題
阿新 • • 發佈：2018-12-04
● 遊戲伺服器偶爾出現如下針狀
2018-11-10 13:51:43,689 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session removed: { Id: 4, Type: DEFAULT, Logged: No, IP: 192.168.0.104:55975 } 2018-11-10 13:52:19,338 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session created: { Id: 5, Type: DEFAULT, Logged: No, IP: 192.168.0.104:55989 } on Server port: 9988 <---> 55989 2018-11-10 13:53:08,704 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session removed: { Id: 5, Type: DEFAULT, Logged: No, IP: 192.168.0.104:55989 } 2018-11-10 13:53:10,609 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session created: { Id: 6, Type: DEFAULT, Logged: No, IP: 192.168.0.104:55994 } on Server port: 9988 <---> 55994 2018-11-10 13:53:55,742 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session removed: { Id: 6, Type: DEFAULT, Logged: No, IP: 192.168.0.104:55994 } 2018-11-10 13:54:04,833 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session created: { Id: 7, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56014 } on Server port: 9988 <---> 56014 2018-11-10 13:54:14,219 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session removed: { Id: 7, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56014 } 2018-11-10 13:54:27,805 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session created: { Id: 8, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56021 } on Server port: 9988 <---> 56021 2018-11-10 13:55:13,444 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session removed: { Id: 8, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56021 } 2018-11-10 13:55:20,640 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session created: { Id: 9, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56028 } on Server port: 9988 <---> 56028 2018-11-10 13:55:31,303 | INFO | pool-2-thread-5 | c.s.v2.util.stats.CCULoggerTask | CCU stats: { Zone: --=={{{ AdminZone }}}==-- }, CCU: 0/0 2018-11-10 13:55:31,304 | INFO | pool-2-thread-5 | c.s.v2.util.stats.CCULoggerTask | CCU stats: { Zone: COK1 }, CCU: 0/0 2018-11-10 13:55:31,304 | INFO | pool-2-thread-5 | c.s.v2.util.stats.CCULoggerTask | CCU stats: CCU: 0/0 2018-11-10 13:56:05,317 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session removed: { Id: 9, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56028 } 2018-11-10 13:56:12,304 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session created: { Id: 10, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56036 } on Server port: 9988 <---> 56036 2018-11-10 13:57:43,277 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session removed: { Id: 10, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56036 } 2018-11-10 13:58:13,233 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session created: { Id: 11, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56050 } on Server port: 9988 <---> 56050 2018-11-10 13:58:18,775 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session removed: { Id: 11, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56050 } 2018-11-10 13:58:36,421 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session created: { Id: 12, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56058 } on Server port: 9988 <---> 56058 2018-11-10 13:58:57,724 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session removed: { Id: 12, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56058 } 2018-11-10 13:59:06,673 | INFO | SocketReader | c.s.b.sessions.DefaultSessionManager | Session created: { Id: 13, Type: DEFAULT, Logged: No, IP: 192.168.0.104:56062 } on Server port: 9988 <---> 56062
● 一旦出現此bug,所有玩家全部登入不上,線上玩家不受影響.只要是玩家執行登入流程,全部卡在50%介面,死活登入不了.
● 經過N久的研究,最後發現是執行緒的原因.讓我們慢慢道來.
首先,這個smartFox原始碼中用於執行登入流程的有一個執行緒池,這個執行緒池比較坑,看如下原始碼
public final class SFSEventManager extends BaseCoreService implements ISFSEventManager { private int corePoolSize = 4; private int maxPoolSize = 5; private int threadKeepAliveTime = 60; private final ThreadPoolExecutor threadPool; private final Map<SFSEventType, Set<ISFSEventListener>> listenersByEvent; private final Logger logger; public SFSEventManager() { this.setName("SFSEventManager"); this.logger = LoggerFactory.getLogger(SFSEventManager.class); this.threadPool = new ThreadPoolExecutor(this.corePoolSize, this.maxPoolSize, (long)this.threadKeepAliveTime, TimeUnit.SECONDS, new LinkedBlockingQueue()); this.listenersByEvent = new ConcurrentHashMap(); }
如上圖所示,這個執行緒池只有4個核心執行緒,只有4個核心執行緒,只有4個核心執行緒!!重要的事說三遍,最大執行緒數量為5,然並卵,執行緒的數量永遠永遠永遠只可能是4個,為什麼呢?請看執行緒使用的阻塞佇列LinkedBlockingQueue,我們來看下預設阻塞佇列的大小:
public LinkedBlockingQueue() {
this(Integer.MAX_VALUE);
}
看到沒,阻塞對列的大小是int的最大,也就是21E多,這是什麼概念?對於我們小遊戲公司來說,玩家登入次數可能永遠達不到這麼多,也就是說可能永遠也觸發不了新的執行緒,換一種說法,執行緒池最大大小5永遠觸發不了,執行緒池的執行緒大小永遠是核心數量大小4.這是一個坑的地方!
● 坑二
上面我們說過用於執行登入流程的執行緒數量只有4個,如果遊戲玩家不多且併發不高,那麼還算稍微正常點,但是一旦遇到一些特殊情況,如遊戲剛開服,或者遊戲維護結束之後,此時有大批玩家登入,這就出現問題了.
登入流程載入東西過多,假設一個玩家耗費5秒,此時若是1000個玩家同時登入,後面的玩家只能慢慢等待前面玩家登入走完才能登入.4個執行緒執行,每個玩家耗時5秒,想想第1000個玩家得等待多久!!!
● 坑三
坑三也是最坑,前面幾個坑忍忍也就過去了,這個坑直接讓遊戲完蛋.為什麼呢?
前面說過執行登入執行緒4個,only 4個,也就要求你要保證這4個執行緒不能出一丁點意外,比如執行緒阻塞,一旦出現執行緒阻塞了,那麼玩完了,4個執行緒同時阻塞(只要出現一個阻塞,四個很快同樣阻塞),導致後面登入的玩家永遠獲取不到執行緒用來執行登入.這樣就會出現頻繁的session create, session remove.
我們做了個實驗,在登入邏輯處給執行緒睡一下,用一個號登入遊戲,這時候,一個執行緒被佔用,一直睡在那,反覆執行四次,所有的執行緒都被耗盡了,此時登入執行緒池已經無能為力了,它已經沒有能力建立新的執行緒來執行登入了,因為阻塞佇列根本超不出佇列的長度.也就是說最大執行緒數量5是無效的.
● 解決方法
1.有能力的改原始碼.
2.找到執行緒阻塞的原因
3.個人認為最重要的是如何讓阻塞的執行緒釋放