Memory allocation time

A

avinash.lakshman

Hi All

I execute the following snippet of code:

public static void main(String[] args)
{
while(true)
{
long startTime = System.currentTimeMillis();
byte[] bytes = new bytes[1024*1024];
System.out.println("Time taken : " + (System.currentTimeMillis()
- startTime));
}
}

After every few iterations it takes 52 ms for the allocation. Why? How
can I reduce the time taken?

Thanks
A
 
C

Chronic Philharmonic

Hi All

I execute the following snippet of code:

public static void main(String[] args)
{
while(true)
{
long startTime = System.currentTimeMillis();
byte[] bytes = new bytes[1024*1024];
System.out.println("Time taken : " + (System.currentTimeMillis()
- startTime));
}
}

After every few iterations it takes 52 ms for the allocation. Why? How
can I reduce the time taken?

Just guessing... After a while, the JVM does some garbage collection to
reclaim the bytes you are no longer using. Each new assignment to bytes
discards the reference to the previous one. So you're just churning through
memory. Roughly speaking, the JVM lets the old references accumulate until
there isn't enough memory to allocate another one. Then it has to stop and
clean up memory.

I am not aware of any way you can change this behavior. You might try
calling System.gc() after each iteration, that might make the timing more
consistent, but probably less efficient overall. Or it might have no effect
at all. From what I understand, System.gc() is just a suggestion. It depends
on what your needs are. If your real application doesn't require endless
allocation, you might try -Xmx and -Xms to control the amount of memory that
the VM has available from the OS. Perhaps you can arrange it so that your
loop will end before the VM runs out of memory.
 
A

Arne Vajhøj

Chronic said:
Hi All

I execute the following snippet of code:

public static void main(String[] args)
{
while(true)
{
long startTime = System.currentTimeMillis();
byte[] bytes = new bytes[1024*1024];
System.out.println("Time taken : " + (System.currentTimeMillis()
- startTime));
}
}

After every few iterations it takes 52 ms for the allocation. Why? How
can I reduce the time taken?

Just guessing... After a while, the JVM does some garbage collection to
reclaim the bytes you are no longer using. Each new assignment to bytes
discards the reference to the previous one. So you're just churning through
memory. Roughly speaking, the JVM lets the old references accumulate until
there isn't enough memory to allocate another one. Then it has to stop and
clean up memory.

I am not aware of any way you can change this behavior.

There is a gazillion -X and -XX options to control GC behavior.

Arne
 
C

Chronic Philharmonic

Arne Vajhøj said:
Chronic said:
Hi All

I execute the following snippet of code:

public static void main(String[] args)
{
while(true)
{
long startTime = System.currentTimeMillis();
byte[] bytes = new bytes[1024*1024];
System.out.println("Time taken : " + (System.currentTimeMillis()
- startTime));
}
}

After every few iterations it takes 52 ms for the allocation. Why? How
can I reduce the time taken?

Just guessing... After a while, the JVM does some garbage collection to
reclaim the bytes you are no longer using. Each new assignment to bytes
discards the reference to the previous one. So you're just churning
through memory. Roughly speaking, the JVM lets the old references
accumulate until there isn't enough memory to allocate another one. Then
it has to stop and clean up memory.

I am not aware of any way you can change this behavior.

There is a gazillion -X and -XX options to control GC behavior.

Perhaps I should have said I am not aware of any particular way to change
this behavior. I did mention -Xms and -Xmx as a possible starting place. But
the basic problem won't necessarily change. The OP is just generating a lot
of unreferenced memory. Unless there's a good reason for that (I assumed
perhaps this was a simplified case that involved cycling through video
buffers or something), the only way to change the fundamental problem would
be to not do that.
 
L

Lars Enderin

Hi All

I execute the following snippet of code:

The following cannot be an exact copy of the code!
public static void main(String[] args)
{
while(true)
{
long startTime = System.currentTimeMillis();
byte[] bytes = new bytes[1024*1024];
"new bytes[...]" cannot work. You must have "new byte[...]".
 
C

Chronic Philharmonic

Eric Sosman said:
I think so, too. But the reported 52 ms is suggestively
close to the old IBM PC AT clock that ticked at 54.9 ms ...
He's surely not using an AT in this day and age, but there
could well be a software artifact that perpetuates its memory.

It would be easy to modify the code to eliminate memory allocation to test
the timing. It certainly is possible that some entirely separate process is
hanging the system periodically.
 
P

Patricia Shanahan

Hi All

I execute the following snippet of code:

public static void main(String[] args)
{
while(true)
{
long startTime = System.currentTimeMillis();
byte[] bytes = new bytes[1024*1024];
System.out.println("Time taken : " + (System.currentTimeMillis()
- startTime));
}
}

After every few iterations it takes 52 ms for the allocation. Why? How
can I reduce the time taken?

Thanks
A

I tried it on my laptop, and failed to reproduce the problem. I made the
following changes:

1. Changed "new bytes" to "new byte". As noted in another article, "new
bytes" does not compile.

2. Changed "currentTimeMillis" to "nanoTime", and changed the message to
indicate time in nanoseconds.

The programs as run:

public class MemoryAllocationTest {
public static void main(String[] args) {
while (true) {
long startTime = System.nanoTime();
byte[] bytes = new byte[1024 * 1024];
System.out.println("Time taken in nanoseconds : "
+ (System.nanoTime() - startTime));
}
}
}

Here is some typical output, after leaving it to run for about 10 minutes:

Time taken in nanoseconds : 379099
Time taken in nanoseconds : 1686528
Time taken in nanoseconds : 12925106
Time taken in nanoseconds : 458158
Time taken in nanoseconds : 804851
Time taken in nanoseconds : 11001678
Time taken in nanoseconds : 476876
Time taken in nanoseconds : 698972
Time taken in nanoseconds : 11967723
Time taken in nanoseconds : 366527
Time taken in nanoseconds : 825524
Time taken in nanoseconds : 11333004
Time taken in nanoseconds : 365689
Time taken in nanoseconds : 804851
Time taken in nanoseconds : 17488536
Time taken in nanoseconds : 806527
Time taken in nanoseconds : 821892
Time taken in nanoseconds : 10484573
Time taken in nanoseconds : 431898
Time taken in nanoseconds : 866312
Time taken in nanoseconds : 12231163
Time taken in nanoseconds : 431340
Time taken in nanoseconds : 799823

I think the variation between times can be reasonably attributed to
garbage collection. Even the long times are around 12 milliseconds.

How does your output behave using nanoTime? Can you post the exact program?

Patricia
 
J

John B. Matthews

Patricia Shanahan said:
Hi All

I execute the following snippet of code:

public static void main(String[] args)
{
while(true)
{
long startTime = System.currentTimeMillis();
byte[] bytes = new bytes[1024*1024];
System.out.println("Time taken : "
+ (System.currentTimeMillis() - startTime));
}
}

After every few iterations it takes 52 ms for the allocation. Why? How
can I reduce the time taken?

Thanks
A

I tried it on my laptop, and failed to reproduce the problem. I made
the following changes:

1. Changed "new bytes" to "new byte". As noted in another article,
"new bytes" does not compile.

2. Changed "currentTimeMillis" to "nanoTime", and changed the message
to indicate time in nanoseconds.
[...]

For comparison to another implementation, I've posted results using Mac
OS X 10.5.5, Java 1.5.0_16, NetBeans 6.1, profiling every memory
allocation:

<http://sites.google.com/site/trashgod/garbageheap>

Although my processor is slower, I see similar results: two quick
allocations followed by a long one. NetBeans reports "Time spent in GC:
95.6%."

[...]
 
R

Roedy Green

ublic static void main(String[] args)
{
while(true)
{
long startTime = System.currentTimeMillis();
byte[] bytes = new bytes[1024*1024];
System.out.println("Time taken : " + (System.currentTimeMillis()
- startTime));
}
}

After every few iterations it takes 52 ms for the allocation. Why? How
can I reduce the time taken?

You are creating and discarding a 1 MB blob each iteration. You must
periodically pause for garbage collection. To avoid the overhead,
reuse the same bytes array.

see http://mindprod.com/jgloss/garbagecollection.html
 
M

Martin Gregorie

It certainly is possible that some entirely separate
process is hanging the system periodically.
That was my first thought. The OP doesn't say how he runs the
repetitions, but my best guess is that he's using a shell script along
the following lines:

i=0
while ($i > 10)
do
java MyLoop
done

This would rule out any GC effect and make it almost certain that its
something that his unknown OS or another application is doing.
 
A

Arne Vajhøj

Chronic said:
Arne Vajhøj said:
Chronic said:
I execute the following snippet of code:

public static void main(String[] args)
{
while(true)
{
long startTime = System.currentTimeMillis();
byte[] bytes = new bytes[1024*1024];
System.out.println("Time taken : " + (System.currentTimeMillis()
- startTime));
}
}

After every few iterations it takes 52 ms for the allocation. Why? How
can I reduce the time taken?
Just guessing... After a while, the JVM does some garbage collection to
reclaim the bytes you are no longer using. Each new assignment to bytes
discards the reference to the previous one. So you're just churning
through memory. Roughly speaking, the JVM lets the old references
accumulate until there isn't enough memory to allocate another one. Then
it has to stop and clean up memory.

I am not aware of any way you can change this behavior.
There is a gazillion -X and -XX options to control GC behavior.

Perhaps I should have said I am not aware of any particular way to change
this behavior. I did mention -Xms and -Xmx as a possible starting place. But
the basic problem won't necessarily change. The OP is just generating a lot
of unreferenced memory. Unless there's a good reason for that (I assumed
perhaps this was a simplified case that involved cycling through video
buffers or something), the only way to change the fundamental problem would
be to not do that.

Some of the GC options will have an effect on the "GC pausing".

Like:
-XX:MaxGCPauseMillis=10

Arne
 

Ask a Question

Want to reply to this thread or ask your own question?

You'll need to choose a username for the site, which only take a couple of moments. After that, you can post your question and our members will help you out.

Ask a Question

Members online

No members online now.

Forum statistics

Threads
473,764
Messages
2,569,567
Members
45,041
Latest member
RomeoFarnh

Latest Threads

Top