You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Mark Thias <Ma...@bnpi.com> on 2004/06/04 17:40:56 UTC
mod_jk2 error logs show packets dropped
Problem Symptom: During the transfer of a pdf document from application
server
to web server to client browser, transmission errors occur resulting in a
partial delivery
of the document to the web client. The browser is then unable to display the
pdf
document. The following Adobe Acrobat error pops-up on the client while
attempting to display the pdf document:
"The file is damaged and could not be repaired".
Configuration:
Apache Web Server (1)
RedHat Linux 9.0
Apache 2.0.48
mod_jk2 2.0.2 or 2.0.4
openssl 0.9.7
mod_ssl 2.0.48
JBoss Application Server (2)
RedHat Linux 9.0
j2sdk-1_4_1_01-fcs-linux
jboss-3.2.2_jetty-4.2.11
JSQLConnect
|------------|
| Internet |
|------------|
|
|
|
\/
|------------|
| Firewall |
|------------|
|
|
|
\/
|----------------------------------------|
| DMZ |
| |
| |------------| |
| | Apache | |
| | mod_jk2 | |
| |------------| |
| /\ |
| / \ |
| / \ |
| |-------------| |-------------| |
| | JBoss/Jetty | | JBoss/Jetty | |
| |-------------| |-------------| |
| |
|----------------------------------------|
Further Description:
The above configuration is in production and has worked well for us up to
this recent problem. I had this problem before internally using our intranet
but seemingly solved it with a Cisco Switch Firmware upgrade. The firmware
upgrade apparently only masked the problem.
We are streaming the pdf document from the app. server to the web server
using the below code. We are unable to replicate the problem via intranet
since the firmware upgrade. We have some suspicions which I will discuss at
the end. The problem is easy to replicate with offsite users accessing our
site via internet. We have a test setup to transfer a pdf document of 100k
in size. I believe this would happen if we tried to transfer a Word document
or anything else. In other words, I don't think it has anything to do with
PDF.
public void displayReport(HttpServletResponse resp)
{
// set the content type to pdf
resp.setContentType("application/pdf");
// retrieve the output stream from the HttpServletResponse
OutputStream toClient = resp.getOutputStream();
// create a byte buffer to put the generated pdf
ByteArrayOutputStream reportBytes = new ByteArrayOutputStream();
// this calls the reporting tool and generates the pdf document into
the byte array
qbReport.export( "pdf", reportBytes);
// set the content length
resp.setContentLength(reportBytes.size());
//
// Save the file to the J2EE App server so that we can compare it
the one send to the client.
// Also we can ensure its not corrupt before its ever sent.
//
OutputStream outputStream = new FileOutputStream("tempFile.pdf");
reportBytes.writeTo(outputStream);
// now send the pdf document to the client
reportBytes.writeTo(toClient);
}
worker.properties.
#
# Mod_jk2 Configuration file for load balancing
#
[logger]
level=DEBUG
[config:]
file=${serverRoot}/conf/workers2.properties
debug=1
debugEnv=3
# Load balances calls with the /ctms in the URL
[uri:/ctms/*]
info=Map ctms
# alternative log file
[logger.file:0]
level=DEBUG
file=${serverRoot}/logs/jk2_lb.log
[shm:]
info=Scoreboard. Required for reconfiguration and status with multiprocess
serve
rs
file=${serverRoot}/logs/shm.file
size=1048576
debug=1
disabled=0
[workerEnv:]
info=Global Server Options
debug=1
logger=logger.file:0
[lb:lb]
info=default load balancer
debug=1
#logger=logger.file:0
#attempts=1
#stickySession=1
[channel.socket:feinman:8009]
info=Ajp13 forwarding over socket
tomcatId=feinman:8009
lb_factor=100
group=lb
[channel.socket:salk:8009]
info=Ajp13 forwarding over socket
tomcatId=salk:8009
lb_factor=100
group=lb
# announce a status worker
[status:status]
# AJP13 Status
[uri:/jk2status/*]
worker=status:status
#Iconizer servlet
[uri:/LASMapper/*]
group=lb
debug=1
logger=logger.file:0
Here are the mod_jk2 logs, the first shows a successful transmission
while the second shows a failed transmission.
I have sectioned off some potential areas of interest which
show two lost packets.
Log 1: Successful Transmission:
Note from Mark: Start of PDF Transmission.
Transmission contains 1 packet of length 176, 13 of 7171 and one of 5993
bytes.
[Thu Jun 03 13:39:38 2004] ( info ) [jk_channel_apr_socket.c (270)]
channelApr.open(): create tcp socket 136143944
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=176 type=4
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 4 sendHeaders
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=5993 type=3
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:40 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=2 type=5
Note from Mark: End Transmission of PDF
[Thu Jun 03 13:39:40 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 5 endResponse
[Thu Jun 03 13:39:46 2004] (debug ) [jk_env.c (119)] env:Create child env
81ee738 81d6398
[Thu Jun 03 13:39:46 2004] (debug ) [jk_worker_lb.c (88)] lb.get_worker 1
Session=feinman:8009
[Thu Jun 03 13:39:46 2004] (debug ) [jk_worker_lb.c (399)] lb.service() try
ajp13:feinman:8009
[Thu Jun 03 13:39:46 2004] (debug ) [jk_env.c (214)] env.createBean2():
Create [endpoint] (null)
[Thu Jun 03 13:39:46 2004] (debug ) [jk_env.c (375)] env.getByName(): Get
by name workerEnv 81f9818
[Thu Jun 03 13:39:46 2004] (debug ) [jk_env.c (291)] env.createBean2():
register endpoint:13 828d628
[Thu Jun 03 13:39:46 2004] ( info ) [jk_channel_apr_socket.c (270)]
channelApr.open(): create tcp socket 136143944
[Thu Jun 03 13:39:46 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=137 type=4
[Thu Jun 03 13:39:46 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 4 sendHeaders
[Thu Jun 03 13:39:46 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=4099 type=3
[Thu Jun 03 13:39:46 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:46 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=5607 type=3
[Thu Jun 03 13:39:46 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:46 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=2 type=5
[Thu Jun 03 13:39:46 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 5 endResponse
[Thu Jun 03 13:39:48 2004] (debug ) [jk_env.c (119)] env:Create child env
81ee738 81d6398
[Thu Jun 03 13:39:48 2004] (debug ) [jk_worker_lb.c (88)] lb.get_worker 1
Session=feinman:8009
[Thu Jun 03 13:39:48 2004] (debug ) [jk_worker_lb.c (399)] lb.service() try
ajp13:feinman:8009
[Thu Jun 03 13:39:48 2004] (debug ) [jk_env.c (214)] env.createBean2():
Create [endpoint] (null)
[Thu Jun 03 13:39:48 2004] (debug ) [jk_env.c (375)] env.getByName(): Get
by name workerEnv 81f9818
[Thu Jun 03 13:39:48 2004] (debug ) [jk_env.c (291)] env.createBean2():
register endpoint:13 828d628
[Thu Jun 03 13:39:48 2004] ( info ) [jk_channel_apr_socket.c (270)]
channelApr.open(): create tcp socket 136143944
[Thu Jun 03 13:39:50 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=137 type=4
[Thu Jun 03 13:39:50 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 4 sendHeaders
[Thu Jun 03 13:39:50 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=497 type=3
[Thu Jun 03 13:39:50 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:39:50 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=2 type=5
[Thu Jun 03 13:39:50 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 5 endResponse
Log 2: Failed Transmission.
Note from Mark: Start of PDF Transmission.
It contains one transmission of length 176 and 12 of 7171 before an error
occurs.
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=176 type=4
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 4 sendHeaders
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:30 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=7171 type=3
[Thu Jun 03 13:44:30 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:30 2004] (error ) [jk_channel_apr_socket.c (488)]
channelApr.receive(): Error receiving message body -1 104
Note from Mark: Transmission apparently ends in an error.
[Thu Jun 03 13:44:30 2004] (error ) [jk_workerEnv.c (492)]
workerEnv.processCallbacks() Error reading reply
[Thu Jun 03 13:44:30 2004] (error ) [jk_worker_ajp13.c (537)]
ajp13.service() ajpGetReply unrecoverable error 120000
[Thu Jun 03 13:44:30 2004] (error ) [jk_worker_ajp13.c (648)]
ajp13.service() Error forwarding ajp13:feinman:8009 0 1
[Thu Jun 03 13:44:30 2004] ( info ) [jk_worker_ajp13.c (689)] ajp13.done()
close endpoint ajp13:feinman:8009 error_state 1
[Thu Jun 03 13:44:30 2004] (error ) [jk_worker_lb.c (427)] lb.service()
worker failed 120000 for ajp13:feinman:8009
[Thu Jun 03 13:44:30 2004] (error ) [jk_worker_lb.c (441)] lb.service()
unrecoverable error...
[Thu Jun 03 13:44:30 2004] (error ) [mod_jk2.c (752)] mod_jk2.handler()
Error connecting to tomcat 120000, status 200
[Thu Jun 03 13:44:51 2004] (debug ) [jk_worker_lb.c (88)] lb.get_worker 1
Session=feinman:8009
[Thu Jun 03 13:44:51 2004] (debug ) [jk_worker_lb.c (399)] lb.service() try
ajp13:feinman:8009
[Thu Jun 03 13:44:51 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=137 type=4
[Thu Jun 03 13:44:51 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 4 sendHeaders
[Thu Jun 03 13:44:51 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=4099 type=3
[Thu Jun 03 13:44:51 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:51 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=5604 type=3
[Thu Jun 03 13:44:51 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:51 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=2 type=5
[Thu Jun 03 13:44:51 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 5 endResponse
[Thu Jun 03 13:44:55 2004] (debug ) [jk_worker_lb.c (88)] lb.get_worker 1
Session=feinman:8009
[Thu Jun 03 13:44:55 2004] (debug ) [jk_worker_lb.c (399)] lb.service() try
ajp13:feinman:8009
[Thu Jun 03 13:44:55 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=137 type=4
[Thu Jun 03 13:44:55 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 4 sendHeaders
[Thu Jun 03 13:44:55 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=494 type=3
[Thu Jun 03 13:44:55 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 3 sendChunk
[Thu Jun 03 13:44:55 2004] ( info ) [jk_channel_apr_socket.c (494)]
channelApr.receive(): Received len=2 type=5
[Thu Jun 03 13:44:55 2004] (debug ) [jk_workerEnv.c (426)]
workerEnv.dispatch() Calling 5 endResponse
Suspicions
The communications between jboss-jetty and mod_jk2 are seemingly interrupted
when forced into a wait state. This is suspected because the problem is so
easily replicated when accessing off site via the internet. Our
international users were the first to report the issue and we have been able
to replicate from our homes to the office. Perhaps hand-shaking issue
between jetty and mod_jk2.
As a further test, we placed the PDF document on the Apache Web Site outside
of the app. server environment. It displayed fine.
The transmission errors only occur when we stream to the HttpServletResponse
from the app servers.
Thank you for reading this rather large report and any help you might
provide.
Thank you,
Mark Thias
Thank you,
Mark Thias
BioNumerik Pharmaceuticals, Inc.
8122 Datapoint Drive, Suite 400
San Antonio, Tx. 78229
Tel: (210) 614-1701 ext. 249
Fax: (210) 614-9439
This email may contain confidential and privileged material for the sole use
of the intended recipient. Any review or distribution by others is strictly
prohibited. If you are not the intended recipient please contact the sender
and delete all copies.