You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by ndunn1979 <nd...@earthlink.net> on 2009/11/12 16:07:13 UTC
Apache Tomcat Connector (AJP13) is corrupting html content
I am experiencing an odd issue using AJP13 to connect Apache up to Tomcat.
I've gotten it all setup and working for small pages, but I have a use case
where Tomcat serves a very large page >300KB. In this particular case, the
page does not load completely. Sections of the html are duplicated, and some
sections are omitted. I've searched all the logs I can think of (Apache's
mod_jk and error.log, and Tomcat's stdout, stderr, and the catalina log
file). I've cranked up the mod_jk log to level 3 and I can see the html
content coming through in chunks, but the chunks are not synched up
correctly. I tried increasing the max packet size to 65536 (both in
workers.properties and in the server.xml), but I didn't really expect that
to work since it would still require the data to be chunked up.
I'm using Apache 2.2 with Tomcat 5.5 on a Windows XP box. Firewall is
disabled at the moment to rule that out. I've found posts describing issues
with very large POST data and issues related to SSL, but nothing similar to
what I'm experiencing. It's very possible I didn't configure something
correctly, but it is mostly working and I used sample versions of
workers.properties and JkMount directives. I've read through the Tomcat
Connector documentation but there are no settings that appear relevant.
I'm stumped...Hopefully someone can help.
Here is a snippet of the mod_jk log file.
[Thu Nov 12 08:24:04.640 2009] [2104:2368] [debug] jk_ajp_common.c (1259):
03e0 3E 0A 0A 3C 74 72 20 63 6C 61 73 73 3D 22 61 6C - >..<tr.class="al
[Thu Nov 12 08:24:04.640 2009] [2104:2368] [debug] jk_ajp_common.c (1259):
03f0 74 65 72 6E 61 74 65 52 6F 77 22 3E 0A 3C 74 64 - ternateRow">.<td
[Thu Nov 12 08:24:04.640 2009] [2104:2368] [debug] mod_jk.c (506): written
8184 out of 8184
[Thu Nov 12 08:24:04.656 2009] [2104:2368] [debug] jk_ajp_common.c (1259):
received from ajp13 pos=0 len=2 max=65536
[Thu Nov 12 08:24:04.656 2009] [2104:2368] [debug] jk_ajp_common.c (1259):
0000 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 - ................
[Thu Nov 12 08:24:04.656 2009] [2104:2368] [debug] jk_ajp_common.c (1846):
AJP13 protocol: Reuse is OK
[Thu Nov 12 08:24:04.656 2009] [2104:2368] [debug] jk_ajp_common.c (743):
(ajp13) resetting endpoint with sd = 1480
[Thu Nov 12 08:24:04.656 2009] [2104:2368] [debug] jk_ajp_common.c (2905):
recycling connection pool slot=0 for worker ajp13
[Thu Nov 12 08:24:04.656 2009] [2104:2368] [debug] mod_jk.c (2599): Service
finished with status=200 for worker=ajp13
--
View this message in context: http://old.nabble.com/Apache-Tomcat-Connector-%28AJP13%29-is-corrupting-html-content-tp26320290p26320290.html
Sent from the Tomcat - User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
RE: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by ndunn1979 <nd...@earthlink.net>.
Apache HTTP Server/2.2.14
mod_jk/1.2.28
jdk 1.6.0_07-b06
Apache Tomcat/5.5.26
I got the binary for mod_jk from a mirror on the tomcat connectors download
page. The exact filename was
"<mirror>/win32/jk-1.2.28/mod_jk-1.2.28-httpd-2.2.3.so"
--
View this message in context: http://old.nabble.com/Apache-Tomcat-Connector-%28AJP13%29-is-corrupting-html-content-tp26320290p26322232.html
Sent from the Tomcat - User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
RE: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by "Caldarale, Charles R" <Ch...@unisys.com>.
> From: ndunn1979 [mailto:ndunnhsd@earthlink.net]
> Subject: Apache Tomcat Connector (AJP13) is corrupting html content
>
>
> I'm using Apache 2.2 with Tomcat 5.5 on a Windows XP box.
Exact httpd version?
Exact Tomcat version?
Exact mod_jk version?
JRE version?
- Chuck
THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by André Warnier <aw...@ice-sa.com>.
ndunn1979 wrote:
> I am experiencing an odd issue using AJP13 to connect Apache up to Tomcat.
> I've gotten it all setup and working for small pages, but I have a use case
> where Tomcat serves a very large page >300KB.
...
Just so that you would not think that this is a common issue : I have a
couple of systems with a setup similar to yours (Windows, Apache,
mod_jk, Tomcat 5.5) with no special settings, and regularly serve html
pages larger than 300 K (results of searches in a text retrieval
system). I have never seen that issue yet.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
To whom it may concern,
On 11/12/2009 10:07 AM, ndunn1979 wrote:
> I am experiencing an odd issue using AJP13 to connect Apache up to Tomcat.
Which version of mod_jk are you using?
Where did you get your mod_jk binary?
What JVM are you using?
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEYEARECAAYFAkr8MNIACgkQ9CaO5/Lv0PC7/wCfbZ3hihqNU6iXBO/Sosi+Vy1X
5wwAoKFF6O1rZ7PkoHcFLI98hcD8zr0I
=q3ZY
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by ndunn1979 <nd...@earthlink.net>.
Another thought, the application works fine if I go to Tomcat directly via
port 8080.
--
View this message in context: http://old.nabble.com/Apache-Tomcat-Connector-%28AJP13%29-is-corrupting-html-content-tp26320290p26320720.html
Sent from the Tomcat - User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by Rainer Jung <ra...@kippdata.de>.
On 13.11.2009 02:39, Christopher Schultz wrote:
> Rainer,
>
> On 11/12/2009 6:10 PM, Rainer Jung wrote:
>> The 8184 refers to the AJP default max packet size of 8KB minus some
>> protocol overhead. So if a bug response is send, you will see lots of
>> thosse 8184, which are simply fully sized AJP packets. Although you
>> tried to increase the max packet size, it won't probably work, because
>> the backend has to be reconfigured to. Anyhow, the max packet size
>> should have no relation to the problem.
>
> If the max packet sizes are mismatched (mod_jk versus Tomcat's AJP
> connector), could that cause a problem here? Or, does mod_jk detect a
> packet-too-large situation and log a more meaningful error message?
No idea at the moment, but from the log snippet I would say he had
max_packet_size on the JK size increased to 64K and since it is the
absolute max you can choose, he cannot have it bigger on the backend
side. If it were smaller at the backend side, it should be no problem,
and since we see a lot of 8K packets, I expect him to actually still use
the default at the backend. That should be fine.
Regards,
Rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Rainer,
On 11/12/2009 6:10 PM, Rainer Jung wrote:
> The 8184 refers to the AJP default max packet size of 8KB minus some
> protocol overhead. So if a bug response is send, you will see lots of
> thosse 8184, which are simply fully sized AJP packets. Although you
> tried to increase the max packet size, it won't probably work, because
> the backend has to be reconfigured to. Anyhow, the max packet size
> should have no relation to the problem.
If the max packet sizes are mismatched (mod_jk versus Tomcat's AJP
connector), could that cause a problem here? Or, does mod_jk detect a
packet-too-large situation and log a more meaningful error message?
- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEYEARECAAYFAkr8uMsACgkQ9CaO5/Lv0PBeHQCeKeCkKZwfW6JFW/9JUijqTI63
qTIAoJ7p2rKQKkI3p5UyHVAegY52jdxt
=hvk6
-----END PGP SIGNATURE-----
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by Rainer Jung <ra...@kippdata.de>.
On 17.11.2009 02:33, ndunn1979 wrote:
>
>
> Rainer Jung-3 wrote:
>>
>>
>> BTW: Do you use the tomcat native connector? If so, try whether the
>> problem comes from tcnative.
>>
>>
>
> So, I tried increasing the log level on the Tomcat side, but it was a stab
> in the dark because I'm not very familiar with the default style of logging
> (I use log4j, and Tomcat is not setup to use that by default). I changed
> some logger settings, but it didn't show me anything so I went ahead and
> grabbed the tomcat source so I could determine if there was any logging to
> be seen or if I had misconfigured the logging.properties file.
>
> I checked the Connector class to find out where I should log and found the
> check for APR support. I googled that and found the documentation
> referencing the global AprLifecycleListener so I commented that out of the
> server.xml file. That didn't change a thing, but I recognized the JNI call
> in the test for APR support so I decided to rename tcnative-1.dll. That
> forced it to use the java implementation of AJP and all of a sudden my page
> works correctly.
>
> So I know for a fact that the issue is with tcnative (thanks for that hint
> Ranier).
Good to know!
> That leaves me with a few questions:
>
> Why did commenting out the following line not affect it's usage:
> <Listener className="org.apache.catalina.core.AprLifecycleListener" />
>
> The docs say:
> "The APR library is configured by the AprLifecycleListener. This listener is
> configured as a global listener under the Server element in server.xml. If
> the listener can't find the APR/native library when it started, the library
> path it searched will be displayed."
>
> Could any of the configuration options (firstReadTimeout, pollTime,
> pollerSize, useSendFile, sendfileSize) be causing my problems?
>
> If so, what could be causing my system to behave incorrectly with the
> default settings?
>
> What should my next step be in trying to understand why this is not working
> on my machine?
I suggest you start a new discussion thread concerning the listener,
because not everybody reads all mails on the list. Pople decide by
Subject line, which topics they are interested in.
Concerning the tcnative problem I suggest you
- replace tcnative with the most recent version. Tomcat will stay
compatible with it.
- If the problem persists with that version, open an issue in Bugzilla
Regards,
Rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by ndunn1979 <nd...@earthlink.net>.
Rainer Jung-3 wrote:
>
>
> BTW: Do you use the tomcat native connector? If so, try whether the
> problem comes from tcnative.
>
>
So, I tried increasing the log level on the Tomcat side, but it was a stab
in the dark because I'm not very familiar with the default style of logging
(I use log4j, and Tomcat is not setup to use that by default). I changed
some logger settings, but it didn't show me anything so I went ahead and
grabbed the tomcat source so I could determine if there was any logging to
be seen or if I had misconfigured the logging.properties file.
I checked the Connector class to find out where I should log and found the
check for APR support. I googled that and found the documentation
referencing the global AprLifecycleListener so I commented that out of the
server.xml file. That didn't change a thing, but I recognized the JNI call
in the test for APR support so I decided to rename tcnative-1.dll. That
forced it to use the java implementation of AJP and all of a sudden my page
works correctly.
So I know for a fact that the issue is with tcnative (thanks for that hint
Ranier).
That leaves me with a few questions:
Why did commenting out the following line not affect it's usage:
<Listener className="org.apache.catalina.core.AprLifecycleListener" />
The docs say:
"The APR library is configured by the AprLifecycleListener. This listener is
configured as a global listener under the Server element in server.xml. If
the listener can't find the APR/native library when it started, the library
path it searched will be displayed."
Could any of the configuration options (firstReadTimeout, pollTime,
pollerSize, useSendFile, sendfileSize) be causing my problems?
If so, what could be causing my system to behave incorrectly with the
default settings?
What should my next step be in trying to understand why this is not working
on my machine?
--
View this message in context: http://old.nabble.com/Apache-Tomcat-Connector-%28AJP13%29-is-corrupting-html-content-tp26320290p26382994.html
Sent from the Tomcat - User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by Rainer Jung <ra...@kippdata.de>.
On 13.11.2009 21:41, ndunn1979 wrote:
>
> I left them off because they were the same. The only difference is they are a
> second apart.
>
> [Fri Nov 13 08:32:07.359 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
> 0000 03 1F F8 61 63 74 69 6F 6E 3D 31 26 6E 61 6D 65 - ...action=1&name
>
> [Fri Nov 13 08:32:08.218 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
> 0000 03 1F F8 61 63 74 69 6F 6E 3D 31 26 6E 61 6D 65 - ...action=1&name
I see.
> Rainer Jung-3 wrote:
>>
>> Hmmm, that one I'm not sure, because after the "inde" there are only
>> null bytes. Since the beginning of the packet is not shown, I'm not
>> sure, but likely the "inde" was just the end of the body data of the AJP
>> packet.
>>
>
> I agree. I was just pointing out the fact that if you ignore the null bytes,
> the body content continues in the next packet after the header information
> for the two "working" packets.
>
>
> Rainer Jung-3 wrote:
>>
>> The bytes after "inde" are all "00", could simply be the end of gthe
>> packet body.
>>
>
> That makes sense.
>
>
> Rainer Jung-3 wrote:
>>
>> Right, that looks wierd. I assume you didn't leave any line in theis
>> block out from the mail.
>>
>
> That's correct, it's in the log the same way.
>
> So is there any way to trace Tomcat to see how it's handling the requests
> from mod_jk?
You can increase the log level of the connector code. Depending on your
exact connectors, set Log Level for org.apache.jk, org.apache.ajp,
org.apache.coyote to debug.
BTW: Do you use the tomcat native connector? If so, try whether the
problem comes from tcnative.
Regards,
rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by ndunn1979 <nd...@earthlink.net>.
I left them off because they were the same. The only difference is they are a
second apart.
[Fri Nov 13 08:32:07.359 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
0000 03 1F F8 61 63 74 69 6F 6E 3D 31 26 6E 61 6D 65 - ...action=1&name
[Fri Nov 13 08:32:08.218 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
0000 03 1F F8 61 63 74 69 6F 6E 3D 31 26 6E 61 6D 65 - ...action=1&name
Rainer Jung-3 wrote:
>
> Hmmm, that one I'm not sure, because after the "inde" there are only
> null bytes. Since the beginning of the packet is not shown, I'm not
> sure, but likely the "inde" was just the end of the body data of the AJP
> packet.
>
I agree. I was just pointing out the fact that if you ignore the null bytes,
the body content continues in the next packet after the header information
for the two "working" packets.
Rainer Jung-3 wrote:
>
> The bytes after "inde" are all "00", could simply be the end of gthe
> packet body.
>
That makes sense.
Rainer Jung-3 wrote:
>
> Right, that looks wierd. I assume you didn't leave any line in theis
> block out from the mail.
>
That's correct, it's in the log the same way.
So is there any way to trace Tomcat to see how it's handling the requests
from mod_jk?
--
View this message in context: http://old.nabble.com/Apache-Tomcat-Connector-%28AJP13%29-is-corrupting-html-content-tp26320290p26343224.html
Sent from the Tomcat - User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by Rainer Jung <ra...@kippdata.de>.
On 13.11.2009 15:06, ndunn1979 wrote:
>
>
> Rainer Jung-3 wrote:
>>
>>
>> As said: "JkLogLevel trace" will log the full packets.
>>
>>
>
> I reran it with trace log level and I can see the break now between the
> packets.
Good.
> One example that works (notice "inde" at the end of the first packet and "x"
> at the beginning of the next one:
Hmmm, that one I'm not sure, because after the "inde" there are only
null bytes. Since the beginning of the packet is not shown, I'm not
sure, but likely the "inde" was just the end of the body data of the AJP
packet.
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
> 1fe0 69 6E 26 70 72 6F 70 65 72 74 79 3D 63 61 74 65 - in&property=cate
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
> 1ff0 67 6F 72 69 65 73 26 69 6E 64 65 00 00 00 00 00 - gories&inde.....
The bytes after "inde" are all "00", could simply be the end of gthe
packet body.
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_ajp_common.c (1263):
> exit
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_ajp_common.c (1702):
> enter
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [debug] mod_jk.c (506): written
> 8184 out of 8184
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_ajp_common.c (1871):
> exit
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_ajp_common.c (1131):
> enter
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_connect.c (807): enter
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_connect.c (836): exit
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_connect.c (807): enter
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_connect.c (836): exit
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
> received from ajp13 pos=0 len=8188 max=65536
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
> 0000 03 1F F8 78 3D 27 20 2B 20 74 68 69 73 2E 6E 61 - ...x='.+.this.na
03 is the packet type (response body), 1FF8 is the size of the following
body part (bytes count in hex).
> [Fri Nov 13 08:32:07.937 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
> 0010 6D 65 20 2B 20 27 26 76 61 6C 75 65 3D 27 20 2B - me.+.'&value='.+
>
> This one did not work (notice the end of the packet contains "pr" -- meaning
> property and refers to "club" while the next packet starts with "action" and
> refers to "wagon"):
>
> [Fri Nov 13 08:32:07.953 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
> 1fe0 6D 2E 6A 73 70 3F 61 63 74 69 6F 6E 3D 32 26 6E - m.jsp?action=2&n
> [Fri Nov 13 08:32:07.953 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
> 1ff0 61 6D 65 3D 63 6C 75 62 26 70 72 00 00 00 00 00 - ame=club&pr.....
Again I guess it's the end of the packet. Size will have likely been
8184, which in hex is 1FF8. Adding 3 Bytes AJP header (03 1F F8), total
size is 1FFB. First Byte in the line above is at position 1FF1, so 1FFB
is exactly the "72".
> [Fri Nov 13 08:32:07.953 2009] [1916:2244] [trace] jk_ajp_common.c (1263):
> exit
> [Fri Nov 13 08:32:07.953 2009] [1916:2244] [trace] jk_ajp_common.c (1702):
> enter
> [Fri Nov 13 08:32:08.218 2009] [1916:2244] [debug] mod_jk.c (506): written
> 8184 out of 8184
> [Fri Nov 13 08:32:08.218 2009] [1916:2244] [trace] jk_ajp_common.c (1871):
> exit
> [Fri Nov 13 08:32:08.218 2009] [1916:2244] [trace] jk_ajp_common.c (1131):
> enter
> [Fri Nov 13 08:32:08.218 2009] [1916:2244] [trace] jk_connect.c (807): enter
> [Fri Nov 13 08:32:08.218 2009] [1916:2244] [trace] jk_connect.c (836): exit
> [Fri Nov 13 08:32:08.218 2009] [1916:2244] [trace] jk_connect.c (807): enter
> [Fri Nov 13 08:32:08.218 2009] [1916:2244] [trace] jk_connect.c (836): exit
> [Fri Nov 13 08:32:08.218 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
> received from ajp13 pos=0 len=8188 max=65536
> [Fri Nov 13 08:32:08.218 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
> 0000 03 1F F8 61 63 74 69 6F 6E 3D 31 26 6E 61 6D 65 - ...action=1&name
> [Fri Nov 13 08:32:08.218 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
> 0010 3D 77 61 67 6F 6E 26 70 72 6F 70 65 72 74 79 3D - =wagon&property=
Right, that looks wierd. I assume you didn't leave any line in theis
block out from the mail.
> The REALLY odd thing is that this line in the log (the beginning of the
> redundant packet appears exactly the same way twice in the mod_jk log:
>
> jk_ajp_common.c (1259): 0000 03 1F F8 61 63 74 69 6F 6E 3D 31 26 6E 61 6D
> 65 - ...action=1&name
>
> So a perfectly identical packet is being sent more than once.
Unfortunately you did not show the full line, so we have no timestamp
and no thread and pid info :(
> I don't know the absolute byte offset in the binary data. I use firebug, but
> I don't know which feature will give you the byte offset (not sure if it's
> necessary in light of this new information).
>
> Is there a specific logger property I can use to look into the Tomcat side
> to see what's going on? I'm not getting any errors but it seems like it's
> more likely Tomcat that's resending the redundant packets (based on what
> little I understand about the interface between the two programs).
The best way here would be a packet sniffer. mod_jk shows you already,
which data you are looking for in the packets, and they go over the wire
excatly in the same format, that is being dumped in the jk log. No
binary encoding or similar involved. So reading the data in the packet
sniffer is not more difficult than in the jk log.
Regards,
Rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by ndunn1979 <nd...@earthlink.net>.
Rainer Jung-3 wrote:
>
>
> As said: "JkLogLevel trace" will log the full packets.
>
>
I reran it with trace log level and I can see the break now between the
packets.
One example that works (notice "inde" at the end of the first packet and "x"
at the beginning of the next one:
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
1fe0 69 6E 26 70 72 6F 70 65 72 74 79 3D 63 61 74 65 - in&property=cate
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
1ff0 67 6F 72 69 65 73 26 69 6E 64 65 00 00 00 00 00 - gories&inde.....
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_ajp_common.c (1263):
exit
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_ajp_common.c (1702):
enter
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [debug] mod_jk.c (506): written
8184 out of 8184
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_ajp_common.c (1871):
exit
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_ajp_common.c (1131):
enter
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_connect.c (807): enter
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_connect.c (836): exit
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_connect.c (807): enter
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [trace] jk_connect.c (836): exit
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
received from ajp13 pos=0 len=8188 max=65536
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
0000 03 1F F8 78 3D 27 20 2B 20 74 68 69 73 2E 6E 61 - ...x='.+.this.na
[Fri Nov 13 08:32:07.937 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
0010 6D 65 20 2B 20 27 26 76 61 6C 75 65 3D 27 20 2B - me.+.'&value='.+
This one did not work (notice the end of the packet contains "pr" -- meaning
property and refers to "club" while the next packet starts with "action" and
refers to "wagon"):
[Fri Nov 13 08:32:07.953 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
1fe0 6D 2E 6A 73 70 3F 61 63 74 69 6F 6E 3D 32 26 6E - m.jsp?action=2&n
[Fri Nov 13 08:32:07.953 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
1ff0 61 6D 65 3D 63 6C 75 62 26 70 72 00 00 00 00 00 - ame=club&pr.....
[Fri Nov 13 08:32:07.953 2009] [1916:2244] [trace] jk_ajp_common.c (1263):
exit
[Fri Nov 13 08:32:07.953 2009] [1916:2244] [trace] jk_ajp_common.c (1702):
enter
[Fri Nov 13 08:32:08.218 2009] [1916:2244] [debug] mod_jk.c (506): written
8184 out of 8184
[Fri Nov 13 08:32:08.218 2009] [1916:2244] [trace] jk_ajp_common.c (1871):
exit
[Fri Nov 13 08:32:08.218 2009] [1916:2244] [trace] jk_ajp_common.c (1131):
enter
[Fri Nov 13 08:32:08.218 2009] [1916:2244] [trace] jk_connect.c (807): enter
[Fri Nov 13 08:32:08.218 2009] [1916:2244] [trace] jk_connect.c (836): exit
[Fri Nov 13 08:32:08.218 2009] [1916:2244] [trace] jk_connect.c (807): enter
[Fri Nov 13 08:32:08.218 2009] [1916:2244] [trace] jk_connect.c (836): exit
[Fri Nov 13 08:32:08.218 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
received from ajp13 pos=0 len=8188 max=65536
[Fri Nov 13 08:32:08.218 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
0000 03 1F F8 61 63 74 69 6F 6E 3D 31 26 6E 61 6D 65 - ...action=1&name
[Fri Nov 13 08:32:08.218 2009] [1916:2244] [debug] jk_ajp_common.c (1259):
0010 3D 77 61 67 6F 6E 26 70 72 6F 70 65 72 74 79 3D - =wagon&property=
The REALLY odd thing is that this line in the log (the beginning of the
redundant packet appears exactly the same way twice in the mod_jk log:
jk_ajp_common.c (1259): 0000 03 1F F8 61 63 74 69 6F 6E 3D 31 26 6E 61 6D
65 - ...action=1&name
So a perfectly identical packet is being sent more than once.
I don't know the absolute byte offset in the binary data. I use firebug, but
I don't know which feature will give you the byte offset (not sure if it's
necessary in light of this new information).
Is there a specific logger property I can use to look into the Tomcat side
to see what's going on? I'm not getting any errors but it seems like it's
more likely Tomcat that's resending the redundant packets (based on what
little I understand about the interface between the two programs).
--
View this message in context: http://old.nabble.com/Apache-Tomcat-Connector-%28AJP13%29-is-corrupting-html-content-tp26320290p26337088.html
Sent from the Tomcat - User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by Rainer Jung <ra...@kippdata.de>.
On 12.11.2009 23:35, ndunn1979 wrote:
>
>
> Rainer Jung-3 wrote:
>>
>> Does it happen every time for that page? Or is it at least easily
>> reproducible for you? Does the "load not completely" always stop at the
>> same position? If yes, which byte offset?
>>
>> Thos questions help us decide, how easily we will be able to attack the
>> prpblem.
>>
>
> The issue is reproducible and it seems to happen at the same place. The log
Good.
> doesn't make it clear what byte offset it's failing at. I don't know if this
One would normally check this at the client/browser, e.g. using Firefox
and the Firebug plugin you can look at what exactly was received.
> is normal for the mod_jk log file, but even for the parts that come through
> clean it doesn't display all of the binary data.
debug logs only the first part of each AJP packet, trace will log the
full packets.
> I see the request headers and the response headers come through clean. Then
> I see this:
>
> [Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] jk_ajp_common.c (1259):
> received from ajp13 pos=0 len=8188 max=65536
> [Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] jk_ajp_common.c (1259):
> 0000 03 1F F8 0A 0A 0A 3C 68 74 6D 6C 3E 0A 3C 68 65 - ......<html>.<he
> [Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] jk_ajp_common.c (1259):
> 0010 61 64 3E 0A 3C 74 69 74 6C 65 3E 4D 6F 64 69 66 - ad>.<title>Modif
>
> Then I see some of the data, then I see:
>
> [Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] jk_ajp_common.c (1259):
> 03f0 65 6D 54 79 70 65 3C 62 72 3E 41 43 42 6F 6E 75 - emType<br>ACBonu
> [Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] mod_jk.c (506): written
> 8184 out of 8184
> [Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] jk_ajp_common.c (1259):
> received from ajp13 pos=0 len=8188 max=65536
> [Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] jk_ajp_common.c (1259):
> 0000 03 1F F8 0A 3C 74 64 3E 3C 69 6E 70 75 74 20 74 - ....<td><input.t
>
> At this point, I can see that the end of the first block doesn't match up
> with the beginning of the next block. But I figure this must be okay because
> this part of the final document being sent to the browser has no issues.
Guess that's the log output truncation be debug.
> The first issue doesn't show up until byte 266507 (in the final html saved
> to a text file).
>
> The next 137514 bytes are repeated two or three times and the file never
> finishes.
Now we would want to find out, whether that repeted data is actually
send by the backend or not.
> The byte offsets are probably skewed because the browser seems to be
> correcting the malformed html. I don't know how to get a more precise byte
> offset because all it ever says is "written 8184 out of 8184" and "pos=0
> len=8188 max=65536" for each block it logs out. Is there an even more
> detailed log level?
The 8184 refers to the AJP default max packet size of 8KB minus some
protocol overhead. So if a bug response is send, you will see lots of
thosse 8184, which are simply fully sized AJP packets. Although you
tried to increase the max packet size, it won't probably work, because
the backend has to be reconfigured to. Anyhow, the max packet size
should have no relation to the problem.
As said: "JkLogLevel trace" will log the full packets.
Regards,
Rainer
> Rainer Jung-3 wrote:
>>
>>
>> Which part of the log of the one request is it? Is it a full excerpt
>> from the end of the request, or are there lines between those shown
>> missing?
>>
>
> The log I posted originally was from the end of the request.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by ndunn1979 <nd...@earthlink.net>.
Rainer Jung-3 wrote:
>
> Does it happen every time for that page? Or is it at least easily
> reproducible for you? Does the "load not completely" always stop at the
> same position? If yes, which byte offset?
>
> Thos questions help us decide, how easily we will be able to attack the
> prpblem.
>
The issue is reproducible and it seems to happen at the same place. The log
doesn't make it clear what byte offset it's failing at. I don't know if this
is normal for the mod_jk log file, but even for the parts that come through
clean it doesn't display all of the binary data.
I see the request headers and the response headers come through clean. Then
I see this:
[Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] jk_ajp_common.c (1259):
received from ajp13 pos=0 len=8188 max=65536
[Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] jk_ajp_common.c (1259):
0000 03 1F F8 0A 0A 0A 3C 68 74 6D 6C 3E 0A 3C 68 65 - ......<html>.<he
[Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] jk_ajp_common.c (1259):
0010 61 64 3E 0A 3C 74 69 74 6C 65 3E 4D 6F 64 69 66 - ad>.<title>Modif
Then I see some of the data, then I see:
[Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] jk_ajp_common.c (1259):
03f0 65 6D 54 79 70 65 3C 62 72 3E 41 43 42 6F 6E 75 - emType<br>ACBonu
[Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] mod_jk.c (506): written
8184 out of 8184
[Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] jk_ajp_common.c (1259):
received from ajp13 pos=0 len=8188 max=65536
[Thu Nov 12 16:44:19.937 2009] [4604:4760] [debug] jk_ajp_common.c (1259):
0000 03 1F F8 0A 3C 74 64 3E 3C 69 6E 70 75 74 20 74 - ....<td><input.t
At this point, I can see that the end of the first block doesn't match up
with the beginning of the next block. But I figure this must be okay because
this part of the final document being sent to the browser has no issues.
The first issue doesn't show up until byte 266507 (in the final html saved
to a text file).
The next 137514 bytes are repeated two or three times and the file never
finishes.
The byte offsets are probably skewed because the browser seems to be
correcting the malformed html. I don't know how to get a more precise byte
offset because all it ever says is "written 8184 out of 8184" and "pos=0
len=8188 max=65536" for each block it logs out. Is there an even more
detailed log level?
Rainer Jung-3 wrote:
>
>
> Which part of the log of the one request is it? Is it a full excerpt
> from the end of the request, or are there lines between those shown
> missing?
>
The log I posted originally was from the end of the request.
--
View this message in context: http://old.nabble.com/Apache-Tomcat-Connector-%28AJP13%29-is-corrupting-html-content-tp26320290p26327775.html
Sent from the Tomcat - User mailing list archive at Nabble.com.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: Apache Tomcat Connector (AJP13) is corrupting html content
Posted by Rainer Jung <ra...@kippdata.de>.
On 12.11.2009 16:07, ndunn1979 wrote:
>
> I am experiencing an odd issue using AJP13 to connect Apache up to Tomcat.
> I've gotten it all setup and working for small pages, but I have a use case
> where Tomcat serves a very large page >300KB. In this particular case, the
> page does not load completely. Sections of the html are duplicated, and some
> sections are omitted. I've searched all the logs I can think of (Apache's
> mod_jk and error.log, and Tomcat's stdout, stderr, and the catalina log
> file). I've cranked up the mod_jk log to level 3 and I can see the html
> content coming through in chunks, but the chunks are not synched up
> correctly. I tried increasing the max packet size to 65536 (both in
> workers.properties and in the server.xml), but I didn't really expect that
> to work since it would still require the data to be chunked up.
Does it happen every time for that page? Or is it at least easily
reproducible for you? Does the "load not completely" always stop at the
same position? If yes, which byte offset?
Thos questions help us decide, how easily we will be able to attack the
prpblem.
> I'm using Apache 2.2 with Tomcat 5.5 on a Windows XP box. Firewall is
> disabled at the moment to rule that out. I've found posts describing issues
> with very large POST data and issues related to SSL, but nothing similar to
> what I'm experiencing. It's very possible I didn't configure something
> correctly, but it is mostly working and I used sample versions of
> workers.properties and JkMount directives. I've read through the Tomcat
> Connector documentation but there are no settings that appear relevant.
>
> I'm stumped...Hopefully someone can help.
>
> Here is a snippet of the mod_jk log file.
>
> [Thu Nov 12 08:24:04.640 2009] [2104:2368] [debug] jk_ajp_common.c (1259):
> 03e0 3E 0A 0A 3C 74 72 20 63 6C 61 73 73 3D 22 61 6C - >..<tr.class="al
> [Thu Nov 12 08:24:04.640 2009] [2104:2368] [debug] jk_ajp_common.c (1259):
> 03f0 74 65 72 6E 61 74 65 52 6F 77 22 3E 0A 3C 74 64 - ternateRow">.<td
> [Thu Nov 12 08:24:04.640 2009] [2104:2368] [debug] mod_jk.c (506): written
> 8184 out of 8184
> [Thu Nov 12 08:24:04.656 2009] [2104:2368] [debug] jk_ajp_common.c (1259):
> received from ajp13 pos=0 len=2 max=65536
> [Thu Nov 12 08:24:04.656 2009] [2104:2368] [debug] jk_ajp_common.c (1259):
> 0000 05 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 - ................
> [Thu Nov 12 08:24:04.656 2009] [2104:2368] [debug] jk_ajp_common.c (1846):
> AJP13 protocol: Reuse is OK
> [Thu Nov 12 08:24:04.656 2009] [2104:2368] [debug] jk_ajp_common.c (743):
> (ajp13) resetting endpoint with sd = 1480
> [Thu Nov 12 08:24:04.656 2009] [2104:2368] [debug] jk_ajp_common.c (2905):
> recycling connection pool slot=0 for worker ajp13
> [Thu Nov 12 08:24:04.656 2009] [2104:2368] [debug] mod_jk.c (2599): Service
> finished with status=200 for worker=ajp13
Which part of the log of the one request is it? Is it a full excerpt
from the end of the request, or are there lines between those shown missing?
Regards,
Rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org