Harmony
  1. Harmony
  2. HARMONY-1194

[classlib][nio] unexpected "Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[xxx]" messages

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: Classlib
    • Labels:
      None

      Description

      The test below report on the 2CPU computers messages like this
      "Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[159703592]"

      Note, on 1 CPU it works fine. I did not detect problem yet so continue to investigate.

      ============================= test.java ===========================
      import java.io.File;
      import java.io.FileOutputStream;
      import java.io.IOException;
      import java.nio.ByteBuffer;
      import java.nio.channels.FileChannel;

      public class test {

      public int NUMBER_OF_ITERATIONS = 10000;
      public int NUMBER_OF_BYTE_BUFFERS = 3;
      public int bufferSize = 1024;
      public int numThreads = 15;

      // Each thread sets PASS/FAIL flag into its corresponding array element
      public int[] statuses;

      public static void main(String[] args)

      { System.exit(new test().test(args)); }

      public int test(String[] params) {
      // Start 'numThreads' threads each reading from file, inflating/deflating
      Thread[] t = new Thread[numThreads];
      statuses = new int[t.length];

      for (int i = 0; i < t.length; i++)

      { t[i] = new Thread(new ChannelWriteThread(i, this)); t[i].start(); System.out.println("Thread " + i + " started"); }

      // wait for all threads to finish
      for (int i = 0; i < t.length; ++i){
      try

      { t[i].join(); System.out.println("Thread " + i + ": joined() "); }

      catch (InterruptedException ie)

      { System.out.println("interruptedException while join() of thread #" + i); return -1; }

      }

      // check status
      for (int i = 0; i < statuses.length; ++i){
      if (statuses[i] != 10)

      { System.out.println("thread #" + i + " returned not PASS status"); return -1; }

      }
      System.out.println("OK");
      return 0;
      }
      }

      class ChannelWriteThread implements Runnable {

      public int id;
      public test base;

      public ChannelWriteThread(int id, test base)

      { this.id = id; this.base = base; }

      public void run() {
      FileOutputStream fos = null;
      FileChannel channel = null;

      try

      { File file = File.createTempFile("test", null); file.deleteOnExit(); fos = new FileOutputStream(file); channel = fos.getChannel(); }

      catch (IOException e)

      { e.printStackTrace(); }


      base.statuses[id] = 10;
      ByteBuffer[] buffer = new ByteBuffer[base.NUMBER_OF_BYTE_BUFFERS];

      for (int i = 0; i < base.NUMBER_OF_ITERATIONS; ++i) {
      for(int j = 0; j < base.NUMBER_OF_BYTE_BUFFERS; j++)

      { buffer[j] = ByteBuffer.allocate(2 * base.bufferSize); }

      buffer[0].flip();
      try

      { channel.write(buffer); }

      catch (IOException e)

      { base.statuses[id] = -1; System.out.println("Thread " + id + " : IOException while buffer writing"); }

      buffer[0].clear();
      }
      try

      { channel.close(); fos.close(); }

      catch (IOException e)

      { base.statuses[id] = -1; System.out.println("Thread " + id + " : IOException while closing"); }

      }
      }
      ===============================================================

      Output (for 4 CPU comp):
      Y:\site\proj\drl\qe\my>inaries\builds\combined\20060815\Harmony-drlvm_20060815_win_ia32_0000_msvc\bin\java.exe -Dvm.assert_dialog=false -cp . -showversion test
      java version "1.5.0"
      pre-alpha : not complete or compatible
      svn = rsvn: '.' is not a working copy, (Aug 15 2006), Windows/ia32/msvc 1310, debug build
      http://incubator.apache.org/harmony
      Thread 0 started
      Thread 1 started
      Thread 2 started
      Thread 3 started
      Thread 4 started
      Thread 5 started
      Thread 6 started
      Thread 7 started
      Thread 8 started
      Thread 9 started
      Thread 10 started
      Thread 11 started
      Thread 12 started
      Thread 13 started
      Thread 14 started
      Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[187955296]
      Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[161934880]
      Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[175398240]
      Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[168220896]
      Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[161925840]
      Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[172589448]
      Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[190659456]
      Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[200620192]
      Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[171946168]
      Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[192747808]
      Thread 0: joined()
      Memory Spy! Fixed attempt to free memory that was not allocated PlatformAddress[172558608]
      Thread 1: joined()
      Thread 2: joined()
      Thread 3: joined()
      Thread 4: joined()
      Thread 5: joined()
      Thread 6: joined()
      Thread 7: joined()
      Thread 8: joined()
      Thread 9: joined()
      Thread 10: joined()
      Thread 11: joined()
      Thread 12: joined()
      Thread 13: joined()
      Thread 14: joined()
      OK

      1. Harmony-1194-3.diff
        1 kB
        Paulex Yang
      2. Harmony-1194-2.diff
        0.8 kB
        Ruth Cao
      3. Harmony-1194.diff
        0.8 kB
        Ruth Cao

        Activity

        Hide
        Ruth Cao added a comment -

        Hi all,

        This issue may be due to a System.err.println() statement in AbstractMemorySpy. I'll attach a simple patch soon, Thanks.

        Ruth

        Show
        Ruth Cao added a comment - Hi all, This issue may be due to a System.err.println() statement in AbstractMemorySpy. I'll attach a simple patch soon, Thanks. Ruth
        Hide
        Ruth Cao added a comment -

        May somebody pls try this one?

        Show
        Ruth Cao added a comment - May somebody pls try this one?
        Hide
        Tim Ellison added a comment -

        No, the point is that people should either mark the address for auto free-ing, or (preferably) explicitly free the memory. If they do not then it is a failure in their usage. Perhaps we should change it to an assertion failure rather than printing to System error (though in this case it does an auto free and continues so the app does not stop).

        Show
        Tim Ellison added a comment - No, the point is that people should either mark the address for auto free-ing, or (preferably) explicitly free the memory. If they do not then it is a failure in their usage. Perhaps we should change it to an assertion failure rather than printing to System error (though in this case it does an auto free and continues so the app does not stop).
        Hide
        Ruth Cao added a comment -

        After some further investigation, I've found the root cause of this issue is a multi-thread access to' memoryInUse' in AbstractMemorySpy. It may be better to have a 'get' operation rather that a 'remove-put' one in orphanedMemory method.

        I'll create a patch soon, and thank you so much for the reminder, Tim.

        Show
        Ruth Cao added a comment - After some further investigation, I've found the root cause of this issue is a multi-thread access to' memoryInUse' in AbstractMemorySpy. It may be better to have a 'get' operation rather that a 'remove-put' one in orphanedMemory method. I'll create a patch soon, and thank you so much for the reminder, Tim.
        Hide
        Ruth Cao added a comment -

        May somebody pls try this patch?

        Show
        Ruth Cao added a comment - May somebody pls try this patch?
        Hide
        Paulex Yang added a comment -

        Hi, Ruth,

        I had a look at the harmony-1194-2.diff, but I'm not sure this patch can fix the issues, which I think is caused by the racing condition between orphanedMemory(Reference) and free(PlatformAddress), consider the situation below:

        Thread A runs into MemorySpy.orphanedMemory(Reference) and get non-null "wrapper" by "shadow", at this time Thread B runs into MemorySpy.free(PlatformAddress) and removed same "shadow" from the HashMap "memoryInUse", then when Thread A runs into "wrapper".free() and MemorySpy.free(PlatformAddress), it will find that "shadow" doesn't exist and reports error message as above.

        So, my proposal is, extend synchronized(this) block in MemorySpy.orphanedMemory(Reference ref) to include wrapper.shadow.free(), so that the racing condition can be avoid. I'll upload a diff file soon for details.

        Show
        Paulex Yang added a comment - Hi, Ruth, I had a look at the harmony-1194-2.diff, but I'm not sure this patch can fix the issues, which I think is caused by the racing condition between orphanedMemory(Reference) and free(PlatformAddress), consider the situation below: Thread A runs into MemorySpy.orphanedMemory(Reference) and get non-null "wrapper" by "shadow", at this time Thread B runs into MemorySpy.free(PlatformAddress) and removed same "shadow" from the HashMap "memoryInUse", then when Thread A runs into "wrapper".free() and MemorySpy.free(PlatformAddress), it will find that "shadow" doesn't exist and reports error message as above. So, my proposal is, extend synchronized(this) block in MemorySpy.orphanedMemory(Reference ref) to include wrapper.shadow.free(), so that the racing condition can be avoid. I'll upload a diff file soon for details.
        Hide
        Paulex Yang added a comment -

        Would you please review this patch, thx.

        (I haven't fully tested it because I have no 2-CPU workstations in hand now )

        Show
        Paulex Yang added a comment - Would you please review this patch, thx. (I haven't fully tested it because I have no 2-CPU workstations in hand now )
        Hide
        Mikhail Markov added a comment -

        Hi, Paulex,

        I agree with your concerns.
        I've reviewed your patch and it looks good to me and could be committed. Thanks!

        Show
        Mikhail Markov added a comment - Hi, Paulex, I agree with your concerns. I've reviewed your patch and it looks good to me and could be committed. Thanks!
        Hide
        Paulex Yang added a comment -

        Tim, are you OK with my patch(Harmony-1194-3)? I'll commit it if so.

        Show
        Paulex Yang added a comment - Tim, are you OK with my patch(Harmony-1194-3)? I'll commit it if so.
        Hide
        Tim Ellison added a comment -

        Patch applied to LUNI module at repo revision r531880.

        Paulex: Please check that the patch was applied correctly,
        Vladimir: Please check that this resolves the problem.

        Show
        Tim Ellison added a comment - Patch applied to LUNI module at repo revision r531880. Paulex: Please check that the patch was applied correctly, Vladimir: Please check that this resolves the problem.
        Hide
        Vladimir Ivanov added a comment -

        verified on r532178

        Show
        Vladimir Ivanov added a comment - verified on r532178

          People

          • Assignee:
            Tim Ellison
            Reporter:
            Vladimir Ivanov
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development