HP_prstat使用.doc

hp_prstat的使用（WLS进程高CPU问题处理）付波涛1. 工具介绍Hp_prstat是BEA公司自己开发的工具，用来查找长时间占用CPU时间的java进程的一款实用的工具。1.1. 运行环境运行于HP UNIX平台。1.2. 具体应用它可以显示进程 ID (PID)、与 PID 关联的轻量型进程 ID (LWPID)、用户时间和所使用的系统时间。您可以使用该程序作为一个大致指南，因为在高 CPU 占用的情况中，LWPID 使用越来越多的 CPU，可以看到用户时间在很短的时间之内便增加了。可以使用 BEA 的 hp_prstat 实用程序，并定期测量每个 LWPID 的用户时间以了解哪一个正在随时间推移而增加。2. 使用方法首先将hp_prstat 工具上传到要处理的服务器，赋予可执行权限。在 Java 进程中运行hp_prstat命令，格式hp_prstat 。通过在 Java 进程中执行以下命令对服务器进行若干Thread Dump：Kill -3 。检查两次 hp_prstat迭代的输出结果以找到已经迅速增加用户时间的出现问题的 LWPID。 一旦您获得该号码 (LWPID)，请检查 Thread Dump，以查找您已经完成的 Thread Dump 中哪一项的 lwp_id=。这将匹配将要占用完 CPU 的有问题的线程。3. 举例说明在 Java 进程中运行 hp_prstat 命令。示例： hp_prstat 每隔几分钟执行一次上述操作，执行数次，同时观察发生高 CPU 占用率的情况。平台：Hp unix，版本：WLS8.1.4，WLS进程：号48353.1. 执行hp_prstat 4484每隔几分钟执行一次上述操作，执行数次，同时观察发生高 CPU 占用率的情况。下面是部分输出结果：第1次：$ hp_prstat 4484lwpid pid pri status UsrTime SysTime- - - - - -6161048 4484 154 1 14 06161056 4484 154 1 12 06161057 4484 154 1 12 06161084 4484 154 1 0 06161085 4484 204 2 11 126161086 4484 154 1 0 06161087 4484 154 1 0 06161088 4484 154 1 0 06161089 4484 154 1 0 06161090 4484 154 1 0 06161091 4484 154 1 0 06161092 4484 154 1 0 06161093 4484 154 1 2 06161094 4484 154 1 3 06161096 4484 154 1 0 06161097 4484 154 1 0 06161098 4484 154 1 0 06161101 4484 154 1 0 06161104 4484 154 1 0 06161109 4484 168 1 0 06161111 4484 154 1 0 06161112 4484 154 1 0 06161114 4484 154 1 0 06161115 4484 154 1 0 06161116 4484 154 1 0 06161117 4484 154 1 0 06161118 4484 154 1 0 06161128 4484 154 1 0 06161129 4484 154 1 0 06161130 4484 154 1 0 06161131 4484 154 1 0 06161132 4484 154 1 0 06161133 4484 154 1 0 06162004 4484 186 4 0 0第2次：$ hp_prstat 4484lwpid pid pri status UsrTime SysTime- - - - - -6161048 4484 154 1 14 06161049 4484 154 1 0 06161050 4484 154 1 2 06161056 4484 154 1 12 06161057 4484 154 1 12 06161058 4484 168 1 0 06161060 4484 154 1 0 06161084 4484 154 1 0 06161085 4484 210 2 13 156161086 4484 154 1 0 06161087 4484 154 1 0 06161088 4484 154 1 0 06161089 4484 154 1 0 06161090 4484 154 1 0 06161091 4484 154 1 0 06161092 4484 154 1 0 06161093 4484 154 1 2 06161094 4484 154 1 3 06161096 4484 154 1 0 06161097 4484 154 1 0 06161098 4484 154 1 0 06161101 4484 154 1 0 06161104 4484 154 1 0 06161109 4484 168 1 0 06161111 4484 154 1 0 06161112 4484 154 1 0 06161114 4484 154 1 0 06161115 4484 154 1 0 06161116 4484 154 1 0 06161117 4484 154 1 0 06161118 4484 154 1 0 06161128 4484 154 1 0 06161129 4484 154 1 0 06161130 4484 154 1 0 06161131 4484 154 1 0 06161132 4484 154 1 0 06161133 4484 154 1 0 06162004 4484 186 4 0 0第3次：$ hp_prstat 4484lwpid pid pri status UsrTime SysTime- - - - - -6161048 4484 154 1 14 06161049 4484 154 1 0 06161050 4484 154 1 2 06161051 4484 154 1 0 06161052 4484 154 1 0 06161053 4484 154 1 0 06161054 4484 154 1 0 06161055 4484 154 1 0 06161056 4484 154 1 12 06161057 4484 154 1 12 06161058 4484 168 1 0 06161060 4484 154 1 0 06161061 4484 154 1 0 06161062 4484 154 1 0 06161063 4484 154 1 0 06161064 4484 154 1 0 06161065 4484 154 1 0 06161066 4484 154 1 0 06161067 4484 154 1 0 06161068 4484 154 1 0 06161069 4484 154 1 0 06161081 4484 154 1 0 06161082 4484 154 1 0 06161083 4484 154 1 0 06161084 4484 154 1 0 06161085 4484 211 2 15 176161086 4484 154 1 0 06161087 4484 154 1 0 06161130 4484 154 1 0 06161131 4484 154 1 0 06161132 4484 154 1 0 06161133 4484 154 1 0 06162004 4484 186 4 0 03.2. 分析hp_prstat数据连续3次得出的结果可看出占用CPU时间比较长的lwpid如下：6161085，它的CPU占用时间是一直增加，lwpid pid pri status UsrTime SysTime6161085 4484 204 2 11 126161085 4484 210 2 13 156161085 4484 211 2 15 173.3. 做threaddump执行kill -3 4484 收集threaddump文件，一般做3次，从3次dump文件中查找lwpid 为6161085的thread 情况，得到：ExecuteThread: 24 for queue: weblogic.kernel.Default daemon prio=3 tid=00066d68 nid=37 lwp_id=6161085 runnable 5fb60000.5fb604f0at java.io.FileOutputStream.writeBytes(Native Method)at java.io.FileOutputStream.write(FileOutputStream.java:260)at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:66)at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:124)- locked (a java.io.BufferedOutputStream)at java.io.PrintStream.write(PrintStream.java:260)- locked (a java.io.PrintStream)at sun.nio.cs.StreamEncoder$CharsetSE.writeBytes(StreamEncoder.java:336)at sun.nio.cs.StreamEncoder$CharsetSE.implFlushBuffer(StreamEncoder.java:404)at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:115)- locked (a java.io.OutputStreamWriter)at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:169)at java.io.PrintStream.write(PrintStream.java:305)- locked (a java.io.PrintStream)at java.io.PrintStream.print(PrintStream.java:448)at java.io.PrintStream.println(PrintStream.java:585)- locked (a java.io.PrintStream)at jsp_servlet._index._jspService(_index.java:141)at weblogic.servlet.jsp.JspBase.service(JspBase.java:33)at ernal.ServletStubImpl$ServletInvocationAction.run(ServletStubImpl.java:1006)at ernal.ServletStubImpl.invokeServlet(ServletStubImpl.java:419)at ernal.ServletStubImpl.invokeServlet(ServletStubImpl.java:463)at ernal.ServletStubImpl.invokeServlet(ServletStubImpl.java:315)at ernal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:6718)at ernal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:121)at ernal.WebAppServletContext.invokeServlet(WebAppServletContext.java:3764)at ernal.ServletRequestImpl.execute(ServletRequestImpl.java:2644)at weblogic.kernel.ExecuteThread.execute(ExecuteThread.java:219)at weblogic.kernel.ExecuteThread.run(ExecuteThread.jav