Program not proceeding forward

I made my own small thread-safe (confirmed it using many tests)library similar to Looper and Handler in Android for Java with some other extensions. All is perfect fine and it is performing quite well (verified it by profiling). What it basically does is that every thread has its queue and the queue has an Handle. Using this handler every other thread can put runnable or callable in the queue. So just to check how it performs under heavy load, I made a small program where i generate 1000 threads and each thread posts 10 Runnables in all other threads (i.e., 999 other threads) and then finally every thread sens a shutdown request to every other thread. This works fine if i perform it for <500 threads. Once I have more than 700, the program never ends and ultimately there is an OutOfMemoryError. When i profiled it, I got the below results:

Plot of memory used to memory free with time

and below is the log:

---

-8.035: [GC 170956K->2635K(517952K), 0.0063501 secs]

-8.610: [GC 170955K->15507K(512832K), 0.1745043 secs]

9.543: [GC 175507K->36673K(516928K), 0.3060842 secs]

8.610: [GC 170955K->15507K(512832K), 0.1745043 secs]

9.543: [GC 175507K->36673K(516928K), 0.3060842 secs]

10.321: [GC 196673K->54009K(488896K), 0.3298292 secs]

11.431: [GC 185977K->84189K(502912K), 0.2965050 secs]

12.818: [GC 216157K->111017K(458752K), 0.4901188 secs]

16.660: [GC 198825K->144073K(470528K), 0.7027064 secs]

17.616: [GC 231881K->156962K(479424K), 0.3269871 secs]

18.407: [GC 247490K->177262K(483584K), 0.2446838 secs]

18.924: [GC 268206K->194510K(481216K), 0.2892096 secs]

19.446: [GC 285454K->210302K(487168K), 0.3186975 secs]

20.022: [GC 308734K->225446K(485120K), 0.2547074 secs]

20.610: [GC 323878K->242026K(490624K), 0.2302190 secs]

21.109: [GC 348010K->260490K(489216K), 0.2775054 secs]

21.692: [GC 366474K->280570K(491200K), 0.3264718 secs]

22.359: [GC 389114K->300690K(491200K), 0.3274282 secs]

23.097: [GC 409234K->321958K(490944K), 0.3410703 secs]

23.722: [GC 430374K->340846K(491136K), 0.3375997 secs]

24.060: [Full GC 340846K->303754K(491136K), 2.2736636 secs]

26.727: [GC 412170K->324490K(492096K), 0.1968805 secs]

27.235: [GC 434698K->345614K(491968K), 0.2752622 secs]

27.510: [Full GC 345614K->334283K(491968K), 2.1151760 secs]

29.968: [Full GC 444491K->349326K(491968K), 2.5176330 secs]

32.817: [Full GC 459534K->348355K(491968K), 3.2688566 secs]

36.553: [Full GC 458563K->371805K(491968K), 2.3835641 secs]

39.211: [Full GC 459776K->395739K(491968K), 2.2324407 secs]

41.654: [Full GC 459776K->409135K(491968K), 2.2631054 secs]

44.113: [Full GC 459776K->396769K(491968K), 3.4707959 secs]

47.930: [Full GC 459775K->415668K(491968K), 2.9166601 secs]

51.051: [Full GC 459775K->425117K(491968K), 2.6670247 secs]

53.886: [Full GC 459775K->432457K(491968K), 2.2265421 secs]

56.192: [Full GC 459775K->422948K(491968K), 3.2675329开发者_运维技巧 secs]

59.651: [Full GC 459775K->436339K(491968K), 2.3835789 secs]

62.136: [Full GC 459775K->441349K(491968K), 2.2442554 secs]

64.433: [Full GC 459775K->445241K(491968K), 2.2672156 secs]

66.750: [Full GC 459775K->437517K(491968K), 3.2987756 secs]

70.109: [Full GC 459776K->447665K(491968K), 1.9295598 secs]

72.069: [Full GC 459776K->449837K(491968K), 1.8525232 secs]

73.966: [Full GC 459776K->451969K(491968K), 1.9544717 secs]

75.956: [Full GC 459776K->445178K(491968K), 3.3964743 secs]

and so on forever till error was thrown. Further I found out that once the threads started terminating, the # came down till 167, but the rest never terminated. There cannot be any race conditions, because it performs well for <500 threads. Now I know it might be due to starvation, but if starvation was the reason, then it would have occurred when there were 1000 threads and not when only 150 were left.

What can be the reason for this?

The below is a short snippet of the code:

protected static <T> Future<T> execute(final Double id, Callable<T> call)
{
    if(call==null)
        throw new NullPointerException("Callable is null");

    synchronized(id)
    {
        if(mapBoolean.get(id))
            {
                setPollTime(0);
                throw new RejectedExecutionException();
            }


        RunnableFuture<T> ftask = new FutureTask<T>(call);
        LinkedBlockingQueue<Runnable> queue = map.get(id);
        queue.add(ftask);//System.out.println("added");
        return ftask;  


    }

}

and this is the code where it is executed

public static void loop() throws InterruptedException
{
    LinkedBlockingQueue<Runnable> queue = map.get(tlocal.get());
    Random random = new Random();// This is used instead of Math.random() so that
    //there is less contention on Math.random(). See the API Documentation of Math.random()
    while(!Thread.currentThread().isInterrupted())
    {

        try{
            //Runnable runnable = queue.take(); cannot be used, as we will have to synchronize the whole block for
            //atomicity, see @link shutDown() for more info
              Runnable runnable = queue.poll(pollTime, TimeUnit.MILLISECONDS);
            if(runnable!=null)//if the polled object is not null, if null try again
            {                    

                    runnable.run();
           }

For shutdown:

synchronized(id)
    {            
        mapBoolean.put(id, !shut);            
    } 

PS: Mine is a dual core machine with 2GB ram PPS: Heap size allocated is 512

---

Basically you've got an N² memory problem - each of the 1000 threads is generating 10 runnables in ~1000 threads, so you've got 10,000,000 runnables.

When you create a program which has N² memory usage, you shouldn't be surprised to see the memory increasing as you increase N. Eventually you've got to the stage where you're basically thrashing the GC.

Note that this can very easily show up race conditions which don't occur in other situations - you should never assume that just because the program works in "easy" conditions, that means there are no race conditions in your code. It just means that you don't have any really obvious race conditions. Subtle race conditions are the hardest to find.

What happens if you change the allocated heap size so that the GC doesn't thrash, e.g. to 1.25GB? You may well find that it performs a lot better but still sometimes doesn't quite finish (e.g. gets down to just a few threads).