§1 Weblogic 日志分析
BEA 公司是 weblogic 的厂商，他们做的日志比我们更专业，我非常肯定他们的分析。 在这里，我就不重复 BEA 公司对肇庆电网营销系统的再分析了，只是从开发的角度，对一 些问题做一点补充。

BEA 的分析非常正确，关于解决方法有一点补充。 这个也可能是网络的原因导致的， 因此建议对于出现慢的地区的网络进行检查， 确保网 络有足够的带宽与速度。

补充一点，这可能是程序内部的代码不优化，导致有大量数据产生，从日志来看，可能 下面这些组件需要优化： epm.component.ar.cmp_ar_servicelocation epm.component.msflow.cmp_ms_ex_flow_getout epm.component.aparchive.cmp_ag_meterasset epm.component.chg.cmp_chg_arrear_query epm.component.aparchive.cmp_ag_servicelocation epm.component.flow.cmp_flow_worklist epm.component.chg.cmp_chg_bank_chgmonth

日志分析

1、日志中 BEA 相关打印信息类汇总 ........................................................................ 3 2、各 BEA 代码分类明细 .......................................................................................... 3 3、BEA 代号分析 ...................................................................................................... 5 3.1、错误类代码分析 ................................................................................................ 5 3.2.Debug 类分析...................................................................................................... 9 3.3.Alert 类分析 ....................................................................................................... 10 3.4.Waining 类分析 ................................................................................................. 11 4、BEA 代码段分析 ................................................................................................ 12 5、日志总体分析 ..................................................................................................... 17

说明： 日志时间段：May 15, 2007 9:02:37 AM CST to May 15, 2007 3:42:03 PM CST Server :weblogic_a2 logname weblogic_a2.log time:2007-5-15 15:42 size:27,275,777K 以下为针对日志中与 weblogic 相关信息进行分析，特别是大量中间件信息与 BEA 相关 代码进行统计及打印信息及特点进行描述。

§1.3 1、日志中 BEA 相关打印信息类汇总
分类 info notice Warning Alert debug error BEA 代码个数 89 16 2 1 1 6 日志出现个数 281 46 1115 1 1 803

§1.4 2、各 BEA 代码分类明细
1、Info 类 BEA-代码 BEA-000111 BEA-000158 BEA-149059 BEA-149060 BEA-320002 BEA-220028 BEA-220029 BEA-281004 BEA-281005 BEA-001514 BEA-001508 BEA-001128 BEA-001126 BEA-040308 BEA-040107 BEA-040015 BEA-001144 BEA-001146 出现个数 1 1 8 8 1 1 1 1 1 1 1 1 1 1 1 1 1 1 BEA-代码 BEA-001149 BEA-000103 BEA-000236 BEA-141107 BEA-000215 BEA-002900 BEA-000214 BEA-320001 BEA-280050 BEA-149513 BEA-001515 BEA-200001 BEA-000377 BEA-002622 BEA-002624 BEA-000570 BEA-002609 BEA-000406 出现个数 1 1 1 2 2 2 2 2 4 1 1 1 2 20 2 2 2 2 BEA-代码 BEA-002014 BEA-400000 BEA-001135 BEA-001140 BEA-190000 BEA-190001 BEA-040090 BEA-040407 BEA-040306 BEA-281002 BEA-101237 BEA-101135 BEA-101052 BEA-101129 BEA-220031 BEA-220027 BEA-141187 BEA-149209 出现个数 2 2 2 2 2 2 2 1 2 2 2 2 2 2 2 2 2 2

BEA-001147 BEA-000626 BEA-001517 BEA-001512 BEA-001174 BEA-001124 BEA-320000 BEA-000115 BEA-000128 BEA-002610 BEA-101295 BEA-002638 2、Notice 类 BEA-代码 BEA-000365 BEA-101276 BEA-101277 BEA-002607 BEA-000395 BEA-090082 BEA-170027 BEA-000102 3、Warning 类 BEA-代码 BEA-170011 4、Alert 类 BEA-代码 BEA-000396 5、Debug 类 BEA-代码 BEA000571 6、ERROR 类 BEA-代码 BEA-101017 BEA-101019 BEA-100049

出现次数 16 3 1 1 2 2 4 2

BEA-代码 BEA-101275 BEA-000138 BEA-000133 BEA-000142 BEA-000164 BEA-002613 BEA-000330 BEA-000360

出现次数 1 2 2 2 2 2 2 2

出现次数 1

BEA-代码 BEA-100089

出现次数 1114

出现次数 2

BEA-代码

出现次数

出现次数 1

BEA-代码

出现次数

出现次数 553 21 2

BEA-代码 BEA-101083 BEA-101214 BEA-101020

出现次数 217 8 2

§1.5 3、BEA 代号分析

3.1、错误类代码分析
3.1.1、代号：BEA-101017

§例举信息 <May 15, 2007 9:03:15 AM CST><May 15, 2007 9:05:02 AM CST><May 15, 2007 9:05:05 AM CST><May 15, 2007 9:05:32 AM CST><May 15, 2007 9:06:01 AM CST><BEA-101017> <[weblogic.servlet.internal.WebAppServletContext@31398b00 - appName: 'epm', name: 'epm', context-path: '/epm'] Root cause of ServletException. at ep.base.ServletRequestInfoImpl.doInclude(ServletRequestInfoImpl.java:160) <May 15, 2007 9:04:12 AM CST> §发生次数 553 §BEA- 代码分析 BEA-101017 Error: [context] Root cause of ServletException. Description [context] Root cause of ServletException, which the Web application container caught while servicing the request. Cause The Web application container caught an unexpected exception. Action Check the exception for the exact error message §错误分析 现象分析： 从所提供的日志上看，引发这个错误都将抛出异常：java.net.SocketException: socket write error: Connection reset by peer. 形成的原因： 联系上错误的上下文可分析出，形成这种异常的主要原因就是用了一个已经关闭的 socket，而产生这种现象有可能存在以下的操作： 1、 客户端在请求后未待数据加载完就作了取消动作。如按暂停、关闭 IE、切换到别的功能 等。 2、 http request timeout value is too small.特别是当大量数据返回时容易产生超时现象. 3、 连接池连设置里没把把三个 test 连接的选项勾上 产生影响: １、对性能和业务没有影响。 ２、用 fireFox 访问不会产生此异常。 解决办法： 1、http request timeout value 调大一点。

2、连接池的设置里把三个 test 连接的选项勾上 参考文档 《BEA WebLogic 平台下 J2EE 调优攻略.》 《WebLogic Server 性能调优 》 http://bbs.chinaunix.net/archiver/?tid-662314.html http://bbs.chinaunix.net/archiver/?tid-662314.html http://support.bea.com/application_content/product_portlets/support_patterns/wls/wls_clust ering.jsp http://www.bea.com.cn/support_pattern/Investigating_Struts_with_WebLogic_Server_Patte rn.html

3.1.2、代号：BEA-101083

§例举信息 <May 15, 2007 9:05:32 AM CST><BEA-101083> <Connection failure. java.io.IOException: A complete message could not be read on socket: 'weblogic.servlet.internal.MuxableSocketHTTP@318b4e69:Socket[addr=/172.19.3.53,port=1072, localport=7020] - idle timeout: '30000' ms, socket timeout: '120000' ms', in the configured timeout period of '60' secs §发生次数 217 §BEA- 代码分析 BEA-101083 Error: Connection failure. Description The HttpRequest failed to execute. Cause Failed while writing data into the stream. Action Check the exception for exact cause. 错误分析 从上下文内容来讲是由于 socket timeout 而引起的。 引起这种错误还有一种可能就是程序中采用数据传递采用 get 方法是，字节过多，这里 就要把数据传递改成 POST 方法了。Try to limit the content to 2000 bytes to see if it works. 参考文章 http://dev2dev.bea.com.cn/bbs/thread.jspa?forumID=81&threadID=16891

3.1.3、代号：BEA-101019

§例举信息 <May 15, 2007 9:09:25 AM CST> <Error> <HTTP> <zqyx-app-01> <weblogic_a2> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1179191365015> <BEA-101019> <[weblogic.servlet.internal.WebAppServletContext@31398b00 - appName: 'epm', name: 'epm', context-path: '/epm'] Servlet failed with IOException weblogic.utils.NestedRuntimeException: Cannot parse POST parameters of request: '/epm/component.do' §发生次数 21 §BEA- 代码分析 BEA-101019 Error: [context] Servlet failed with IOException Description [context] Servlet failed with IOException Cause An unexpected IOException was caught while processing request. Action Check the exception for exact error message. 错误分析 从日志上下文中发现，所有出现这种错误都与应用/epm/component.do 相关，而且均为 Cannot parse POST parameters of request。 很明显应用有可能在 request 中采用了 Post 方法来传递数据或试图取一个不存在 Request 的值,一般都指取 session。 参考文章 http://dev2dev.bea.com.cn/bbs/thread.jspa?forumID=121&threadID=20060&messageID=11 5674 http://dev2dev.bea.com.cn/bbs/thread.jspa?forumID=121&threadID=18115 http://www.theserverside.com/news/thread.tss?thread_id=29058 http://saloon.javaranch.com/cgi-bin/ubb/ultimatebb.cgi?ubb=get_topic&f=40&t=002914 http://discuss.fogcreek.com/joelonsoftware/default.asp?cmd=show&ixPost=73334 http://curl.haxx.se/mail/lib-2001-07/0012.html

3.1.4、代号：BEA-101214

§例举信息 <May 15, 2007 9:18:19 AM CST> <Error> <HTTP> <zqyx-app-01> <weblogic_a2> <[ACTIVE] ExecuteThread: '14' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <>

<1179191899374> <BEA-101214> <Included resource or "/epm/static/common/ep/base/webGrid.interface.js" not found from requested "/epm/component.do".> §发生次数 8

错误分析： 从 抛 出 的 异 常 中 可 以 看 出 应 用 程 序 中 的 应 用 文 件 不 全 Included resource or file "/epm/static/common/ep/base/webGrid.interface.js" not found from requested resource "/epm/component.do" §1.5.1.5 3.1.5、代号：BEA-100049

§例举信息 <May 15, 2007 9:32:26 AM CST> <Error> <HTTP Session> <zqyx-app-01> <weblogic_a2> <[ACTIVE] ExecuteThread: '8' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <> <1179192746937> <BEA-100049> <Error looking up session with id:dnTxGJCQZpPBbm0sL4bQhxqBGdrt4S0lJ95XZ9p9BVhypqTWV3vh!1575745605!-2227711 69 java.rmi.ConnectIOException: Server is being shut down Error: Error looking up session with id:id §发生次数 2 §BEA- 代码分析 Description Error looking up session with id:id - session refresh failed Cause Got RemoteException looking up session from the secondary Action Check if the secondary server is down. Note that it is not recommended to kill both the primary and secondary server at the same time. Remember the replication happens lazily, upon request. So if you need to bring down the secondary server too give sufficient time so that the active end users hit their sessions and they get replicated. 原因分析 这是由于做集群时 session 同步而引起的。如果服务在没完全启动完时访问就不存在这 种异常了。或做 session 复制也不会产生这个问题。 参考文档： http://forums.bea.com/bea/message.jspa?messageID=202198273&tstart=0 http://forums.bea.com/bea/thread.jspa?messageID=202184320&tstart=0 §1.5.1.6 §例举信息 <May 15, 2007 9:35:39 AM CST> <Error> <HTTP> <zqyx-app-01> <weblogic_a2> <[ACTIVE] 3.1.6、代号：BEA-101020

3.2.Debug 类分析
3.2.1、代号：BEA-000571

§例举信息 ####<May 15, 2007 3:26:56 PM CST> <Debug> <RJVM> <zqyx-app-01> <weblogic_a2> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1179214016578> <BEA-000571> <Network Configuration Detail for Channel "weblogic_a2" Channel Weight 50 Accept Backlog 500 Login Timeout 5000ms Max Message Size 10000000 Message Timeout 60s Idle Timeout 65s Tunneling Timeout 40s Tunneling Ping 45s>

错误分析 这是个校验与网络相关配置的信息，上下文联系可见网络的监听、端口都正常，上文信 息为：Network Configuration for Channel "weblogic_a2" Listen Address 10.150.208.4:7020 Public Address N/A Http Enabled true Tunneling Enabled false Outbound Enabled false Admin Traffic Enabled true 参考资料： http://dev2dev.bea.com.cn/bbs/thread.jspa?forumID=81&threadID=41884 http://www.myeclipseide.com/PNphpBB2+file-printview-t-2769-start-0.html http://www.itpub.net/500557.html

3.3.Alert 类分析
3.2.1、代号：BEA-000396

§例举信息 ####<May 15, 2007 9:32:46 AM CST> <Alert> <WebLogicServer> <zqyx-app-01> <weblogic_a2> <[ACTIVE] ExecuteThread: '10' for queue: 'weblogic.kernel.Default (self-tuning)'> <weblogic> <> <> <1179192766562> <BEA-000396> <Server shutdown has been requested by weblogic> §发生次数 2 §BEA- 代码分析 BEA-000396 Alert: Server operation has been requested by requester0 Description The server is requested to operation. Cause The server is requested to perform the request operation. Action No action needed. 错误分析 这是由于服务器已经关闭了但客户端又向服务器发出请求而引发的。联系上下文 '10' for queue: 'weblogic.kernel.Default (self-tuning)'> <weblogic> <> <> <1179192766562> <BEA-002638> <Force shutdown was issued remotely from 10.150.208.4>是由于强制关掉了服 务器，应该是人工直接关的。

3.4.Waining 类分析
3.4.1、代号：BEA-170011

§例举信息 ####<May 15, 2007 10:12:19 AM CST> <Warning> <Log Management> <zqyx-app-01> <weblogic_a2> <[ACTIVE] ExecuteThread: '4' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1179195139765> <BEA-170011> <The LogBroadcaster on this server failed to broadcast log messages to the admin server. The Admin server may not be running. Message broadcasts to the admin server will be disabled.> §发生次数 1 §BEA- 代码分析 BEA-170011 Warning: The LogBroadcaster on this server failed to broadcast log messages to the admin server. The Admin server may not be running. Message broadcasts to the admin server will be disabled. Description The LogBroadCaster on the managed server could not find a reference to the DomainLogHandler on the admin server. Messages from this server will not be logged in the domain log. Cause The managed server might not be able to reach the admin server. One of the possible causes could be due to the admin server being shutdown. Action To fix this problem, inspect the exception stack trace, correct the problem. If the admin server is shutdown, restart it to resume normal log broadcasta to the domain. 错误分析 这是由于在配置服务器端的 broadcast ip 指向一个不存在的 IP 引发的， 目前系统没有用 到广播功能。 §1.5.4.2 3.4.2、代号：BEA-100089

§例举信息 BEA-100089> <The session id: CgGgGL3NgyBpGjq82ZLsLhyRVgJGHydnQ7ZZCwHpqnWfZ7hSMb0K has been accessed from -8305630332285958955S:10.150.208.4:YXDomain:weblogic_a2, a server that is neither the primary (8983270560839801745S:10.150.208.4:[7010,7010,-1,-1,-1,-1,-1]:YXDomain:weblogic_a1) nor the secondary (6245526094817342656S:10.150.208.5:[7040,7040,-1,-1,-1,-1,-1]:YXDomain:weblogic_b2). The request URL was: http://10.150.208.3:80/epm/component.do> §发生次数 1114 §BEA- 代码分析 BEA-100089

Warning: The session id: sessionID has been accessed from currentServer, a server that is neither the primary (primaryServer) nor the secondary (secondaryServer). The request URL was: requestUrl Description The session id: sessionID has been accessed from currentServer, a server that is neither the primary (primaryServer) nor the secondary (secondaryServer). Repeated occurrences of this can cause memory problems and performance degredation, as sessions are loaded into memory on more than two servers at a time. Cause The most likely cause is a configuration error on a front end hardware loadbalancer or webserver plugin. They should be configured to respect the values of primary/secondary in the cookie (i.e., stickyness), when possible. Action Please ensure that the front end webserver or load-balancer has been properly configured. 错误分析 由上下文 ####<May 15, 2007 10:13:42 AM CST> <Warning> <HTTP Session> <zqyx-app-01> <weblogic_a2> <[ACTIVE] ExecuteThread: '5' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <> <1179195222812> <BEA-100089> <The session id: CgGgGL3NgyBpGjq82ZLsLhyRVgJGHydnQ7ZZCwHpqnWfZ7hSMb0K has been accessed from -8305630332285958955S:10.150.208.4:YXDomain:weblogic_a2, a server that is neither the primary (8983270560839801745S:10.150.208.4:[7010,7010,-1,-1,-1,-1,-1]:YXDomain:weblogic_a1) nor the secondary (6245526094817342656S:10.150.208.5:[7040,7040,-1,-1,-1,-1,-1]:YXDomain:weblogic_b2). The request URL was: http://10.150.208.3:80/epm/component.do> 可以看出是由于第一次访问时连到的机器是 7010 端口， 而在取 session 时是取到 7040 端口。 即两台节点服务器的级别是同等的。若要解决这个问题，可指定 session 复制或服务器 FailOver 形式。

§1.6 4、BEA 代码段分析

§1.7 5、日志总体分析
从这个日志文件及文件中的消息可总结几个问题： 1、日志中报最多的就是警告：BEA-100089 有 1114 个 在每个警告时都象报与应用 http://10.150.208.3:80/epm/component.do 处理 session 有关。 经检查及跟踪这几天的日志来看（截止 2007-5-17 日志）a1、a2、b1、b2 均出现同样的 警告。 建议检查一下应用 epm/component.do。因为只有这个应用报警告。同时我们也将继续关 注和解决此警告。 2、错误日志报最多的是 BEA-101017(553 个)和 BEA-101083(227 个) 引起 BEA-101017 错误的 bea 解释为 http request timeout 值太小，目前为 120 秒。对于 此值的合理性，我将继续验证，据以往几个客户的值设置情况来看，一般都在 100 左右，当

然这与具体的应用有关。 引起 BEA-101083 错误是由于 request 数据传送时数据量过大。对于数据的传递一般建 议大批量的数据传送使用 POST 方法。可参阅 http://dev2dev.bea.com.cn/bbs/thread.jspa?forumID=81&threadID=16891 ３、从日志上看从<May 15, 2007 3:06:04 PM CST>到<May 15, 2007 3:26:49 PM CST>之间 无日志输出，这可能是死机后无日志输出。 从日志上看，在 3:06:04 前是正常的，3:26:49 后也是正常的。据现场观察的小王说控制 台状态是 Active。因此我觉得很有可能在此期间是由于暂停了 a2 的服务，因为如果是应用 产生 down 机将会至少有一个与之相关的异常抛出。产生暂停的主要操作是用鼠标点选了后 台日志输出屏。当然这种问题看频繁程度及需进一步跟踪确诊。 ４、从日志上看当做银行实时收费情况查询结果时有大量的日志。光日志输出的相关 SQL 信息都有 5813783byte.有 5000 行 (line 18082~23082) 请开发商确认做这种操作时作到 A、 多记录时是否采用分页分载。这样防止 socket httpRequest timeout B、 集合是批量取还是一个一个取。一条一条取将会加重服务器与 DB 的负荷。

--转自