Memory allocation time

Discussion in 'Java' started by avinash.lakshman@gmail.com, Oct 19, 2008.

  1. Guest

    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
     
    , Oct 19, 2008
    #1
    1. Advertising

  2. <> wrote in message
    news:...
    > 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.
     
    Chronic Philharmonic, Oct 19, 2008
    #2
    1. Advertising

  3. Arne Vajhøj Guest

    Chronic Philharmonic wrote:
    > <> wrote in message
    > news:...
    >> 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
     
    Arne Vajhøj, Oct 19, 2008
    #3
  4. "Arne Vajhøj" <> wrote in message
    news:48fb9e98$0$90273$...
    > Chronic Philharmonic wrote:
    >> <> wrote in message
    >> news:...
    >>> 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.
     
    Chronic Philharmonic, Oct 19, 2008
    #4
  5. Lars Enderin Guest

    wrote:
    > 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[...]".
    > System.out.println("Time taken : " + (System.currentTimeMillis()
    > - startTime));
    > }
    > }
    >
     
    Lars Enderin, Oct 19, 2008
    #5
  6. "Eric Sosman" <> wrote in message
    news:...
    > Mike Schilling wrote:
    >> Eric Sosman wrote:
    >>> It's also possible that your system's clock actually "ticks"
    >>> in coarser increments than a millisecond.

    >>
    >> That was my first thought too, but 52 ms is an awfully large and
    >> oddly-sized tick. If it were, say, 16ms (60 ticks/second) or even
    >> exactly 50ms, I'd think this was a more probalbe explanation. As it is,
    >> GC is the likely culprit.

    >
    > 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.
     
    Chronic Philharmonic, Oct 19, 2008
    #6
  7. wrote:
    > 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
     
    Patricia Shanahan, Oct 20, 2008
    #7
  8. In article <gdgjri$1ffp$>,
    Patricia Shanahan <> wrote:

    > wrote:
    > > 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%."

    [...]
    > 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?


    --
    John B. Matthews
    trashgod at gmail dot com
    http://home.roadrunner.com/~jbmatthews/
     
    John B. Matthews, Oct 20, 2008
    #8
  9. Roedy Green Guest

    On Sun, 19 Oct 2008 13:18:29 -0700 (PDT),
    wrote, quoted or indirectly quoted someone who said :

    >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
    --
    Roedy Green Canadian Mind Products
    http://mindprod.com
    The Canadian national animal should be changed from the beaver to the ostrich.
    Canadians elected a party that denies global warming so they too could pretend it presents no danger.
     
    Roedy Green, Oct 20, 2008
    #9
  10. On Sun, 19 Oct 2008 22:03:22 +0000, Chronic Philharmonic wrote:

    > 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.


    --
    martin@ | Martin Gregorie
    gregorie. | Essex, UK
    org |
     
    Martin Gregorie, Oct 20, 2008
    #10
  11. Arne Vajhøj Guest

    Chronic Philharmonic wrote:
    > "Arne Vajhøj" <> wrote in message
    > news:48fb9e98$0$90273$...
    >> Chronic Philharmonic wrote:
    >>> <> wrote in message
    >>> news:...
    >>>> 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
     
    Arne Vajhøj, Oct 26, 2008
    #11
    1. Advertising

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

It takes just 2 minutes to sign up (and it's free!). Just click the sign up button to choose a username and then you can ask your own questions on the forum.
Similar Threads
  1. s.subbarayan

    Dynamic memory allocation and memory leak...

    s.subbarayan, Mar 18, 2005, in forum: C Programming
    Replies:
    10
    Views:
    707
    Eric Sosman
    Mar 22, 2005
  2. Rodrigo Dominguez

    memory allocation and freeing memory

    Rodrigo Dominguez, Jun 13, 2005, in forum: C Programming
    Replies:
    11
    Views:
    605
    Jean-Claude Arbaut
    Jun 15, 2005
  3. Ken
    Replies:
    24
    Views:
    3,876
    Ben Bacarisse
    Nov 30, 2006
  4. chris
    Replies:
    6
    Views:
    992
    chris
    Oct 28, 2005
  5. Bjarke Hammersholt Roune
    Replies:
    14
    Views:
    1,192
    Bjarke Hammersholt Roune
    Mar 6, 2011
Loading...

Share This Page