memory allocation problem

[Hendrik Adler]

Hallo,

I am sending a lot of events per second to Jtalis. But while doing this I run into a big problem.
The memory usage of Jtalis is growing with time till the program crashes.

Here is the output of top:
  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND           
30618 hendrik   20   0 3977m 823m  11m S   99 10.3  33:18.60 java

You can see that the resident size (RES) of the program grows up to 823 MB after just 33 minutes. It grows on till memory is full. I tried to play around
with the garbage collection parameters. But I had no success to prevent an unlimited growing of the java task.

By the way, I have also tried using Etalis directly from java, but run into the same problem. Is this behaviour expected or do I something wrong?

It would be great if someone could help me out.

Cheers
Hendrik

Ps: Here is my java program for replicating this behaviour. I am using jdk1.7.0_17 and swipl-6.2.6 under Ubuntu 12.04 64 bit.

class Main {

    public static void main(String[] args) {

        PrologEngineWrapper<?> engine = new JPLEngineWrapper(false);

        JtalisContextImpl ctx = new JtalisContextImpl(engine);
        ctx.setEtalisFlags("logging", "off");
        ctx.setEtalisFlags("logging_to_file", "off");
        ctx.setEtalisFlags("out_of_order", "off");
        ctx.setEtalisFlags("garbage_clt", "on");
        ctx.setEtalisFlags("garbage_control", "on");

        // ctx.setEtalisFlags("garbage_window","1");
        // ctx.setEtalisFlags("garbage_window_edge","1");
        ctx.setEtalisFlags("garbage_clt", "on");
        ctx.setEtalisFlags("garbage_control", "general");
        // ctx.setEtalisFlags("windowsvalue","1");
        // ctx.setEtalisFlags("event_consumption_policy","recent");
        ctx.addEventTrigger("_");
        ctx.addDynamicRuleWithId("a([property(event_rule_window,1)])", "a(Y)");
        ctx.addDynamicRule("c <- b(X) seq a(Y)");
        // property(event_rule_window,1)
        ctx.registerOutputProvider(new DefaultOutputProvider());
        ctx.registerInputProvider(new DefaultInputProvider());

        int n = 0;
        System.out
                .println("Total memory:" + Runtime.getRuntime().totalMemory());
        while (n < 20000000) {
            ctx.pushEvent(new EtalisEvent("a", 1));
            n++;
            try {
                Thread.sleep(1);
            } catch (InterruptedException e5) {
                // TODO Auto-generated catch block
                e5.printStackTrace();
            }
        }

        ctx.waitForInputProviders();
        ctx.shutdown();
    }
}

[Hendrik Adler]

Sorry in my last message there was an error in the code:

import com.jtalis.core.JtalisContextImpl;
import com.jtalis.core.event.EtalisEvent;
import com.jtalis.core.event.EventTimestamp;
import com.jtalis.core.event.provider.DefaultInputProvider;
import com.jtalis.core.event.provider.DefaultOutputProvider;
import com.jtalis.core.plengine.JPLEngineWrapper;
import com.jtalis.core.plengine.PrologEngineWrapper;

class Main {

    public static void main(String[] args) {

        PrologEngineWrapper<?> engine = new JPLEngineWrapper(false);

        JtalisContextImpl ctx = new JtalisContextImpl(engine);
        ctx.setEtalisFlags("logging", "off");
        ctx.setEtalisFlags("logging_to_file", "off");
        ctx.setEtalisFlags("out_of_order", "off");
        ctx.setEtalisFlags("garbage_clt", "on");
        ctx.setEtalisFlags("garbage_control", "on");

        // ctx.setEtalisFlags("windowsvalue","1");
        // ctx.setEtalisFlags("event_consumption_policy","recent");
        ctx.addEventTrigger("_");

[Vesko Georgiev]

Hi Hendrik,

What garbage collector parameters are talking about? It might be useful if you send also the stack trace. We need to figure out whether this is the prolog part or the java part that causes the problem. 

Cheers,

Vesko

--
You received this message because you are subscribed to the Google Groups "ETALIS" group.
To unsubscribe from this group and stop receiving emails from it, send an email to etalis+un...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

[Hendrik Adler]

Hi Vesko,

many thanks for your support! With garbage collection parameters I mean that I tried to change the window size and  played arround with different setting, e.g. ctx.setEtalisFlags("garbage_clt", "on") and ctx.setEtalisFlags("garbage_control", "on"). I had the idea that old events had not been deleted properly from jtalis because of wrong parameters. That could be a reason for the continuously growing program size.
By the way I use the newest SVN-Sources and have not modified the code.
5 Minutes after the start I created a stack dump of JTALIS. At this point in time the program has continously grown to 112MB. I hope this stack trace is some helpful. I got the same problem when using Etalis with JPL. If you want I also can create a simple example program using ETALIS with JPL that grows without stopping. So quite likely it must be a prolog problem.

Cheers Hendrik

Full thread dump Java HotSpot(TM) 64-Bit Server VM (23.7-b01 mixed mode):

"InputEventProvider [Reading from Standard Input]" prio=10 tid=0x00007fe27843e000 nid=0x2da0 runnable [0x00007fe247ddc000]
   java.lang.Thread.State: RUNNABLE
    at java.io.FileInputStream.readBytes(Native Method)
    at java.io.FileInputStream.read(FileInputStream.java:242)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:273)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
    - locked <0x0000000783210ab0> (a java.io.BufferedInputStream)
    at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283)
    at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325)
    at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177)
    - locked <0x0000000783248fb8> (a java.io.InputStreamReader)
    at java.io.InputStreamReader.read(InputStreamReader.java:184)
    at java.io.Reader.read(Reader.java:100)
    at java.util.Scanner.readInput(Scanner.java:849)
    at java.util.Scanner.findWithinHorizon(Scanner.java:1728)
    at java.util.Scanner.hasNextLine(Scanner.java:1545)
    at com.jtalis.core.event.persistence.DefaultEventIO.deserialize(DefaultEventIO.java:59)
    at com.jtalis.core.event.provider.DefaultInputProvider.getEvent(DefaultInputProvider.java:118)
    at com.jtalis.core.threads.InputEventProviderWorker.run(InputEventProviderWorker.java:48)

"OutputEventProvider [Writing to Standard output]" prio=10 tid=0x00007fe27843b800 nid=0x2d9f waiting on condition [0x00007fe247edd000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x0000000783243c20> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    at com.jtalis.core.threads.OutputEventProviderWorker.run(OutputEventProviderWorker.java:44)

"EventExecutionWorker" prio=10 tid=0x00007fe278432800 nid=0x2d9e waiting on condition [0x00007fe247fde000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x0000000783249840> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389)
    at com.jtalis.core.threads.EventExecutionWorker.run(EventExecutionWorker.java:42)

"Service Thread" daemon prio=10 tid=0x00007fe2780ec800 nid=0x2d9b runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x00007fe2780ea000 nid=0x2d9a waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x00007fe2780e7000 nid=0x2d99 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x00007fe2780e5000 nid=0x2d98 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x00007fe278098000 nid=0x2d97 in Object.wait() [0x00007fe26e102000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x0000000783211a90> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x0000000783211a90> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177)

"Reference Handler" daemon prio=10 tid=0x00007fe278095800 nid=0x2d96 in Object.wait() [0x00007fe26e203000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000007832114a8> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:503)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
    - locked <0x00000007832114a8> (a java.lang.ref.Reference$Lock)

"main" prio=10 tid=0x00007fe278009000 nid=0x2d8f waiting on condition [0x00007fe27e599000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at Main.main(Main.java:41)

"VM Thread" prio=10 tid=0x00007fe27808e000 nid=0x2d95 runnable

"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007fe278017000 nid=0x2d93 runnable

"GC task thread#1 (ParallelGC)" prio=10 tid=0x00007fe278018800 nid=0x2d94 runnable

"VM Periodic Task Thread" prio=10 tid=0x00007fe2780f7000 nid=0x2d9c waiting on condition

JNI global references: 293

Heap
 PSYoungGen      total 7104K, used 205K [0x00000007d6600000, 0x00000007d7900000, 0x0000000800000000)
  eden space 7040K, 2% used [0x00000007d6600000,0x00000007d6623570,0x00000007d6ce0000)
  from space 64K, 100% used [0x00000007d78f0000,0x00000007d7900000,0x00000007d7900000)
  to   space 128K, 0% used [0x00000007d78c0000,0x00000007d78c0000,0x00000007d78e0000)
 ParOldGen       total 85248K, used 600K [0x0000000783200000, 0x0000000788540000, 0x00000007d6600000)
  object space 85248K, 0% used [0x0000000783200000,0x0000000783296070,0x0000000788540000)
 PSPermGen       total 21248K, used 4804K [0x000000077e000000, 0x000000077f4c0000, 0x0000000783200000)
  object space 21248K, 22% used [0x000000077e000000,0x000000077e4b1120,0x000000077f4c0000)