users@glassfish.java.net

[gf-users] Re: Using AJP when downloading of large streaming data results in the errors "OutOfMemoryError: Java heap space" and "503 Service Temporarily Unavailable"

From: Philip Durbin <philipdurbin_at_gmail.com>
Date: Wed, 24 Jun 2015 15:02:32 -0400

Hi Steve,

The reason I'm using mod_proxy_ajp rather than mod_jk is the mod_jk
does not ship with RHEL/CentOS. mod_proxy_ajp is built in to the
"httpd" RPM. For details about this, please see
https://access.redhat.com/solutions/18495

At a high level, I'm trying to keep the configuration as simple as
possible for people who install our software. It's easy to type `yum
install httpd` to install Apache and mod_proxy_ajp, which is what I've
documented at http://guides.dataverse.org/en/4.0/installation/shibboleth.html

I haven't been able to find any mod_jk RPMs.

Phil

On Wed, Jun 24, 2015 at 2:46 PM, Steve Wiser
<steve_at_specializedbusinesssoftware.com> wrote:
> Hi Phil,
>
> Is there a reason why you don't use mod_jk instead of mod_proxy_ajp? I had
> thought mod_jk was more mature and better supported.
>
> -steve
>
>
> On Wed, Jun 24, 2015 at 2:30 PM, Philip Durbin <philipdurbin_at_gmail.com>
> wrote:
>>
>> Hello Glassfish users!
>>
>> Does anyone know why the test case below works fine when I use
>> mod_proxy_http but fails when I use mod_proxy_ajp?
>>
>> I originally posted this as a Payara issue but I'm quite sure it
>> applies to Glassfish as well since we're using Glassfish in
>> production: https://github.com/payara/Payara/issues/350
>>
>> I have since uploaded the war file I'm testing with if it's of
>> interest:
>> https://github.com/IQSS/apachetest/releases/download/v0.1/apachetest-0.1.war
>>
>> I'd be happy to provide a Vagrantfile to demo the Apache side of
>> things if that's of interest.
>>
>> Phil
>>
>> ## Summary
>>
>> I'm using Payara 4.1.152.1 behind Apache 2.2 (specifically, the
>> version that ships with CentOS 6: `httpd-2.2.15-39.el6.centos.x86_64`)
>> and I'm getting `java.lang.OutOfMemoryError: Java heap space` and "503
>> Service Temporarily Unavailable" when I try to use AJP
>> (`mod_proxy_ajp`) when downloading a gigabyte from a [simple
>> app](https://github.com/IQSS/apachetest) that [allows an arbitrary
>> number of bytes to be
>>
>> streamed](https://github.com/IQSS/apachetest/blob/master/src/main/java/org/dataverse/apachetest/api/Download.java).
>> I don't see the problem when I don't use AJP.
>>
>> ## How to reproduce
>>
>> - `asadmin start-domain domain1`
>> - enable listener port with `asadmin create-network-listener
>> --protocol http-listener-1 --listenerport 8009 --jkenabled true
>> jk-connector`
>> - deploy apachetest-0.1.war built from https://github.com/IQSS/apachetest
>> - download a one gigabyte file (1 billion bytes) with
>> http://example.com/apachetest-0.1/api/download/streamBytes/1000000000
>>
>> Expected behavior: The file is downloaded without incident
>>
>> Actual behavior: Payara logs `java.lang.OutOfMemoryError: Java heap
>> space` and the client reports "503 Service Temporarily Unavailable".
>>
>> ## Without AJP everything works
>>
>> Below is the output of `curl` when AJP is **not** used. Everything
>> works fine. No 503 errors. The Apache config looks like this:
>>
>> ```
>> <VirtualHost *:80>
>> ServerName example.com
>> ProxyPass / http://localhost:8080/
>> ProxyPassReverse / http://localhost:8080/
>> </VirtualHost>
>> ```
>>
>> The most important output below is the line indicating `200 OK`. The
>> one gigabyte file was downloaded without indicent:
>>
>> ```
>> murphy:apachetest pdurbin$ curl -v
>>
>> http://pdurbin.iq.harvard.edu/apachetest-0.1/api/download/streamBytes/1000000000
>> > /dev/null
>> * Hostname was NOT found in DNS cache
>> % Total % Received % Xferd Average Speed Time Time Time
>> Current
>> Dload Upload Total Spent Left
>> Speed
>> 0 0 0 0 0 0 0 0 --:--:-- --:--:--
>> --:--:-- 0* Trying 140.247.115.167...
>> * Connected to pdurbin.iq.harvard.edu (140.247.115.167) port 80 (#0)
>> > GET /apachetest-0.1/api/download/streamBytes/1000000000 HTTP/1.1
>> > User-Agent: curl/7.37.1
>> > Host: pdurbin.iq.harvard.edu
>> > Accept: */*
>> >
>> < HTTP/1.1 200 OK
>> < Date: Mon, 22 Jun 2015 18:51:39 GMT
>> * Server Payara Server Open Source Edition 4.1.152.1 #badassfish is
>> not blacklisted
>> < Server: Payara Server Open Source Edition 4.1.152.1 #badassfish
>> < X-Powered-By: Servlet/3.1 JSP/2.3 (Payara Server Open Source Edition
>> 4.1.152.1 #badassfish Java/Oracle Corporation/1.7)
>> < Content-Type: application/octet-stream
>> < Connection: close
>> < Transfer-Encoding: chunked
>> <
>> { [data not shown]
>> 100 953M 0 953M 0 0 8266k 0 --:--:-- 0:01:58 --:--:--
>> 8401k
>> * Closing connection 0
>> murphy:apachetest pdurbin$
>> ```
>> ## Using AJP results in OutOfMemoryError and 503 errors
>>
>> In order to use AJP we first enable 8009 as the listener port:
>> `asadmin create-network-listener --protocol http-listener-1
>> --listenerport 8009 --jkenabled true jk-connector`
>>
>> Then we modify the Apache config to use `mod_proxy_ajp` rather than
>> `mod_proxy_http`:
>>
>> ```
>> <VirtualHost *:80>
>> ServerName example.com
>> ProxyPass / ajp://localhost:8009/
>> ProxyPassReverse / ajp://localhost:8009/
>> </VirtualHost>
>> ```
>>
>> Then we repeat the curl command that worked fine when we were not
>> using AJP. Notice that we see "503 Service Temporarily Unavailable":
>>
>> ```
>> murphy:apachetest pdurbin$ curl -v
>>
>> http://pdurbin.iq.harvard.edu/apachetest-0.1/api/download/streamBytes/1000000000
>> > /dev/null
>> * Hostname was NOT found in DNS cache
>> % Total % Received % Xferd Average Speed Time Time Time
>> Current
>> Dload Upload Total Spent Left
>> Speed
>> 0 0 0 0 0 0 0 0 --:--:-- --:--:--
>> --:--:-- 0* Trying 140.247.115.167...
>> * Connected to pdurbin.iq.harvard.edu (140.247.115.167) port 80 (#0)
>> > GET /apachetest-0.1/api/download/streamBytes/1000000000 HTTP/1.1
>> > User-Agent: curl/7.37.1
>> > Host: pdurbin.iq.harvard.edu
>> > Accept: */*
>> >
>> 0 0 0 0 0 0 0 0 --:--:-- 0:01:00
>> --:--:-- 0< HTTP/1.1 503 Service Temporarily Unavailable
>> < Date: Mon, 22 Jun 2015 18:34:43 GMT
>> < Content-Length: 411
>> < Connection: close
>> < Content-Type: text/html; charset=iso-8859-1
>> <
>> { [data not shown]
>> 100 411 100 411 0 0 6 0 0:01:08 0:01:00 0:00:08
>> 101
>> * Closing connection 0
>> murphy:apachetest pdurbin$
>> ```
>>
>> Here is the `OutOfMemoryError` error we see in
>> /home/payara/payara41/glassfish/domains/domain1/logs/server.log
>>
>> ```
>> [2015-06-22T14:35:40.097-0400] [Payara 4.1] [SEVERE]
>> [AS-WEB-CORE-00037] [javax.enterprise.web.core] [tid: _ThreadID=119
>> _ThreadName=jk-connector(1)] [timeMillis: 1434998140097] [levelValue:
>> 1000] [[
>> An exception or error occurred in the container during the request
>> processing
>> java.lang.OutOfMemoryError: Java heap space
>> at java.util.Arrays.copyOf(Arrays.java:2367)
>> at
>> java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:130)
>> at
>> java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:114)
>> at
>> java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:415)
>> at java.lang.StringBuilder.append(StringBuilder.java:132)
>> at
>> com.sun.enterprise.server.logging.UniformLogFormatter.uniformLogFormat(UniformLogFormatter.java:457)
>> at
>> com.sun.enterprise.server.logging.UniformLogFormatter.format(UniformLogFormatter.java:178)
>> at java.util.logging.StreamHandler.publish(StreamHandler.java:196)
>> at
>> java.util.logging.ConsoleHandler.publish(ConsoleHandler.java:105)
>> at java.util.logging.Logger.log(Logger.java:616)
>> at java.util.logging.Logger.doLog(Logger.java:641)
>> at java.util.logging.Logger.logp(Logger.java:757)
>> at
>> com.sun.enterprise.web.logger.IASLogger.write(IASLogger.java:127)
>> at
>> com.sun.enterprise.web.logger.LoggerBase.write(LoggerBase.java:230)
>> at
>> com.sun.enterprise.web.logger.LoggerBase.log(LoggerBase.java:204)
>> at com.sun.enterprise.web.logger.IASLogger.log(IASLogger.java:57)
>> at
>> org.apache.catalina.core.StandardWrapperValve.log(StandardWrapperValve.java:465)
>> at
>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:357)
>> at
>> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:160)
>> at
>> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:734)
>> at
>> org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:673)
>> at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:99)
>> at
>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:174)
>> at
>> org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:415)
>> at
>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:282)
>> at
>> com.sun.enterprise.v3.services.impl.ContainerMapper$HttpHandlerCallable.call(ContainerMapper.java:459)
>> at
>> com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:167)
>> at
>> org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:206)
>> at
>> org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:180)
>> at
>> org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:235)
>> at
>> org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
>> at
>> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:283)
>> ]]
>>
>> [2015-06-22T14:35:52.037-0400] [Payara 4.1] [WARNING] []
>> [org.glassfish.grizzly.filterchain.DefaultFilterChain] [tid:
>> _ThreadID=119 _ThreadName=jk-connector(1)] [timeMillis: 1434998152037]
>> [levelValue: 900] [[
>> GRIZZLY0013: Exception during FilterChain execution
>> java.lang.OutOfMemoryError: Java heap space
>> at java.util.Arrays.copyOf(Arrays.java:2219)
>> at
>> org.glassfish.grizzly.memory.BuffersBuffer.ensureBuffersCapacity(BuffersBuffer.java:316)
>> at
>> org.glassfish.grizzly.memory.BuffersBuffer.append(BuffersBuffer.java:240)
>> at
>> org.glassfish.grizzly.memory.BuffersBuffer.split(BuffersBuffer.java:478)
>> at
>> org.glassfish.grizzly.http.ajp.AjpMessageUtils.appendContentAndTrim(AjpMessageUtils.java:486)
>> at
>> org.glassfish.grizzly.http.ajp.AjpHandlerFilter.encodeHttpPacket(AjpHandlerFilter.java:275)
>> at
>> org.glassfish.grizzly.http.ajp.AjpHandlerFilter.handleWrite(AjpHandlerFilter.java:244)
>> at
>> org.glassfish.grizzly.filterchain.ExecutorResolver$8.execute(ExecutorResolver.java:111)
>> at
>> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:283)
>> at
>> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:200)
>> at
>> org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:132)
>> at
>> org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:111)
>> at
>> org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
>> at
>> org.glassfish.grizzly.filterchain.FilterChainContext.write(FilterChainContext.java:890)
>> at
>> org.glassfish.grizzly.filterchain.FilterChainContext.write(FilterChainContext.java:858)
>> at
>> org.glassfish.grizzly.http.io.OutputBuffer.flushBuffer(OutputBuffer.java:1029)
>> at
>> org.glassfish.grizzly.http.io.OutputBuffer.flushBinaryBuffers(OutputBuffer.java:1016)
>> at
>> org.glassfish.grizzly.http.io.OutputBuffer.flushAllBuffers(OutputBuffer.java:987)
>> at
>> org.glassfish.grizzly.http.io.OutputBuffer.close(OutputBuffer.java:716)
>> at
>> org.glassfish.grizzly.http.io.OutputBuffer.endRequest(OutputBuffer.java:379)
>> at
>> org.glassfish.grizzly.http.server.Response.finish(Response.java:516)
>> at
>> org.glassfish.grizzly.http.server.HttpServerFilter.afterService(HttpServerFilter.java:384)
>> at
>> org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:260)
>> at
>> org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
>> at
>> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:283)
>> at
>> org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:200)
>> at
>> org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:132)
>> at
>> org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:111)
>> at
>> org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
>> at
>> org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:536)
>> at
>> org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:112)
>> at
>> org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:117)
>> ]]
>> ```
>
>