You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by eurotrans-Verlag <ve...@t-online.de> on 2011/05/14 15:20:20 UTC

Canceling Download on IIS7 with ISAPI Redirector 1.2.31 causes 100% CPU usage

Hello everybody,

I stumbled upon a strange problem with the ISAPI Redirector 1.2.31 on
Windows Server 2008 SP2 (32 bit) with IIS 7.0. The problem is, that when a
Servlet is generating lots of data (e.g. 200 MB) and a user downloads it
over the Isapi Redirector/IIS7, and cancels the download, the IIS Worker
process (w3wp.exe) will have 100% CPU usage for about 30 seconds. However if
the download is completed normally (not canceled), everything is fine and
the CPU usage will not go up that far.

The exact Components used are:
Windows Server 2008 SP2 (32 bit) with IIS 7.0,
Sun JDK 1.6.0_25,
Tomcat 7.0.14,
ISAPI Redirector 1.2.31.

I could reproduce the problem with a clean install of these components.

To reproduce:
1. Install Tomcat and the ISAPI Redirector on a Windows Server 2008 SP2 IIS
7.0 system, as described in the Tomcat Connectors Documentation
(The problem occurs with both settings of "enable_chunked_encoding", "true"
and "false").

2. Create a Servlet or JSP that produces some huge amount of random data,
for example:

@WebServlet("/DownloadServlet")
public class DownloadServlet extends HttpServlet {
	protected void doGet(HttpServletRequest request, HttpServletResponse
response) throws ServletException, IOException {
    		response.setContentType("application/x-msdownload");
    		OutputStream out = response.getOutputStream();
    		Random r = new Random();
    		byte[] content = new byte[1024];
    		for (int i = 0; i < content.length; i++)
    			content[i] = (byte) (r.nextFloat() * 256);
    		for (int i = 0; i < 200000; i++)
    			out.write(content);
    		out.close();
	}
}

3. Request the Servlet or JSP through the IIS port with a browser. After
some seconds, cancel the download.

4. One thread of the IIS Worker Process (w3wp.exe) will have 100% CPU usage
for some time (about 30 seconds), before it normalizes to 0%.
Note that is does not happen every time. Sometimes you will have to repeat
starting and canceling the download until the problem occurs.

5. In the ISAPI log, following lines are logged ("log_level"="info"):
[Sat May 14 14:48:55.654 2011] [3508:3560] [error]
isapi_write_client::jk_isapi_plugin.c (1210): WriteClient failed with 995
(0x000003e3)
[Sat May 14 14:48:55.654 2011] [3508:3560] [info]
ajp_process_callback::jk_ajp_common.c (1885): Writing to client aborted or
client network problems
[Sat May 14 14:48:55.654 2011] [3508:3560] [info]
ajp_service::jk_ajp_common.c (2543): (worker1) sending request to tomcat
failed (unrecoverable), because of client write error (attempt=1)
[Sat May 14 14:48:55.669 2011] [3508:3560] [info]
HttpExtensionProc::jk_isapi_plugin.c (2217): service() failed because client
aborted connection

These lines are logged immediately after the client cancels the connection
(not after the CPU usage of w3wp.exe goes down).

The worker process continues normally after the CPU usage went down.

However, if one would do this repeatedly, it could enable DoS attacks,
couldn't it?
What would cause these excessive CPU usages of the IIS worker process when
the user cancels the download?


Thanks for your help.

Konstantin Preißer


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Canceling Download on IIS7 with ISAPI Redirector 1.2.31 causes 100% CPU usage

Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

André,

On 5/14/2011 4:01 PM, André Warnier wrote:
> eurotrans-Verlag wrote:
>> However I would expect write() to always throw an IOException when the
>> connection to the client is aborted, 
> 
> Remember, there are 2 separate connections : the connection of the
> client to IIS+isapi_redirector, and the connection from
> IIS+isapi_redirector to Tomcat+servlet.
> The servlet will only throw an I/O exception if that second connection
> is closed.

+1

If the ISAPI redirector works anything like mod_jk, then the connection
is expected to be persistent. That means the redirector might end up
reading a lot of data and throwing it into the bit bucket.

If ISAPI redirector connections are /not/ intended to be persistent,
then the redirector should be terminating the connection with Tomcat as
soon as possible. You should only have to wait for a buffer to fill-up
before an error is detected, which shouldn't be long at all.

If reading and discarding the data sends the CPU high, there might be a
bug in there... maybe a buffer that is too small or a loop that either
doesn't do enough work in it's body (a "tight" loop) or is doing too
much useless work (like re-calculating a value that might be constant
during the loop).

> I have no idea.  We need Mladen or Rainer here..

I think so. I've looked at the mod_jk code before for certain things and
while it's fairly straightforward, it is certainly extensive.

- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAk3RUuIACgkQ9CaO5/Lv0PBPJQCgqcGo1rvFpjCOjzcMx17GS2cm
C2YAn0BETp2I6HK7fJrLLx0BBvMdvFwg
=vUDE
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Canceling Download on IIS7 with ISAPI Redirector 1.2.31 causes 100% CPU usage

Posted by André Warnier <aw...@ice-sa.com>.
eurotrans-Verlag wrote:
> Hi André, thanks for your reply.
> 
>> To figure out if this is what's happening, you could do some logging at
>> the servlet end,
>> to see if it keeps sending data even when the client has canceled, or
>> if it itself gets
>> some stop indication from the isapi_redirector (also a closed socket
>> e.g.).
>>
>> Or else Mladen or Rainer could tell us if I'm totally off-base here.
> 
> 
> I added some logging to the Servlet to see what it is actually doing
> (logging the start and end of the doGet() method and every time 2 MB are
> written, and I also put the write loop in a try-catch clause to catch
> IOException).
> 
> You are right: When I start the download, the servlet writes the bytes
> slowly (due to the speed of the Connection) to the output. However, when I
> then cancel the download, it writes the remaining bytes very fast, probably
> causing the high CPU usage of the ISAPI redirector.
> 
> But in some cases, the result is another: After I canceled the download, the
> write() method throws an IOException:
> ClientAbortException:  java.io.IOException: Failed to send AJP message
> 
> and the remaining bytes are not written, so the CPU usage does not go up to
> 100% (That's probably the other case I mentioned before, that sometimes the
> CPU usage doesn't go up).
> 
> However I would expect write() to always throw an IOException when the
> connection to the client is aborted, 

Remember, there are 2 separate connections : the connection of the client to 
IIS+isapi_redirector, and the connection from IIS+isapi_redirector to Tomcat+servlet.
The servlet will only throw an I/O exception if that second connection is closed.

So it all depends on whether the isapi_redirector closes the connection to Tomcat also, 
when the client has closed its connection to IIS.

but it seems that in most cases, the
> IOException is not thrown, thus causing the servlet to write the remaining
> bytes very fast to the ISAPI redirector and probably causing the high CPU
> load.
> Do you or anybody have an idea why sometimes the IOException is not thrown
> when the Client aborts the Connection?
> 
I have no idea.  We need Mladen or Rainer here..

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: Canceling Download on IIS7 with ISAPI Redirector 1.2.31 causes 100% CPU usage

Posted by eurotrans-Verlag <ve...@t-online.de>.
Hi André, thanks for your reply.

> To figure out if this is what's happening, you could do some logging at
> the servlet end,
> to see if it keeps sending data even when the client has canceled, or
> if it itself gets
> some stop indication from the isapi_redirector (also a closed socket
> e.g.).
> 
> Or else Mladen or Rainer could tell us if I'm totally off-base here.


I added some logging to the Servlet to see what it is actually doing
(logging the start and end of the doGet() method and every time 2 MB are
written, and I also put the write loop in a try-catch clause to catch
IOException).

You are right: When I start the download, the servlet writes the bytes
slowly (due to the speed of the Connection) to the output. However, when I
then cancel the download, it writes the remaining bytes very fast, probably
causing the high CPU usage of the ISAPI redirector.

But in some cases, the result is another: After I canceled the download, the
write() method throws an IOException:
ClientAbortException:  java.io.IOException: Failed to send AJP message

and the remaining bytes are not written, so the CPU usage does not go up to
100% (That's probably the other case I mentioned before, that sometimes the
CPU usage doesn't go up).

However I would expect write() to always throw an IOException when the
connection to the client is aborted, but it seems that in most cases, the
IOException is not thrown, thus causing the servlet to write the remaining
bytes very fast to the ISAPI redirector and probably causing the high CPU
load.
Do you or anybody have an idea why sometimes the IOException is not thrown
when the Client aborts the Connection?


Cheers
Konstantin Preißer


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Canceling Download on IIS7 with ISAPI Redirector 1.2.31 causes 100% CPU usage

Posted by André Warnier <aw...@ice-sa.com>.
eurotrans-Verlag wrote:
> Hello everybody,
> 
> I stumbled upon a strange problem with the ISAPI Redirector 1.2.31 on
> Windows Server 2008 SP2 (32 bit) with IIS 7.0. The problem is, that when a
> Servlet is generating lots of data (e.g. 200 MB) and a user downloads it
> over the Isapi Redirector/IIS7, and cancels the download, the IIS Worker
> process (w3wp.exe) will have 100% CPU usage for about 30 seconds. However if
> the download is completed normally (not canceled), everything is fine and
> the CPU usage will not go up that far.
> 
> The exact Components used are:
> Windows Server 2008 SP2 (32 bit) with IIS 7.0,
> Sun JDK 1.6.0_25,
> Tomcat 7.0.14,
> ISAPI Redirector 1.2.31.
> 
> I could reproduce the problem with a clean install of these components.
> 
> To reproduce:
> 1. Install Tomcat and the ISAPI Redirector on a Windows Server 2008 SP2 IIS
> 7.0 system, as described in the Tomcat Connectors Documentation
> (The problem occurs with both settings of "enable_chunked_encoding", "true"
> and "false").
> 
> 2. Create a Servlet or JSP that produces some huge amount of random data,
> for example:
> 
> @WebServlet("/DownloadServlet")
> public class DownloadServlet extends HttpServlet {
> 	protected void doGet(HttpServletRequest request, HttpServletResponse
> response) throws ServletException, IOException {
>     		response.setContentType("application/x-msdownload");
>     		OutputStream out = response.getOutputStream();
>     		Random r = new Random();
>     		byte[] content = new byte[1024];
>     		for (int i = 0; i < content.length; i++)
>     			content[i] = (byte) (r.nextFloat() * 256);
>     		for (int i = 0; i < 200000; i++)
>     			out.write(content);
>     		out.close();
> 	}
> }
> 
> 3. Request the Servlet or JSP through the IIS port with a browser. After
> some seconds, cancel the download.
> 
> 4. One thread of the IIS Worker Process (w3wp.exe) will have 100% CPU usage
> for some time (about 30 seconds), before it normalizes to 0%.
> Note that is does not happen every time. Sometimes you will have to repeat
> starting and canceling the download until the problem occurs.
> 
> 5. In the ISAPI log, following lines are logged ("log_level"="info"):
> [Sat May 14 14:48:55.654 2011] [3508:3560] [error]
> isapi_write_client::jk_isapi_plugin.c (1210): WriteClient failed with 995
> (0x000003e3)
> [Sat May 14 14:48:55.654 2011] [3508:3560] [info]
> ajp_process_callback::jk_ajp_common.c (1885): Writing to client aborted or
> client network problems
> [Sat May 14 14:48:55.654 2011] [3508:3560] [info]
> ajp_service::jk_ajp_common.c (2543): (worker1) sending request to tomcat
> failed (unrecoverable), because of client write error (attempt=1)
> [Sat May 14 14:48:55.669 2011] [3508:3560] [info]
> HttpExtensionProc::jk_isapi_plugin.c (2217): service() failed because client
> aborted connection
> 
> These lines are logged immediately after the client cancels the connection
> (not after the CPU usage of w3wp.exe goes down).
> 
> The worker process continues normally after the CPU usage went down.
> 
> However, if one would do this repeatedly, it could enable DoS attacks,
> couldn't it?
> What would cause these excessive CPU usages of the IIS worker process when
> the user cancels the download?
> 
> 
A guess :
IIS and the isapi_redirector are one process, and Tomcat and the servlet are another 
process.  The isapi_redirector makes a connection to Tomcat, sends the request over it.
The servlet starts running and producing output, quite a lot and quite fast, over that 
connection.
The isapi_redirector reads the servlet output, and writes it to the client connection.
Now the client closes the connection, and isapi_redirector finds a closed socket the next 
time it tries to write to the client.  It writes this error to the logfile, and stops 
trying to send output to the client (well, it cannot anymore, the socket is closed).
But in the meantime the servlet keeps producing output and sending it to isapi_redirector.
So either isapi_redirector has a way to stop the servlet and discarding any servlet output 
still pending, or else it is forced to read and discard whatever the servlet is still 
sending, until the servlet decides to stop by itself.
Maybe the 100% CPU usage is happening while isapi_redirector is reading and discarding 
whatever remains of the servlet output ?  Since there is no client connection anymore to 
slow things down, this is bound to be rather fast and cpu-intensive.

To figure out if this is what's happening, you could do some logging at the servlet end, 
to see if it keeps sending data even when the client has canceled, or if it itself gets 
some stop indication from the isapi_redirector (also a closed socket e.g.).

Or else Mladen or Rainer could tell us if I'm totally off-base here.



---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org