troubleshoot.xtp

RESIN 3.2 最新源码

exception, or seems to be spending an excessive amount of time doing garbage
collection, a heap dump can help track down the source of the problem.</p>

<p>What you really need to do is get a good CPU and heap profile.
The JDK has a simple one (but not very 
user-friendly), so you don't absolutely need to buy a profiler.</p>

<p>An alternative for simple heap monitoring (garbage collection issues), are
the <a href="http://developer.sun.com/dev/coolstuff/jvmstat">jvmstat tools</a>.</p>

<p>It's a standard java argument, so "java -Xrunhprof:help" will tell you how to start it.  For example, you could 
start Resin (unix or windows) as</p>

<example>
&gt; resin.sh -J-Xrunhprof:heap=sites,cpu=samples
</example>

<p>(On Unix, Resin's startup script has a -cpuprof-ascii argument that sets it for you automatically.)</p>

<p>Run a load against it for a decent amount of time (you can even use something like Apache's "ab" for 10 
minutes), and then stop the server nicely.  i.e. you can't just kill it with ctrl-C, but you need to make it do a 
clean exit.</p>

<p>That will dump a java.hprof.txt.  Skip to the bottom to get the trace.</p>
</s3>

<s3 title="Understanding java.hprof.txt heap">

<p>Assuming you're being cheap, and using the JDK's heap profiling instead of
buying a profiler, you'll need a bit of help interpreting it.</p>

<p>The following is an example of a heap dump running Resin.  Here's what you
might see skipping down to the "SITES BEGIN" section.  (I did mention this is
the cheap way of doing things.)  As with most profiling, you only want
to pay attention to the top 20.  Everything else is in the noise.  Ignore it.
</p>

<example>
SITES BEGIN (ordered by live bytes) Tue Jan  9 17:44:33 2001
          percent         live       alloc'ed  stack class
 rank   self  accum    bytes objs   bytes objs trace name
    1 11.87% 11.87%   983520  120 1393320  170  2553 [B
    2  9.89% 21.76%   819600  100 1286772  157  4070 [B
    3  9.09% 30.85%   753756   23 3539376  108  4970 [L&lt;Unknown&gt;;
    4  5.83% 36.68%   483564   59  778620   95  7180 [B
    5  5.74% 42.42%   475368   58  745836   91  7178 [B
    6  4.35% 46.77%   360624   44  696660   85  7182 [B
    7  2.97% 49.74%   245880   30  450780   55  7176 [B
    8  2.37% 52.11%   196704   24  352428   43  7254 [B
    9  1.88% 53.99%   155724   19  262272   32  7174 [B
   10  1.78% 55.77%   147528   18  245880   30  7137 [B
   11  1.53% 57.30%   126988 1063 16973092 129113  3271 [C
   12  1.34% 58.64%   110684 3953 20362832 727244  1213 sun/io/CharToByteISO8859_1
   13  1.25% 59.88%   103320  738  141820 1013  5942 java/lang/Class
   14  1.21% 61.10%   100548   49  221616  108  5003 [L&lt;Unknown&gt;;
   15  1.21% 62.31%   100548   49  221616  108  5005 [L&lt;Unknown&gt;;
   16  1.07% 63.38%    89080 1532 18393580 317347  1340 [B
   17  0.79% 64.18%    65568    8   81960   10  8408 [B
   18  0.79% 64.97%    65552    4   65552    4 27630 [C
   19  0.70% 65.67%    58232   24 1110128  386  5038 [C
   20  0.68% 66.35%    56200  450  116816  980  7186 [C
</example>

<p>There are two things to look for.  First, if any one class starts
chewing up a large number in the "live objs" column, you'll need to
take a look.  That might be a memory leak.</p>

<p>Second, if some class has a huge number in the "alloc'ed objs" column,
you may be wasting lots of garbage collection time that could be easily
solved with some caching.</p>

<p>The [C in the class name means a character array.
To see what that really means, you'll need to look at the stack
trace (3271):</p>

<example>
TRACE 3271:
	java/lang/String.&lt;init&gt;(String.java:244)
	com/caucho/util/CharBuffer.close(CharBuffer.java:714)
	com/caucho/vfs/FilesystemPath.normalizePath(FilesystemPath.java:162)
	com/caucho/vfs/FilesystemPath.schemeWalk(FilesystemPath.java:127)
</example>

<p>That's part of Resin's VFS code.  Maybe in the future it'll make sense
to try to reduce that.

</p><p>You can get a longer trace using the "-prof-depth 10" argument to Resin.
(Or the corresponding depth in -Xrunhprof.)  That will often give more
information.</p>

</s3>

<s3 title="Understanding java.hprof.txt CPU">

<p>The CPU profiling is a little easier to read.  On some JDK's you'll need to
run it with the JIT disabled.</p>

<example>
CPU SAMPLES BEGIN (total = 424614) Tue Jan  9 17:44:33 2001
rank   self  accum   count trace method
   1 21.36% 21.36%   90704  7266 com/caucho/server/http/VirtualHost.logAccess
   2 10.84% 32.20%   46041  7269 java/net/SocketInputStream.socketRead
   3  5.99% 38.19%   25428  1213 java/lang/Class.newInstance0
   4  5.11% 43.31%   21715  7896 com/caucho/util/CharBuffer.toString
   5  4.82% 48.13%   20463  1286 sun/io/CharToByteISO8859_1.convert
   6  3.54% 51.66%   15018  1242 sun/io/CharToByteConverter.&lt;init&gt;
   7  2.68% 54.35%   11388  7241 java/io/PrintWriter.&lt;init&gt;
   8  2.47% 56.82%   10508  7748 com/caucho/server/http/Request.fillCookies
   9  2.27% 59.09%    9650  1214 sun/io/ByteToCharConverter.&lt;init&gt;
  10  1.85% 60.94%    7857  5097 java/lang/String.&lt;init&gt;
  11  1.59% 62.53%    6754  1341 java/lang/String.substring
  12  1.57% 64.10%    6650  1340 java/lang/String.getBytes
  13  0.92% 65.02%    3907  7897 java/lang/String.&lt;init&gt;
  14  0.76% 65.78%    3227  3259 com/caucho/vfs/FilePath.fsWalk
  15  0.75% 66.53%    3195  7895 com/caucho/server/http/Request.fillCookie
  16  0.71% 67.25%    3031  7321 java/lang/String.getBytes
  17  0.71% 67.95%    2996  3270 com/caucho/util/CharBuffer.close
  18  0.68% 68.63%    2892  3271 java/lang/String.&lt;init&gt;
  19  0.66% 69.29%    2782  7318 com/caucho/vfs/FilePath.openWriteImpl
  20  0.61% 69.90%    2604  7320 java/io/FileOutputStream.&lt;init&gt;
</example>

<p>You should only pay attention to the top 20 or so.  You'll
probably need to ignore a few of the top 10, because they're just waiting
for a user response.  The SocketInputStream.socketRead is an example.

</p><p>You can use the trace number to get a call trace:</p>

<example>
TRACE 7266:
	com/caucho/server/http/VirtualHost.logAccess(VirtualHost.java:487)
	com/caucho/server/http/Application.logAccess(Application.java:1846)
	com/caucho/server/http/Response.finish(Response.java:1345)
	com/caucho/server/http/Request.finish(Request.java:416)
</example>
</s3>

<s3 name="garbage-collection" title="Monitor garbage collection">

<p>(thanks to Rob Lockstone for his comments)</p> 

<p>
Run Resin with the additional argument <var>-Xloggc:gc.log</var> where
"gc.log" is the name of the log file which will be created in the root Resin
directory, e.g. <code>/resin/gc.log</code>.
</p>


<p>Once the server has run under load for a while, or when problems start
appearing, look in the gc.log file and search for "Full". They will happen
fairly infrequently at first, and then towards the end of the file, they will
become progressively more frequent until they are happening almost continuously
(with little or no change in the size of the heap). Note that the "timestamp"
in the first column is the number of seconds since the process started. </p>

<p>Garbage collection logging will have a small imapct on performance but is
invaluable in diagnosing garbe collection related problems.</p>

<p>Possible reasons for excessive garbage collection are 
<a href="#memory-leaks">memory leaks</a> and 
<a href="#increase-memory">inadequate heap memory</a> 
</p>

</s3> <!-- garbage-collection -->

<s3 name="increase-memory" title="Increase heap memory">

<p>See <a href="jvm-tuning.xtp#memory">Performance : JVM Tuning : Memory</a>.</p>
</s3> <!-- increase-memory -->

</s2>

<s2 name="classpath" title="Clean up the classpath">

<p>Conflicts often arise with older or incompatible versions of classes.</p>

<p>Starting Resin with an empty CLASSPATH environmental variable is a first
step to eliminating these classes.</p>

<example title="Starting Resin with an empty CLASSPATH">
win&gt; set CLASSPATH=
win&gt; bin/resin.exe

unix.sh&gt; export CLASSPATH=""
unix.sh&gt; bin/resin.sh
</example>

<p>If you have manually placed any jars in $RESIN_HOME/lib or you
jdk directories, those are possible conflicts as well.</p>

<p>If a new version of Resin s installed overtop of an older
version of Resin (i.e. in the same directory), some old jars
might be left.  It is best to give each version it's own directory.</p>

<p>If the RESIN_HOME environment variable is not set, Resin may be
picking up an older version.</p>

<p>You can start resin.sh/resin.exe with the -verbose option to see the
CLASSPATH that is being used when Resin is started.</p>

</s2> <!-- classpath  -->

<s2 name="tcpmon" title="Monitor the HTTP communication">

<p>To monitor just the HTTP headers, the following debug logging can be
enabled in $RESIN_HOME/resin.xml:</p>

<example title="debug logging for HTTP headers">
&lt;resin xmlns="http://caucho.com/ns/resin"&gt;

  ...

  &lt;log-handler name='com.caucho.server.http' level='finer'
                  path='log/http.log'/&gt;
  &lt;log-handler name='com.caucho.server.connection' level='finer'
                  path='log/http.log'/&gt;

  ...

&lt;/resin&gt;
</example>

<p>Intercepting and monitoring the raw data passed between a web browser and
Resin can provide valuable insight.  This raw data reveals the headers and
content that are submitted by the browser, and the headers and content that are
returned by Resin.</p>

<p>The <a href="http://ws.apache.org/axis">Apache Axis</a> jar includes a utility
"tcpmon" that can be used to intercept and monitor the  communication between a
browser and Resin.  Using tcpmon, you specify a "listen port" and a "target
host" and a "target port".  For example, if you usually have Resin running on
port 8080, you can start tcpmon with a "listen port" os 9090, and a target host
of localhost and a target port of 8080.  Now you will use a url
<code>http://localhost:9090</code> in your browser.  This causes your browser
to use tcpmon.  tcpmon will log the request, pass it through to Resin (on port
8080), and log the response before returning it to the browser.</p>

</s2>

<s2 name="external-compiler" title="Use an external compiler">

<p>Resin's default is to use the `internal' compiler because it is the most
likely to be available.  Sometimes the internal compiler will start to cause
errors, causing exceptions or simply hanging and taking up a thread.  The
solution is to change the compiler to `javac' in resin.xml:</p>

<example title="Using the external javac java compiler">
  &lt;javac compiler="javac" args=""/&gt;
</example>

<p>Jikes is another option for the compiler, as discussed in the documentation
for <a config-tag="javac"/>.</p>
</s2> <!-- external-compiler -->

<s2 name="os-thread" title="Increase stack size to avoid thread limitations">

<p>Each thread is allocated a stack, if the size of the stack is too large,
then you may run out of memory when a higher number of threads is reached.
Techniques to adress this are discussed in <a href="jvm-tuning.xtp#stack-size">JVM Tuning</a>.

</p></s2> <!-- os-thread -->

<s2 name="netstat" title="Use netstat to obtain an OS level view of current TCP/IP port usage">

<p>
The <code>netstat</code> utility is useful for obtaining information from the
operating system about the current state of network usage.
</p>

<example>
unix$ netstat -anp
win&gt; netstat -an
</example>

<p>
The -a indicates that both listening (waiting for a connection) and
non-listening (active) sockets should be displayed.  The -n causes the 
display of port numbers (i.e. 80) instead of port names (i.e. http).  The -p
causes the display of the process that is using the socket.  Since the windows
<code>netstat</code> is different than the Unix one, -p is not used on Windows.
</p>

<s3 title="Connection state">

<p>
The connection state is probably the most important information.  The man page
for netstat has a full description of each state that is displayed.
</p>

<p>
"LISTEN" or "LISTENING" is an indication that there is a process waiting for
connections on the socket.
</p>

<p>
</p>

<p>
"TIME_WAIT"  indicates that the socket is waiting after close to handle packets
still in the network.  After a connection is closed, the socket is kept open by
the operating system for a short period of time.  Even after the close is done,
there may be some stray packets on the network that are destined for the
connection.  The idea of TIME_WAIT is that it keeps the socket open long enough
to catch those stray packets, so that they don't get erronously delivered to a
new connection opened on the same socket.
</p>
</s3>


<s3 title="Port usage">
<p>
If Resin is indicating that it cannot bind to a port, it may be an
indication that another process is using the port.  <code>netstat</code> may
help determine the process that is using the port.
</p>

<p>Since netstat produces a lot of information, it is helpful to filter the
output to limit it to the port of interest.  The following example is for port
80:
</p>

<example title="netstat -anp">
unix$ netstat -anp | grep ":80" | less
</example>

</s3>

</s2> <!-- netstat -->

</s1>

<s1 title="Common Problems">

<s2 title="Specification version 1.3 of package javax.servlet, J2EE Specification, version 1.3 is not compatible with Resin Resin-3.0.x. Resin-3.0.x requires version 2.4." type="faq">
<description>
</description>

<p>This error occurs when you have an old or conflicting jar containing the
servlet api in your CLASSPATH.  The solution is to <a href="#classpath">clean up your classpath</a>.</p>

</s2>

<s2 title="class file has wrong version 48.0, should be 47.0" type="faq">
<description>
</description>

<p>
This error occurs when you have an old or conflicting jar 
in your CLASSPATH.  The solution is to 
<a href="#classpath">clean up your classpath</a>.
</p>

<p>
If it is a Resin jar that is causing the error, you may have jars from a
previous installation that are causing the error.  This occasionally occurs
when people try to copy a new installation over an old one, and due to write
permissions etc. some of the older jars are not replaced.
</p>

<p>
If the cleaning of the CLASSPATH (above) does not work, you may need to
completely remove Resin from
your system and re-install. 
</p>

</s2>
</s1>


</body>
</document>