Weblogic81中HttpCompleteMessageTimeout相關的兩個異常

在網絡性能較差的環境中，weblogic server的日志中經常能看到如下的兩種異常，

1：####<Mar 1, 2005 12:18:57 PM PST> <Error> <HTTP> <****> <****> <ExecuteThread: '3' for queue: 'weblogic.kernel.System'> <<WLS Kernel>> <> <BEA-101083> <Connection failure. java.io.IOException: A complete message could not be read on socket: 'weblogic.servlet.internal.MuxableSocketHTTP@115954e - idle timeout: '30000'

ms, socket timeout: '100' ms', in the configured timeout period of '60' secs

2：####<2008/11/14 09:18:23 PM PST> <Info> <HTTP> <****> <****> <ExecuteThread: '0' for queue: 'weblogic.kernel.System'> <<anonymous>> <> <BEA-101326> <The server could not send the HTTP message during the configured timeout value. The socket has been closed.>　

我們可以看到上面的兩個異常都是因為在指定的timeout時間內完成數據包的發送。BEA-101083出現在客戶端請求往服務器端發送請求數據的時間內沒有結束，而BEA-101326則是發生在weblogic回寫response的時候在指定的timeout內沒有完成數據包發送。 HttpCompleteMessageTimeout默認值為60秒，最大值為480秒。如果沒有設定，會取 server---->Protocols---->General中的CompleteMessageTimout值（general中配置適合於所有協議，包括Http, T3, IIOP等）。如果兩個都沒有設定，那麼weblogic server會將該值設定為：CompleteMessageTimeoutTrigger. CLEANUP_TRIGGER_TIMEPERIOD_LOW=2secs。

注意：CompleteMessageTimeout是數據包，而不是整個請求的timeout時間。

對於BEA-101326，假如客戶端請求下載一個100M的文件，這100M的文件將會被分解成N多TCP/IP 　packets進行傳送（weblogic內部為chunk，默認的chunk大小為4080bytes，chunk的大小可以通過 -Dweblogic. ChunkSize設定）。100M的文件即使在網絡性能很好的情況下，也很難在60秒（CompleteMessageTimout的默認值）內完成，所以這個timeout不是針對整個reponse而言的。在weblogic實現中，每次回寫數據包(Chunk)的時候，會將當前的 OutputStream register到CompleteMessageTimeoutTrigger中，這樣trigger被觸發的時候，它會負責檢查這個數據報是否在指定的timeout內完成發送，如果沒有，則BEA-101326會記入到日志中，同時會關閉到客戶端的socket，剩余的數據將無法繼續寫入。如果數據包在timeout之前已經寫完，該OutputStream會從tigger中移除，tigger不會繼續檢查該OutputStream

1　static　void　writeChunks(Chunk　header,Chunk　c,　OutputStream　os,　int　size,　boolean　chunkXfer)　throws　IOException　{
2　　　　　　　try　{
3　　　　　　　　　　　　　trigger.register(os);
4　　　　　　　　　　　　　if　(chunkXfer)
5　　　　　　　　　　　　　　　　　　　　　writeChunkTransfer(header,c,　os);
6　　　　　　　　　　　　　else
7　　　　　　　　　　　　　　　　　　　　　　writeChunkNoTransfer(header,　c,　os,　size);
8　　　　　　　}　finally　{
9　　　　　　　　　　　　　trigger.unregister(os);
10　　　　　　}
11}

BEA-101326通常跟網絡性能有關系（60秒內，4k的數據無法發送完成），首要解決方法就是調優網絡。從weblogic方面來看，我們可以通過調整如下兩個參數來解決這個問題，但這不是解決問題的關鍵。

1：增加HttpCompleteMessageTimeout，最大值為480秒

2：減小weblogic.ChunkSize

至於BEA-101083，通常是因為客戶端發送的請求數據不能在HttpCompleteMessageTimeout內完成，常見的兩種情況是：性能很差的網絡環境、黑客攻擊（連續的向服務器寫入數據，但每次寫入很少的數據，例如，10bytes/secs或更少）。客戶端數據讀取超時是通過SocketMuxer.TimeoutTrigger實現的。這個trigger同時還負責IdleTimeout（KeepAlive的 HttpConnection的Duration，默認為30秒）。

1　　　/*package*/　final　int　checkTimeout(long　idleTimeout,　long　msgTimeout)　{
2　　　　　int　status　=　OKAY;
3　　　　　long　interval;
4　　　　　synchronized　(this)　{
5
6　　　　　　　if　(messagePending())　{
7　　　　　　　　　if　(msgTimeout　<=　0)　return　OKAY;
8　　　　　　　　　/*
9　　　　　　　　　*get　time　left　for　reading　message　from　client.　When　SocketMuxer　begins　reading　packets
10　　　　　　　　　*from　http　connection.　System.currentTimeMills()　is　recorded　info　SocketInfo　as　lastMessageReadingStartedTimeMillis
11　　　　　　　　　*and　in　getMessageIntervalMillis(),　it　returns　(System.currentTimeMills()　-　info.lastMessageReadingStartedTimeMillis)
12　　　　　　　　　*If　reading　finishes　in　time,　SocketMuxer　will　set　messagePending　to　false.
13　　　　　　　　　*/　
14　　　　　　　　　interval　=　getMessageIntervalMillis(msgTimeout);
15　　　　　　　　　if　(interval　<=　msgTimeout)　return　OKAY;
16　　　　　　　　　status　=　MSG_TIMEOUT;
17　　　　　　　}　else　{
18　　　　　　　　　　　　//idle　timeout　is　checked　here
19　　　　　　　}
20　　　　　　　//for　MuxableSocketHttp,　ms.requestTimeout()　is　always　true,　i.e.,　timeout　affects　such　connection
21　　　　　　　if　(!ms.requestTimeout())　return　OKAY;
22　　　　　　　setCloseOnly();
23　　　　　}
24　　　　　return　status;
25　　　}

對於IdleTimeout，可以參考SocketInfo.lastIoInitiatedTimeMillis　

Last time we had some activity on socket, for enforcing idle timeout　of a socket.　 A -1 value indicates that there is no pending IO.

用於控制keepAlive的HttpConnection空閒多長時間後將被weblogic關閉，所以空閒，是指Socket上沒有IO操作。

要解決BEA-101083，基本和BEA-101326差不多，還是要解決網絡性能問題，另外就是加強網絡安全管理，防止黑客攻擊。

最後在說一下CompleteMessageTimeout設定，weblogic admin console上提示改設定是動態的，即不需要重啟，但實際並不是這樣的。如果該設定是要解決BEA-101083，那麼它是動態的，不要重啟，而如果是要解決

BEA-101326，那麼要使設定生效，重啟是必須的。我們看一下兩個trigger就知道了，

BEA-101083，SocketMuxer,

1　　　protected　class　TimeoutTrigger　implements　Triggerable　{
2　　　　　public　void　trigger(Schedulable　sched)　{
3　　　　　　　MuxableSocket[]　socks　=　getSockets();
4　　　　　　　for　(int　i　=　0;　i　<　socks.length;　i++)　{
5
6　　　　　　　　　MuxableSocket　ms　=　socks[i];
7　　　　　　　　　SocketInfo　info　=　ms.getSocketInfo();
8　　　　　　　　　if　(info　==　null)　continue;
9　　　　　　　　　long　idleTimeout　=　ms.getIdleTimeoutMillis();
10　　　　　　　　　long　msgTimeout　=　ms.getCompleteMessageTimeoutMillis();
11
12　　　　　　　　　switch　(info.checkTimeout(idleTimeout,　msgTimeout))　{
13
14　　　　　　　　　}
15
16　　　　　　　}　　
17　　　　　}　
18　　　}

BEA-101326, ChunkUtils

1　　　　　static　{
2　　　　　　　trigger　=　new　CompleteMessageTimeoutTrigger();
3　　　　　}

從上面代碼可以看出，BEA-101083的trigger每次被觸發的時候，都會重新讀取配置參數，所以修改是動態的。而BEA- 101326，tigger是靜態變量，當ChunkUtils被load的時候實例化，實例化的時候，它會讀取配置參數。但靜態變量的初始化只有一次，除非ChunkUtils被重新裝載，所以需要重啟才能使該設定生效。