You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Leif Mortenson <le...@tanukisoftware.com> on 2004/06/21 12:05:06 UTC

Problem with Tomcat 4.1.30, IIS, isapi_redirect.dll and POSTs

I have been using version 4.1.18 along with the newest isapi_redirect.dll at
the time it was installed for the past year or. Recently to resolve an
unrelated problem we upgraded to Tomcat 4.1.30 and isapi_redirect.dll 1.2.5
and have been testing things out on our test servers.

This was working for me for a day or two. Just before I went to deploy this
onto our live servers, I decided to do one last test. For some reason,
all of
the pages which are requested using a POST, hang for a couple minutes
before returning an error.

Reviewing the log from Tomcat, I found the following message:

Jun 21, 2004 6:42:33 PM org.apache.jk.common.HandlerRequest invoke
SEVERE: Error decoding request
java.io.IOException
at org.apache.jk.common.JkInputStream.receive(JkInputStream.java:294)
at
org.apache.jk.common.HandlerRequest.decodeRequest(HandlerRequest.java:537)
at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:373)
at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:673)
at
org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:615)
at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:786)
at
org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
at java.lang.Thread.run(Thread.java:536)
12 34 01 c1 02 04 00 08 48 54 54 50 2f 31 2e 31 | .4.?....HTTP/1.1
00 00 18 2f 6b 61 6e 73 68 69 2f 6a 5f 73 65 63 | .../kanshi/j_sec
75 72 69 74 79 5f 63 68 65 63 6b 00 00 0c 31 39 | urity_check...19
32 2e 31 36 38 2e 31 2e 33 31 00 00 0c 31 39 32 | 2.168.1.31...192
2e 31 36 38 2e 31 2e 33 31 00 00 07 6f 72 6c 61 | .168.1.31...orla
6e 64 6f 00 00 50 00 00 0b a0 01 00 57 69 6d 61 | ndo..P...?..Wima
67 65 2f 67 69 66 2c 20 69 6d 61 67 65 2f 78 2d | ge/gif, image/x-
78 62 69 74 6d 61 70 2c 20 69 6d 61 67 65 2f 6a | xbitmap, image/j
70 65 67 2c 20 69 6d 61 67 65 2f 70 6a 70 65 67 | peg, image/pjpeg
2c 20 61 70 70 6c 69 63 61 74 69 6f 6e 2f 78 2d | , application/x-
73 68 6f 63 6b 77 61 76 65 2d 66 6c 61 73 68 2c | shockwave-flash,
20 2a 2f 2a 00 a0 04 00 02 6a 61 00 a0 06 00 0a | */*.?...ja.?...
4b 65 65 70 2d 41 6c 69 76 65 00 a0 0b 00 07 6f | Keep-Alive.?...o
72 6c 61 6e 64 6f 00 a0 0d 00 1f 68 74 74 70 3a | rlando.?...http:
2f 2f 6f 72 6c 61 6e 64 6f 2f 6b 61 6e 73 68 69 | //orlando/kanshi
2f 6c 6f 67 69 6e 2e 6a 73 70 00 a0 0e 00 32 4d | /login.jsp.?..2M
6f 7a 69 6c 6c 61 2f 34 2e 30 20 28 63 6f 6d 70 | ozilla/4.0 (comp
61 74 69 62 6c 65 3b 20 4d 53 49 45 20 36 2e 30 | atible; MSIE 6.0
3b 20 57 69 6e 64 6f 77 73 20 4e 54 20 35 2e 31 | ; Windows NT 5.1
29 00 a0 09 00 2b 4a 53 45 53 53 49 4f 4e 49 44 | ).?..+JSESSIONID
3d 37 34 39 44 46 39 34 32 42 35 45 38 32 39 33 | =749DF942B5E8293
45 39 32 31 32 34 34 36 32 35 36 37 38 41 34 46 | E921244625678A4F
42 00 a0 08 00 02 33 37 00 a0 07 00 21 61 70 70 | B.?...37.?..!app
6c 69 63 61 74 69 6f 6e 2f 78 2d 77 77 77 2d 66 | lication/x-www-f
6f 72 6d 2d 75 72 6c 65 6e 63 6f 64 65 64 00 a0 | orm-urlencoded.?
03 00 0d 67 7a 69 70 2c 20 64 65 66 6c 61 74 65 | ...gzip, deflate
00 00 0d 63 61 63 68 65 2d 63 6f 6e 74 72 6f 6c | ...cache-control
00 00 08 6e 6f 2d 63 61 63 68 65 00 03 00 00 00 | ...no-cache.....
04 00 00 00 ff | ....?
Jun 21, 2004 6:42:33 PM org.apache.jk.common.ChannelSocket processConnection
WARNING: processCallbacks status 2

Doing additional tests, I have found that it appears to be timeout
waiting for
more data to be sent? (guess) I say this because if I do the POST and then
wait patiently then the error takes about 50 seconds to show up in the log.
The request will cause 2 such dumps before returning an error to the
browser. However if I push the submit button on my form then the
previous request will immediately cause the above error to be dumped.
The second request will continue to hang until it too times out and dumps
the above message.

I enabled debug output in the connector and get the following. It seems to
fail once and then retry. I am including the significant portion of the
second
attempt:

[Mon Jun 21 19:14:44 2004] [jk_ajp_common.c (295)]: Into
ajp_marshal_into_msgb
[Mon Jun 21 19:14:44 2004] [jk_ajp_common.c (463)]:
ajp_marshal_into_msgb - Done
[Mon Jun 21 19:14:44 2004] [jk_connect.c (158)]: Into jk_open_socket
[Mon Jun 21 19:14:44 2004] [jk_connect.c (165)]: jk_open_socket, try to
connect socket = 424
[Mon Jun 21 19:14:44 2004] [jk_connect.c (174)]: jk_open_socket, after
connect ret = 0
[Mon Jun 21 19:14:44 2004] [jk_connect.c (183)]: jk_open_socket, set
TCP_NODELAY to on
[Mon Jun 21 19:14:44 2004] [jk_connect.c (192)]: jk_open_socket, set
SO_KEEPALIVE to on
[Mon Jun 21 19:14:44 2004] [jk_connect.c (200)]: jk_open_socket, return,
sd = 424
[Mon Jun 21 19:14:44 2004] [jk_ajp_common.c (661)]: In
jk_endpoint_t::ajp_connect_to_endpoint, connected sd = 424
[Mon Jun 21 19:14:44 2004] [jk_ajp_common.c (693)]: sending to ajp13 #453
[Mon Jun 21 19:14:44 2004] [jk_ajp_common.c (966)]: ajp_send_request 2:
request body to send 37 - request body to resend 0
[Mon Jun 21 19:14:44 2004] [jk_isapi_plugin.c (514)]: Into
jk_ws_service_t::read
[Mon Jun 21 19:15:44 2004] [jk_isapi_plugin.c (548)]:
jk_ws_service_t::read, ReadClient failed
[Mon Jun 21 19:15:44 2004] [jk_ajp_common.c (882)]: ERROR: receiving
data from client failed. Connection aborted or network problems
[Mon Jun 21 19:15:44 2004] [jk_ajp_common.c (1303)]: ERROR: Client
connection aborted or network problems
[Mon Jun 21 19:15:44 2004] [jk_isapi_plugin.c (925)]: HttpExtensionProc
service() returned OK
[Mon Jun 21 19:15:44 2004] [jk_ajp_common.c (1529)]: Into
jk_endpoint_t::done, closing connection 0
[Mon Jun 21 19:15:44 2004] [jk_ajp_common.c (605)]: In
jk_endpoint_t::ajp_close_endpoint

My question is: Do you have any idea what could be causing this. The
really peculiar thing is that even if I go back to using my old Tomcat
4.1.18
deployment. This particular IIS server is now completely unable to do
POSTs. I had not made any changes on the IIS server between the time
that it was working and when it stopped. So I am wondering if I had just
been lucky that things had been working before.

Needless to say I am not thinking it is a good idea to try this out on the
live servers as I have not been able to figure out a way to return the old
state should it fail there as well.

Thanks in advance for any advice you may have.
Cheers,
Leif

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


Re: Problem with Tomcat 4.1.30, IIS, isapi_redirect.dll and POSTs

Posted by Leif Mortenson <le...@tanukisoftware.com>.
For the archives. I got no replies to this. But I was able to correct this
problem by switching over to using jk2 rather than jk. That means using
isapi_redirector2.dll rather than isapi_redirect.dll.

This was not at all clear from the online docs. Everything points to using
isapi_redirect.dll for connecting via IIS.

Cheers,
Leif

Leif Mortenson wrote:

>I have been using version 4.1.18 along with the newest isapi_redirect.dll at
>the time it was installed for the past year or. Recently to resolve an
>unrelated problem we upgraded to Tomcat 4.1.30 and isapi_redirect.dll 1.2.5
>and have been testing things out on our test servers.
>
>This was working for me for a day or two. Just before I went to deploy this
>onto our live servers, I decided to do one last test. For some reason,
>all of
>the pages which are requested using a POST, hang for a couple minutes
>before returning an error.
>
>Reviewing the log from Tomcat, I found the following message:
>
>Jun 21, 2004 6:42:33 PM org.apache.jk.common.HandlerRequest invoke
>SEVERE: Error decoding request
>java.io.IOException
>at org.apache.jk.common.JkInputStream.receive(JkInputStream.java:294)
>at
>org.apache.jk.common.HandlerRequest.decodeRequest(HandlerRequest.java:537)
>at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:373)
>at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:673)
>at
>org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:615)
>at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:786)
>at
>org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
>at java.lang.Thread.run(Thread.java:536)
>12 34 01 c1 02 04 00 08 48 54 54 50 2f 31 2e 31 | .4.?....HTTP/1.1
>00 00 18 2f 6b 61 6e 73 68 69 2f 6a 5f 73 65 63 | .../kanshi/j_sec
>75 72 69 74 79 5f 63 68 65 63 6b 00 00 0c 31 39 | urity_check...19
>32 2e 31 36 38 2e 31 2e 33 31 00 00 0c 31 39 32 | 2.168.1.31...192
>2e 31 36 38 2e 31 2e 33 31 00 00 07 6f 72 6c 61 | .168.1.31...orla
>6e 64 6f 00 00 50 00 00 0b a0 01 00 57 69 6d 61 | ndo..P...?..Wima
>67 65 2f 67 69 66 2c 20 69 6d 61 67 65 2f 78 2d | ge/gif, image/x-
>78 62 69 74 6d 61 70 2c 20 69 6d 61 67 65 2f 6a | xbitmap, image/j
>70 65 67 2c 20 69 6d 61 67 65 2f 70 6a 70 65 67 | peg, image/pjpeg
>2c 20 61 70 70 6c 69 63 61 74 69 6f 6e 2f 78 2d | , application/x-
>73 68 6f 63 6b 77 61 76 65 2d 66 6c 61 73 68 2c | shockwave-flash,
>20 2a 2f 2a 00 a0 04 00 02 6a 61 00 a0 06 00 0a | */*.?...ja.?...
>4b 65 65 70 2d 41 6c 69 76 65 00 a0 0b 00 07 6f | Keep-Alive.?...o
>72 6c 61 6e 64 6f 00 a0 0d 00 1f 68 74 74 70 3a | rlando.?...http:
>2f 2f 6f 72 6c 61 6e 64 6f 2f 6b 61 6e 73 68 69 | //orlando/kanshi
>2f 6c 6f 67 69 6e 2e 6a 73 70 00 a0 0e 00 32 4d | /login.jsp.?..2M
>6f 7a 69 6c 6c 61 2f 34 2e 30 20 28 63 6f 6d 70 | ozilla/4.0 (comp
>61 74 69 62 6c 65 3b 20 4d 53 49 45 20 36 2e 30 | atible; MSIE 6.0
>3b 20 57 69 6e 64 6f 77 73 20 4e 54 20 35 2e 31 | ; Windows NT 5.1
>29 00 a0 09 00 2b 4a 53 45 53 53 49 4f 4e 49 44 | ).?..+JSESSIONID
>3d 37 34 39 44 46 39 34 32 42 35 45 38 32 39 33 | =749DF942B5E8293
>45 39 32 31 32 34 34 36 32 35 36 37 38 41 34 46 | E921244625678A4F
>42 00 a0 08 00 02 33 37 00 a0 07 00 21 61 70 70 | B.?...37.?..!app
>6c 69 63 61 74 69 6f 6e 2f 78 2d 77 77 77 2d 66 | lication/x-www-f
>6f 72 6d 2d 75 72 6c 65 6e 63 6f 64 65 64 00 a0 | orm-urlencoded.?
>03 00 0d 67 7a 69 70 2c 20 64 65 66 6c 61 74 65 | ...gzip, deflate
>00 00 0d 63 61 63 68 65 2d 63 6f 6e 74 72 6f 6c | ...cache-control
>00 00 08 6e 6f 2d 63 61 63 68 65 00 03 00 00 00 | ...no-cache.....
>04 00 00 00 ff | ....?
>Jun 21, 2004 6:42:33 PM org.apache.jk.common.ChannelSocket processConnection
>WARNING: processCallbacks status 2
>
>Doing additional tests, I have found that it appears to be timeout
>waiting for
>more data to be sent? (guess) I say this because if I do the POST and then
>wait patiently then the error takes about 50 seconds to show up in the log.
>The request will cause 2 such dumps before returning an error to the
>browser. However if I push the submit button on my form then the
>previous request will immediately cause the above error to be dumped.
>The second request will continue to hang until it too times out and dumps
>the above message.
>
>I enabled debug output in the connector and get the following. It seems to
>fail once and then retry. I am including the significant portion of the
>second
>attempt:
>
>[Mon Jun 21 19:14:44 2004] [jk_ajp_common.c (295)]: Into
>ajp_marshal_into_msgb
>[Mon Jun 21 19:14:44 2004] [jk_ajp_common.c (463)]:
>ajp_marshal_into_msgb - Done
>[Mon Jun 21 19:14:44 2004] [jk_connect.c (158)]: Into jk_open_socket
>[Mon Jun 21 19:14:44 2004] [jk_connect.c (165)]: jk_open_socket, try to
>connect socket = 424
>[Mon Jun 21 19:14:44 2004] [jk_connect.c (174)]: jk_open_socket, after
>connect ret = 0
>[Mon Jun 21 19:14:44 2004] [jk_connect.c (183)]: jk_open_socket, set
>TCP_NODELAY to on
>[Mon Jun 21 19:14:44 2004] [jk_connect.c (192)]: jk_open_socket, set
>SO_KEEPALIVE to on
>[Mon Jun 21 19:14:44 2004] [jk_connect.c (200)]: jk_open_socket, return,
>sd = 424
>[Mon Jun 21 19:14:44 2004] [jk_ajp_common.c (661)]: In
>jk_endpoint_t::ajp_connect_to_endpoint, connected sd = 424
>[Mon Jun 21 19:14:44 2004] [jk_ajp_common.c (693)]: sending to ajp13 #453
>[Mon Jun 21 19:14:44 2004] [jk_ajp_common.c (966)]: ajp_send_request 2:
>request body to send 37 - request body to resend 0
>[Mon Jun 21 19:14:44 2004] [jk_isapi_plugin.c (514)]: Into
>jk_ws_service_t::read
>[Mon Jun 21 19:15:44 2004] [jk_isapi_plugin.c (548)]:
>jk_ws_service_t::read, ReadClient failed
>[Mon Jun 21 19:15:44 2004] [jk_ajp_common.c (882)]: ERROR: receiving
>data from client failed. Connection aborted or network problems
>[Mon Jun 21 19:15:44 2004] [jk_ajp_common.c (1303)]: ERROR: Client
>connection aborted or network problems
>[Mon Jun 21 19:15:44 2004] [jk_isapi_plugin.c (925)]: HttpExtensionProc
>service() returned OK
>[Mon Jun 21 19:15:44 2004] [jk_ajp_common.c (1529)]: Into
>jk_endpoint_t::done, closing connection 0
>[Mon Jun 21 19:15:44 2004] [jk_ajp_common.c (605)]: In
>jk_endpoint_t::ajp_close_endpoint
>
>My question is: Do you have any idea what could be causing this. The
>really peculiar thing is that even if I go back to using my old Tomcat
>4.1.18
>deployment. This particular IIS server is now completely unable to do
>POSTs. I had not made any changes on the IIS server between the time
>that it was working and when it stopped. So I am wondering if I had just
>been lucky that things had been working before.
>
>Needless to say I am not thinking it is a good idea to try this out on the
>live servers as I have not been able to figure out a way to return the old
>state should it fail there as well.
>
>Thanks in advance for any advice you may have.
>Cheers,
>Leif
>  
>


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