Issue Details (XML | Word | Printable)

Key: GLASSFISH-18446
Type: Bug Bug
Status: Resolved Resolved
Resolution: Fixed
Priority: Blocker Blocker
Assignee: oleksiys
Reporter: buddypine
Votes: 4
Watchers: 14
Operations

If you were logged in you would be able to see more operations.
glassfish

JK listener with Apache + mod_ajp_proxy causes truncated downloads

Created: 03/Mar/12 04:34 AM   Updated: 05/Oct/12 02:15 PM   Resolved: 06/Mar/12 10:42 AM
Component/s: grizzly-kernel
Affects Version/s: 3.1.2_b23
Fix Version/s: 3.1.2.2

Time Tracking:
Not Specified

File Attachments: 1. File ajp_trunc.cap (331 kB) 03/Mar/12 04:34 AM - buddypine
2. Text File chrome_dump.txt (6 kB) 07/Mar/12 11:58 AM - jsl123
3. Java Archive File grizzly-http-ajp.jar (29 kB) 18/Jun/12 04:35 PM - oleksiys
4. Java Archive File grizzly-http.jar (183 kB) 05/Mar/12 04:42 PM - oleksiys
5. Text File mod_jk.log (3.02 MB) 03/Mar/12 04:54 AM - buddypine
6. Text File wget_dump.txt (12 kB) 07/Mar/12 11:58 AM - jsl123


Tags: 3_1_2-next apache jk jl-listener mod_ajp_proxy
Participants: AndrewJames, benjamin_m, bland999, buddypine, christoph.bernhofer, jsl123, oleksiys, rainerfrey, robbob and tmpsa


 Description  « Hide

Since upgrading to 3.1.2 I am experiencing truncated file downloads from my app with GF behind Apache using a lk-listener and Apache mod_ajp_proxy. It seems to be ajp related as downloads complete fully when accessing app directly on GF http port.

With jk downloads truncate at 256Kb, the original file is 700Kb.

This appears in the Apache logs:

ajp_check_msg_header() got bad signature 28e9
ajp_ilink_receive() received bad header
ajp_read_header: ajp_ilink_receive failed
(120007)APR does not understand this error code: proxy: dialog to 192.168.200.44:8009 (ww.mydomain.com) failed

Config:

asadmin create-network-listener --jkenabled true --protocol http-listener-1 --listenerport 8009 jk-listener
ProxyPass / ajp://www.mydomain.com:8009/
ProxyPassReverse / ajp://www.mydomain.com:8009/

Packet capture of failed download attached.



buddypine added a comment - 03/Mar/12 04:53 AM

I have also tried with mod_jk Tomcat Connector and downloads are truncated at 512Kb.
Attaching error log from mod_jk.


buddypine added a comment - 03/Mar/12 04:54 AM

mod_jk log file showing error


jsl123 added a comment - 03/Mar/12 07:37 AM

Similar problem, webapp returning jsp pages works fine in 3.1.1 and when connecting to glassfish directly, but when you use mod_proxy_ajp, browsers time out waiting for the remaining data


oleksiys added a comment - 05/Mar/12 04:42 PM

to buddypine:
sorry, looks like a bug on our side.
pls. try the attached patch (copy it to glassfish3/glassfish/modules folder)


oleksiys added a comment - 05/Mar/12 04:46 PM

to jsl123:
can you pls. also try the patch, if it doesn't help - pls. let us know how we can reproduce the issue.


christoph.bernhofer added a comment - 05/Mar/12 05:05 PM - edited

Patch doesn't work for me. Have the same issue.
Files still truncated

--> Filesizes compared:
theme.css: should be 31.3 kb
primefaces.css: should be 41 kb
jquery.js: should be 299.8 kb
primefaces.js: should be 179.5 kb

WITHOUT AJP PROXY:
GET adminLogin.jsf?loc=en-GB 200 OK 192.168.78.77:8181 3.1 KB 192.168.78.77:8181 16ms
GET theme.css.jsf?ln=primefaces-aristo 200 OK 192.168.78.77:8181 31.3 KB 11ms
GET primefaces.css.jsf?ln=primefaces&v=3.1.1 200 OK 192.168.78.77:8181 41 KB 12ms
GET password.css.jsf?ln=primefaces&v=3.1.1 200 OK 192.168.78.77:8181 1.4 KB 21ms
GET jquery.js.jsf?ln=primefaces&v=3.1.1 200 OK 192.168.78.77:8181 299.8 KB 22ms
GET primefaces.js.jsf?ln=primefaces&v=3.1.1 200 OK 192.168.78.77:8181 179.5 KB 22ms
GET password.js.jsf?ln=primefaces&v=3.1.1 200 OK 192.168.78.77:8181 4.7 KB 205ms
GET iPCP.css 304 Not Modified 192.168.78.77:8181 2 KB 192.168.78.77:8181 15ms

8 Anfragen

562.8 KB

(559.6 KB vom Cache)

WITH AJP PROXY:
GET adminLogin.jsf?loc=en-GB 200 OK 192.168.78.77 1.1 KB 192.168.78.77:443 16ms
GET theme.css.jsf?ln=primefaces-aristo 200 OK 192.168.78.77 0 192.168.78.77:443 16ms
GET primefaces.css.jsf?ln=primefaces&v=3.1.1 200 OK 192.168.78.77 0 192.168.78.77:443 16ms
GET password.css.jsf?ln=primefaces&v=3.1.1 200 OK 192.168.78.77 433 B 5ms
GET jquery.js.jsf?ln=primefaces&v=3.1.1 200 OK 192.168.78.77 0 192.168.78.77:443 47ms
GET primefaces.js.jsf?ln=primefaces&v=3.1.1 200 OK 192.168.78.77 0 192.168.78.77:443 32ms
GET password.js.jsf?ln=primefaces&v=3.1.1 200 OK 192.168.78.77 1.9 KB 8ms
GET iPCP.css 304 Not Modified 192.168.78.77 733 B 192.168.78.77:443 16ms
GET primefaces.js.jsf?ln=primefaces&v=3.1.1 200 OK 192.168.78.77 0 192.168.78.77:443 16ms

9 Anfragen

4.1 KB

(3 KB vom Cache)


buddypine added a comment - 05/Mar/12 06:14 PM

@oleksiys - thanks the patch does work for me.


oleksiys added a comment - 06/Mar/12 10:38 AM

oleksiys added a comment - 06/Mar/12 10:41 AM

@jsl123
@christoph.bernhofer

can you pls. create a separate issue and provide more data, logs etc. Cause w/ the patch I'm not able to reproduce truncate issue (tried both secure and plain connections).


oleksiys added a comment - 06/Mar/12 10:42 AM

fix will be available in the next 3.1.x release


rainerfrey added a comment - 06/Mar/12 10:50 AM

Will that be a regular several-month release cycle, or is there a chance for a quick release with this fix? AFAIS this is a general problem with Glassfish and JK, and in that case it will keep us from upgrading to 3.1.2.

Or can the circumstances be narrowed down to more special configuration than using a jk-listener in general?


oleksiys added a comment - 06/Mar/12 01:42 PM

Normally we upgrade Grizzly as part of GF release cycle or as patch (which we provided).
I can try to investigate if we can make Grizzly upgrade using GF update tool...


oleksiys added a comment - 06/Mar/12 05:21 PM

changing priority and module


oleksiys added a comment - 06/Mar/12 05:23 PM

@jsl123
@christoph.bernhofer

guys, wanted to ask you to give me more info on your usecases, so we can fix and deliver updates asap.

thanks.


christoph.bernhofer added a comment - 06/Mar/12 05:33 PM

Hi oleksiys

My Application is a JSF2 WAR Application behind Apache 2.2. mod_proxy_ajp.

Created with
asadmin create-threadpool --minthreadpoolsize 5 --maxthreadpoolsize 150 jk-thread-pool
asadmin create-network-listener --protocol http-listener-1 --listenerport 8091 --jkenabled true --threadpool jk-thread-pool jk-connector

and

ProxyPass /iPCP ajp://localhost:8091/iPCP
ProxyPassReverse /iPCP ajp://localhost:8091/iPCP

works flawless with glassfish 3.1.1 in same configuration

updated now Apache ond Debian squeeze x64 to apache/2.2.16 (Debian) PHP/5.3.3-7+squeeze1 with Suhosin-Patch mod_python/3.3.1 Python/2.6.6 mod_ssl/2.2.16 OpenSSL/0.9.8o mod_perl/2.0.4 Perl/v5.10.1 configured

but this hasn't changed anything.

error.log apache2:

ajp_check_msg_header() got bad signature 6575
[Mon Mar 05 14:14:22 2012] [error] ajp_ilink_receive() received bad header
[Mon Mar 05 14:14:22 2012] [error] ajp_read_header: ajp_ilink_receive failed
[Mon Mar 05 14:14:22 2012] [error] (120007)APR does not understand this error code: proxy: dialog to 127.0.0.1:8091 (localhost) failed
[Mon Mar 05 14:14:23 2012] [error] [client 192.168.178.14] File does not exist: /var/www/favicon.ico
[Mon Mar 05 14:14:23 2012] [error] [client 192.168.178.14] File does not exist: /var/www/favicon.ico
[Mon Mar 05 14:14:23 2012] [error] [client 192.168.178.14] File does not exist: /var/www/favicon.ico
[Mon Mar 05 14:15:06 2012] [error] [client 192.168.178.14] proxy: error processing end, referer: http://192.168.78.77/iPCP/admin/adminLogin.jsf?loc=en-GB
[Mon Mar 05 14:15:06 2012] [error] [client 192.168.178.14] proxy: error processing body. Client aborted connection., referer: http://192.168.78.77/iPCP/admin/adminLogin.jsf?loc=en-GB
[Mon Mar 05 14:15:16 2012] [error] ajp_check_msg_header() got bad signature 6575
[Mon Mar 05 14:15:16 2012] [error] ajp_ilink_receive() received bad header
[Mon Mar 05 14:15:16 2012] [error] ajp_read_header: ajp_ilink_receive failed

which more info do you need?

Christoph


oleksiys added a comment - 06/Mar/12 05:42 PM

can you pls. attach the app, or better very reduced version of the app, so I'll be able to debug the problem.

Thanks.


rainerfrey added a comment - 07/Mar/12 07:34 AM

An uüdate via updatetool would be great! Thank you.


christoph.bernhofer added a comment - 07/Mar/12 08:07 AM

Hi oleksiys

I just tried withthe Primefces showcase App.
Same issue. Glassfish 3.1.1. same configuration, same Apache --> works flawless
Glassfish 3.1.2 don't work with proxy, Without proxy it works
I tried to access the App via mod_ssl at Apache at 443 and ajp behind as written above.

Here is the Link to the sample war file:

http://repository.primefaces.org/org/primefaces/prime-showcase/1.0.0-SNAPSHOT/prime-showcase-1.0.0-SNAPSHOT.war

Thx

Christoph


jsl123 added a comment - 07/Mar/12 09:19 AM

Hi guys, sorry didn't get updates about this and was distracted. Trying patch now. Will report on progress.


oleksiys added a comment - 07/Mar/12 10:37 AM

Hi Christoph,

what exactly doesn't work in that app? Cause I'm able to load it in a browser and go throw couple of menu items w/o problems.

Thanks.


christoph.bernhofer added a comment - 07/Mar/12 10:40 AM

Hi oleksiys

Now I get a complete timeout of the whole App. App is not loaded via proxy.

Can you plese tell me your exact versions for Apache, Java...
have you tried also via SSL?

Tx

Christoph


oleksiys added a comment - 07/Mar/12 10:47 AM - edited

I tried mod_ssl and plain, both work fine.

Apache 2.2.17:

ProxyPass /prime-showcase-1.0.0-SNAPSHOT ajp://localhost:8009/prime-showcase-1.0.0-SNAPSHOT retry=0 ttl=30
ProxyPassReverse /prime-showcase-1.0.0-SNAPSHOT ajp://localhost:8009/prime-showcase-1.0.0-SNAPSHOT
ProxyPreserveHost on

JDK:

java version "1.6.0_30"
Java(TM) SE Runtime Environment (build 1.6.0_30-b12)
Java HotSpot(TM) 64-Bit Server VM (build 20.5-b03, mixed mode)


jsl123 added a comment - 07/Mar/12 11:57 AM - edited

OK, further investigation.

Ubuntu 11.10 x64
Apache 2.2.20-1ubuntu1.2
Glassfish 3.1.2 with grizzly patch

If I disable mod_deflate in apache it works fine, pages appear as normal, however as soon as I enable mod_deflate, things break.

With mod_deflate:
Using standard wget works fine - no compression used
Using wget with "accept-encoding:gzip" header set works.
Using firefox/chrome doesn't work. Firefox silently shows a blank page however chrome gives us a clue and reports
"Error 321 (net::ERR_INVALID_CHUNKED_ENCODING): Unknown error

This all works fine in 3.1.1

Looking at the net traffic (attached) they are different both in content (should be the same) and also size, the chunked version is bigger. The wget compressed data expands into the same as if compression isn't used.

So it looks like a different bug


jsl123 added a comment - 07/Mar/12 11:58 AM

tcpdump of chrome page fetch


jsl123 added a comment - 07/Mar/12 11:58 AM

tcp dump of wget


christoph.bernhofer added a comment - 07/Mar/12 12:07 PM - edited

Get the same Error 321 (net::ERR_INVALID_CHUNKED_ENCODING): Unknown error
Deactiveated now mod_deflate --> works


oleksiys added a comment - 07/Mar/12 12:37 PM

thank you guys, i'll investigate that and let you know asap.


oleksiys added a comment - 07/Mar/12 04:07 PM

additional patch


oleksiys added a comment - 07/Mar/12 04:08 PM

guys, can you pls. try to apply another jar (attached) additionally to one which had been attached before?
thx.


christoph.bernhofer added a comment - 07/Mar/12 04:16 PM

Wworks for me with an without mod_deflate!

Great Work, thank you


jsl123 added a comment - 07/Mar/12 04:49 PM

Looks to work for me as well, with mod_deflate.

Will do more testing and post if I find anything else..

good work, Cheers


jsl123 added a comment - 08/Mar/12 05:37 PM

One thing I've noticed and don't think it is expected, but wanted to check before I file a bug? With 3.1.2 when we use HttpServletRequest.getRemoteAddr/Host it returns 127.0.0.1 when using mod_proxy_ajp and apache. With 3.1.1 it returns the address of the client.
I assume this is a bug


oleksiys added a comment - 08/Mar/12 05:42 PM

ok, will check that.

thanks.


oleksiys added a comment - 09/Mar/12 12:29 PM

fix for getRemoteXXX()


oleksiys added a comment - 09/Mar/12 12:31 PM

attached the grizzly-http-ajp.jar with the getRemoteAddr/Host fix.
thanks!


jsl123 added a comment - 09/Mar/12 12:50 PM

Cheers, looks to have fixed it. Would it be possible to push this via the update-tool?

Thanks


oleksiys added a comment - 09/Mar/12 01:48 PM

thank you for confirming!

w/ update tool, we're still investigating this...


AndrewJames added a comment - 18/Mar/12 11:16 PM

I faced the same issue - very happy to see this patch, which resolved the problem - thank you. A life-saver (figuratively speaking).


oleksiys added a comment - 29/Mar/12 09:54 AM

internal bugdb# 13902008.


oleksiys added a comment - 25/Apr/12 09:21 AM

update the patch to fix issue
http://java.net/jira/browse/GRIZZLY-1254


jsl123 added a comment - 02/May/12 09:56 AM

Although the download truncation seems to have been fixed, it looks like we are getting an upload truncation issue. One of my clients is posting files to our server which all worked fine with 3.1.1, but after upgrading and applying the above patches, it bombs out part way through the transfer.

Small files work, but larger ones don't. In apache I get
[Tue May 01 15:06:32 2012] [debug] mod_proxy_ajp.c(273): proxy: data to read (max 8186 at 4)
[Tue May 01 15:06:32 2012] [debug] mod_proxy_ajp.c(288): proxy: got 1448 bytes of data
[Tue May 01 15:06:32 2012] [error] ajp_check_msg_header() got bad signature 4854
[Tue May 01 15:06:32 2012] [error] ajp_ilink_receive() received bad header
[Tue May 01 15:06:32 2012] [error] ajp_read_header: ajp_ilink_receive failed
[Tue May 01 15:06:32 2012] [error] (120007)APR does not understand this error code: proxy: read response failed from 127.0.0.1:8009 (localhost)
[Tue May 01 15:06:32 2012] [debug] proxy_util.c(2029): proxy: AJP: has released connection for (localhost)
[Tue May 01 15:06:32 2012] [debug] mod_headers.c(756): headers: ap_headers_output_filter()
[Tue May 01 15:06:32 2012] [debug] mod_dumpio.c(142): mod_dumpio: dumpio_out

which then results in a 500 error from the server ultimately being returned.

John


oleksiys added a comment - 04/May/12 12:47 PM

Did you try the latest grizzly-http-ajp.jar I attached recently?
Does this problem occur all the time you try to upload files? Do you see anything interesting in the Glassfish server.log?

thx.


jsl123 added a comment - 04/May/12 01:11 PM

I've used the file version from yesterday which was the latest, I'll try and do some more tests to narrow down the problem.
Thanks


oleksiys added a comment - 14/May/12 09:24 AM

any updates?

thx.


jsl123 added a comment - 15/May/12 01:40 PM

Hi, sorry for the delay. I've done some more testing and doesn't appear to be a truncation issue as such, although it might be related. I'm not sure if this is a bug in the grizzly ajp code or apaches mod_proxy_ajp. I've created a new issue for this:
http://java.net/jira/browse/GLASSFISH-18731

Thanks

John


oleksiys added a comment - 02/Jun/12 08:41 AM

update grizzly-http-ajp.jar , which has to have a fix for
http://java.net/jira/browse/GRIZZLY-1276


bland999 added a comment - 02/Jun/12 09:58 AM

The original issue of truncated transmissions is biting my organization (healthcare, 14000+ employees) pretty badly now. We recently upgraded to Glassfish 3.1.2 and we are trying to move away from a very expensive commercial server to this excellent open source choice.

However, this particular issue is a major stopper for us... is there any chance to please roll this fix into an update through the "updatetool" interface?

(We are running the Oracle supported release by the way.)

Thank you!


benjamin_m added a comment - 08/Jun/12 11:16 PM

Ran into similar issue for content generated by Servlets behind mod_jk .
Fix was to remove response.setContentLength() and add "chunked" in HTTP header. Otherwise HTTP chunked data would get truncated for any response bigger than 512KB. Make sure chunked encoding is enable in your Glassfish listeners.


bland999 added a comment - 13/Jun/12 07:42 AM

Chunked encoding is already enabled for the JK listener that we created. And also for the existing HTTP listeners... so I don't think this was the issue.


benjamin_m added a comment - 13/Jun/12 07:58 AM - edited

Having JK listener enabled for chunked encoding is not enough. If your servlet/producer sets the content length then the transfer will be truncated over 512KB.
That part takes its roots in the principle of chunking in HTTP 1.1 against HTTP 1.0 but I don't know if it's an actual error from the GRIZZLY implementation to by pass the chunked setting if setContentLength() is used.


oleksiys added a comment - 13/Jun/12 08:01 AM

@bland999: just to make sure, do you see any issues after applying the patch (2 jar files attached here)? Thanks.


bland999 added a comment - 14/Jun/12 01:55 AM

Thank you both (benjamin_m and oleksiys) for trying to help.

To oleksiys in particular, may I respectfully quote you in an earlier comment: "I can try to investigate if we can make Grizzly upgrade using GF update tool..."

This is actually important to my organization, as they are not very comfortable with open source (this is the first major installation in 30 years to give you an idea), so I was politely hoping that there would be an official release through the update toolset as opposed to applying a patch.

I apologize to request this, but even though I personally am an open source user for many years (I built my first Slackware distribution back in the mid-90's), there is a culture that I am trying to change here. I am sure my organization would be thrilled to see these patches "automagically" appear through updatetool.

Just my two cents, and thanks for taking it into consideration please.


tmpsa added a comment - 17/Jun/12 12:11 PM

I can also confirm that the patched jar files solves the problem. I also got a broken connection to Apache after upgrading GF from 3.1.1 to 3.1.2 . Very frustrating! Thanks for the fix, you saved my day!!

I'll second the suggestion that these kind of critical patches should be distributed, e.g. at the GF 3.1.2 download page.


oleksiys added a comment - 18/Jun/12 04:35 PM

latest patch for fix
http://java.net/jira/browse/GRIZZLY-1284
"AJP connector can not recover after unexpected EOF"


tmpsa added a comment - 14/Aug/12 08:24 AM

I suddenly get get an intense stream of SEVERE loggings, all identical. Same ThreadID, too. See below.
I run GF behind Apache, and have installed the patched jar files (which helped fix the file download issue).

I don't know if this is related, or perhaps another issue?

[#|2012-08-14T10:06:48.961+0200|SEVERE|glassfish3.1.2|com.sun.grizzly.config.GrizzlyServiceListener|_ThreadID=25;_ThreadName=Thread-2;|GRIZZLY0051: ProcessorTask exception.
java.lang.IllegalStateException: Invalid packet magic number: 4745 pos=0lastValid=54 end=0
at com.sun.grizzly.http.ajp.AjpInputBuffer.readAjpMessageHeader(AjpInputBuffer.java:85)
at com.sun.grizzly.http.ajp.AjpProcessorTask.parseRequest(AjpProcessorTask.java:107)
at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:706)
at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1045)
at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:228)
at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)
at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)
at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)
at com.sun.grizzly.ContextTask.run(ContextTask.java:71)
at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)
at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)
at java.lang.Thread.run(Thread.java:662)

#]

oleksiys added a comment - 14/Aug/12 01:14 PM

That's interesting, may be you try to send plain HTTP request to the AJP port?
Cause instead of AJP protocol magic 0x1234 we read 0x4745, which corresponds to characters "GE", which is probably part of "GET ...."


robbob added a comment - 27/Aug/12 09:53 PM

We are having the same exact issue (same exception & magic number 4745) running GF behind Apache as well. The problem is random, and we have not been able to replicate it consistently. We will go a week or more without any issues, and then when it does occur, it continues occurring for every single request from that point on until the GF domain is restarted. We upgraded to GF 3.1.2.2 hoping that would clear up the issue, but it didn't


oleksiys added a comment - 27/Aug/12 10:09 PM

is it possible to capture tcp traffic (for example using wireshark) when you see this issue?
it really looks like plain HTTP messages come to AJP port, but i might be wrong.

thx.


oleksiys added a comment - 05/Oct/12 02:15 PM

ajp related update for GF 3.1.2.2
http://java.net/jira/browse/GRIZZLY-1340