dev@grizzly.java.net

Re: memory usage with asyncfilter

From: Oleksiy Stashok <Oleksiy.Stashok_at_Sun.COM>
Date: Wed, 18 Nov 2009 17:24:51 +0100

Hi,

Jeanfrancois, once you'll have time, can you pls. take a look at this?

Thanks.

WBR,
Alexey.

On Nov 3, 2009, at 16:00 , Jeanfrancois Arcand wrote:

> Salut,
>
> Oleksiy Stashok wrote:
>> Hi Rama,
>> IMO I've found what causes the higher memory consumption, when
>> AsyncFilter is enabled.
>> Here are my findings, which will help to understand the issue and
>> fix I'm proposing...
>> Basically there is no leak, but because of specific, how we run
>> AsyncProcessorTask - we create and cache much more ProcessorTasks
>> objects, than for regular usecause without AsyncFilters.
>> By specific, I mean approach how we're running AsyncProcessorTask
>> in DefaultAsyncHandler.handle() method. Each AsyncProcessorTask is
>> run in a *new* worker thread (which seems redundant for me, because
>> the current thread is a worker thread).
>
> No, it will not work with Comet if we remove that second thread. I
> will give a try to your patch as I did ARP in 2005, and we may be
> able to remove the second thread pool
>
>
> The situation is following... Assume we have
>> thread pool with max 5 threads and 50 HTTP requests come
>> simultaneously. We enqueue those requests tasks in a worker thread
>> queue.
>> 1) Thread-Pool queue:
>> 50 Request tasks
>> Now first thread picks up first request task, which polls
>> ProcessorTask cache, which is empty, so it creates new
>> ProcessorTask and executes it using AsyncProcessorTask in a new
>> worker thread. So basically we processed so called request task,
>> but added new AsyncProcessorTask on a worker thread queue.
>> 2) Thread-Pool queue:
>> 49 Request tasks
>> 1 AsyncProcessorTask
>> The same situation happens with the 2nd request task, again we
>> create new ProcessorTask and execute it using AsyncProcessorTask in
>> a new worker thread. So basically enqueue one more
>> AsyncProcessorTask.
>> 3) Thread-Pool queue:
>> 48 Request tasks
>> 2 AsyncProcessorTask
>> So finally we will come to up to *50* ProcessorTasks created to
>> process 50 requests, which then will be stored in ProcessorTask
>> cache.
>
> Yes, since ProcessorTask references the request bytes buffer, we ust
> have one ProcessorTask per suspended request. Note that alternative,
> Grizzly Async API, does the same as well. We can't get rid of the
> ProcessorTask, unfortunalty.
>
>
>> Notice, that in normal usecase, without AsyncFilters, we will have
>> only *5* ProcessorTasks in cache, one per each thread.
>> So the easiest solution I can propose is to run AsyncProcessorTasks
>> in the current worker thread (diff is attached).
>> Jeanfrancois, can I ask you to review it?
>
> I suspect Comet will not works with the patch.
>
> A+
>
> -- Jeanfrancois
>
>
>> Thanks.
>> WBR,
>> Alexey.
>> On Oct 30, 2009, at 12:30 , rama.rama_at_tiscali.it wrote:
>>> Ok back :D
>>>
>>> let's be back to memory usage issue.
>>>
>>>
>>>
>>> at the end fo the
>>> mail you can found the test that i have used to found this issue.
>>>
>>> let
>>> me explain how and why i think that there is something of strange.
>>>
>>>
>>> 1)
>>> i'll start a gws, with a static adapter that say "yo"
>>> 2) this gws,
>>> after a 2500ms, will do a GC :)
>>> 3) after a small warmup, a couple of
>>> secs, this is the memory usage
>>> RE 0 MU 1788240
>>> this means that i
>>> haven't do any request and that 1788240 is the minimal memory
>>> usage of
>>> this example.
>>>
>>>
>>> now, let's start AB benchmark.
>>>
>>> ab -c 200 -n 20000
>>> http://192.168.2.143:8080/
>>>
>>> wait a bit (to have some GC issued) and
>>> copy again the memory usage
>>> RE 20001 MU 6038432 --> after the AB (why
>>> there s 1 more request?? maybe my code is stupid)
>>> RE 20001 MU 4419504 --
>>>> 1 min later :)
>>>
>>>
>>>
>>> let's start the 1st test with a AsyncFilter.
>>> The
>>> asyncfilter, added to this gws, is configured as follow. If the uri
>>> contains "rama" it will just schedule the request to be issued 10 ms
>>> later.
>>> if not, the request will simply proceed.
>>>
>>> Let's start it! and
>>> allow a little warmup :)
>>> RE 0 MU 1786376
>>> pretty much the same of
>>> before, so we are ready for the test!
>>>
>>>
>>> now, let's start AB benchmark.
>>>
>>>
>>> ab -c 200 -n 20000 http://192.168.2.143:8080/ --> as you can notice,
>>> there isn't any "rama" on the uri, so asyncfilter, will just pass
>>> the
>>> request to be executed later :)
>>>
>>> and we got
>>> RE 20076 MU 62715680 -->
>>> after the AB (why there is 76 more request?? maybe ab is
>>> stupid?!? :))
>>>
>>> RE 20076 MU 56168440 --> 3 mins later (sorry i have a call hehehe)
>>>
>>>
>>> In
>>> any case, you can see the enormous memory usage while using
>>> asyncfilter
>>> (and without even suspending a request!!)
>>>
>>>
>>> So, just with the 1st test,
>>> i am a bit worried about that..maybe my fault? if so, please,
>>> check the
>>> example and let me know where is the error (i have copy the example
>>> here http://weblogs.java.
>>> net/blog/jfarcand/archive/2008/07/extending_the_g.html btw)
>>>
>>>
>>> let's
>>> start the 2nd test case.
>>> Same code of above.
>>>
>>> ab -c 200 -n 20000 http:
>>> //192.168.2.143:8080/rama (so suspend is on)
>>>
>>> and we got
>>> RE 20005 MU
>>> 68343376 --> after AB (05?? what the hell!!)
>>> RE 20005 MU 68293528 --> 1
>>> mins later
>>>
>>> Any help is appreciated :)
>>>
>>> and here is the test code!
>>>
>>>
>>> ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>>
>>> package test;
>>>
>>> import com.eg.euler.ipc.http.newHttp.EulerAsyncAdapter;
>>>
>>> import com.sun.grizzly.arp.AsyncExecutor;
>>> import com.sun.grizzly.arp.
>>> AsyncFilter;
>>> import com.sun.grizzly.http.embed.GrizzlyWebServer;
>>> import
>>> com.sun.grizzly.tcp.http11.GrizzlyAdapter;
>>> import com.sun.grizzly.tcp.
>>> http11.GrizzlyRequest;
>>> import com.sun.grizzly.tcp.http11.
>>> GrizzlyResponse;
>>>
>>> import java.io.IOException;
>>> import java.util.
>>> concurrent.Callable;
>>> import java.util.concurrent.
>>> ScheduledThreadPoolExecutor;
>>> import java.util.concurrent.TimeUnit;
>>>
>>> import java.util.concurrent.atomic.AtomicInteger;
>>>
>>> /**
>>> * Created by
>>> IntelliJ IDEA.
>>> * User: Rama
>>> * Date: 30-ott-2009
>>> * Time: 11.49.46
>>> */
>>>
>>> public class DemoWebServer {
>>>
>>> static final AtomicInteger req = new
>>> AtomicInteger();
>>> public static void main(String args[]){
>>>
>>> GrizzlyWebServer test = new GrizzlyWebServer();
>>> test.
>>> addGrizzlyAdapter(new MyGrizzlyAdapter(),new String[]{"/"});
>>>
>>> test.addAsyncFilter(new MyAsyncFilter());
>>> test.
>>> getSelectorThread().setDisplayConfiguration(true);
>>> try {
>>>
>>> test.start();
>>> } catch (IOException e){
>>>
>>> e.printStackTrace(); //To change body of catch statement
>>> use File | Settings | File Templates.
>>> }
>>> while
>>> (true) {
>>>
>>> int reqn = req.get();
>>> System.out.
>>> println("RE "+reqn+" MU "+(Runtime.getRuntime().totalMemory() -
>>> Runtime.
>>> getRuntime().freeMemory()));
>>> try {
>>> Thread.
>>> sleep(2500);
>>> System.gc();System.gc();System.gc();
>>>
>>> } catch (Exception e) {
>>>
>>> }
>>>
>>>
>>> }
>>> }
>>>
>>>
>>> static class MyGrizzlyAdapter extends
>>> GrizzlyAdapter {
>>> public void service(GrizzlyRequest
>>> grizzlyRequest, GrizzlyResponse grizzlyResponse) {
>>> try {
>>>
>>> grizzlyResponse.getWriter().print("Great!");
>>>
>>> req.incrementAndGet();
>>> } catch (IOException
>>> e) {
>>>
>>> }
>>> }
>>> }
>>>
>>> static class MyAsyncFilter
>>> implements AsyncFilter {
>>> private final
>>> ScheduledThreadPoolExecutor scheduler =
>>>
>>> new ScheduledThreadPoolExecutor(1);
>>>
>>> public boolean doFilter
>>> (final AsyncExecutor asyncExecutor) {
>>> String url =
>>> asyncExecutor.getProcessorTask().getRequestURI();
>>>
>>>
>>> //if
>>> req url is rama, then delay the request
>>> if (url.contains
>>> ("rama")) {
>>> scheduler.schedule(new Callable() {
>>>
>>> public Object call() throws Exception {
>>>
>>> asyncExecutor.execute();
>>>
>>> asyncExecutor.postExecute();
>>>
>>> return null;
>>> }
>>>
>>> }, 10, TimeUnit.MILLISECONDS);
>>> return
>>> false;
>>> }
>>>
>>> //if not, let them pass :)
>>>
>>> try {
>>> asyncExecutor.execute();
>>>
>>> asyncExecutor.postExecute();
>>> } catch (Exception e) {
>>>
>>>
>>> }
>>>
>>> return false;
>>> }
>>> }
>>>
>>> }
>>>
>>>
>>>
>>>
>>> ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>> Passa a Tiscali Tutto Incluso Light: telefono + adsl 8 Mb senza
>>> limiti a soli 9,95 euro al mese fino al 01/04/2010. Gratis la Sim
>>> Tiscali Mobile con 25 euro di traffico. L’offerta è valida solo
>>> se attivi entro il 29/10/09 http://abbonati.tiscali.it/telefono-adsl/prodotti/tc/tuttoincluso_light/?WT.mc_id=01fw
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: dev-unsubscribe_at_grizzly.dev.java.net
>>> For additional commands, e-mail: dev-help_at_grizzly.dev.java.net
>>>
>> ------------------------------------------------------------------------
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe_at_grizzly.dev.java.net
>> For additional commands, e-mail: dev-help_at_grizzly.dev.java.net
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe_at_grizzly.dev.java.net
> For additional commands, e-mail: dev-help_at_grizzly.dev.java.net
>