Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8066764

Self-deadlock in FileChannelImpl.map

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Duplicate
    • Icon: P4 P4
    • None
    • 7u67
    • core-libs
    • x86_64
    • linux

      FULL PRODUCT VERSION :
      java version "1.7.0_67"
      Java(TM) SE Runtime Environment (build 1.7.0_67-b01)
      Java HotSpot(TM) 64-Bit Server VM (build 24.65-b04, mixed mode)


      ADDITIONAL OS VERSION INFORMATION :
      Linux jglick-t520 3.13.0-34-generic #60-Ubuntu SMP Wed Aug 13 15:45:27 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

      A DESCRIPTION OF THE PROBLEM :
      This is not so much a new bug report as a confirmation that #8024833 continues to affect Java 7 and a request for confirmation and backport.

      Originally discovered by a Jenkins user who had a number of threads in the JVM piled up waiting for a succession of locks, ultimately all waiting on a builder thread for a build which had also been interrupted at least once:

      ---%<---
      Executor #0 for … : executing … #… id=… (0x…) state=WAITING cpu=82%
          - waiting on <0x2c830cf0> (a sun.nio.ch.NativeThreadSet)
          - locked <0x2c830cf0> (a sun.nio.ch.NativeThreadSet)
          at java.lang.Object.wait(Native Method)
          at java.lang.Object.wait(Object.java:503)
          at sun.nio.ch.NativeThreadSet.signalAndWait(NativeThreadSet.java:102)
          at sun.nio.ch.FileChannelImpl.implCloseChannel(FileChannelImpl.java:119)
          at java.nio.channels.spi.AbstractInterruptibleChannel$1.interrupt(AbstractInterruptibleChannel.java:165)
          at java.nio.channels.spi.AbstractInterruptibleChannel.begin(AbstractInterruptibleChannel.java:173)
          at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:302)
            - locked java.lang.Object@7a5bfa22
          at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:849)
          at sun.nio.ch.FileChannelImpl.transferFromFileChannel(FileChannelImpl.java:591)
            - locked java.lang.Object@7a5bfa22
          at sun.nio.ch.FileChannelImpl.transferFrom(FileChannelImpl.java:665)
          at org.apache.tools.ant.util.ResourceUtils.copyResource(ResourceUtils.java:532)
          at org.apache.tools.ant.util.FileUtils.copyFile(FileUtils.java:559)
          at org.apache.tools.ant.taskdefs.Copy.doFileOperations(Copy.java:899)
          at org.apache.tools.ant.taskdefs.Copy.execute(Copy.java:567)
          at hudson.Util.copyFile(Util.java:928)
          at hudson.plugins.changelog_history.ChangeLogHistoryRunListener.copyChangeLogs(ChangeLogHistoryRunListener.java:75)
          at hudson.plugins.changelog_history.ChangeLogHistoryRunListener.onDeleted(ChangeLogHistoryRunListener.java:50)
          at hudson.plugins.changelog_history.ChangeLogHistoryRunListener.onDeleted(ChangeLogHistoryRunListener.java:40)
          at hudson.model.listeners.RunListener.fireDeleted(RunListener.java:244)
          at hudson.model.Run.delete(Run.java:1424)
            - locked hudson.model.FreeStyleBuild@16c15ffc
          at hudson.tasks.LogRotator.perform(LogRotator.java:124)
          at hudson.model.Job.logRotate(Job.java:437)
          at hudson.model.Run.execute(Run.java:1728)
          at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:46)
          at hudson.model.ResourceController.execute(ResourceController.java:88)
          at hudson.model.Executor.run(Executor.java:246)
      ---%<---

      Note that #8012019 also shows a similar thread dump, but I am fairly sure that #8024833 is the explanation here.

      STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
      Run the attached test case.

      EXPECTED VERSUS ACTUAL BEHAVIOR :
      EXPECTED -
      In JDK 8u20 I get something like:

      ---%<---
      Iteration: 1
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedByInterruptException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      Iteration: 2
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedByInterruptException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      Iteration: 3
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedByInterruptException (expected)
      class java.nio.channels.AsynchronousCloseException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      Iteration: 4
      class java.nio.channels.AsynchronousCloseException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedByInterruptException (expected)
      Iteration: 5
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedByInterruptException (expected)
      Iteration: 6
      class java.nio.channels.ClosedByInterruptException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      Iteration: 7
      class java.nio.channels.AsynchronousCloseException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedByInterruptException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      Iteration: 8
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.AsynchronousCloseException (expected)
      class java.nio.channels.ClosedByInterruptException (expected)
      Iteration: 9
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedByInterruptException (expected)
      Iteration: 10
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedByInterruptException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      ---%<---
      ACTUAL -
      Usually just

      ---%<---
      Iteration: 1
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      ---%<---

      before a hang. Occasionally it gets through a few iterations before hanging:

      ---%<---
      Iteration: 1
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedByInterruptException (expected)
      class java.nio.channels.AsynchronousCloseException (expected)
      Iteration: 2
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.ClosedByInterruptException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      Iteration: 3
      class java.nio.channels.ClosedChannelException (expected)
      class java.nio.channels.AsynchronousCloseException (expected)
      class java.nio.channels.ClosedChannelException (expected)
      ---%<---

      ERROR MESSAGES/STACK TRACES THAT OCCUR :
      Typical thread dump (redacted):

      ---%<---
      "Mapper" prio=10 tid=0x00007f4f2c0e3000 nid=0x3788 waiting for monitor entry [0x00007f4f105f7000]
         java.lang.Thread.State: BLOCKED (on object monitor)
      at java.lang.Thread.blockedOn(Thread.java:240)
      - waiting to lock <0x0000000746002c10> (a java.lang.Object)
      at java.lang.System$2.blockedOn(System.java:1192)
      at java.nio.channels.spi.AbstractInterruptibleChannel.blockedOn(AbstractInterruptibleChannel.java:211)
      at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:198)
      at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:312)
      - locked <0x0000000746002ba8> (a java.lang.Object)
      at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:849)
      at InterruptDeadlock$Mapper.run(InterruptDeadlock.java:17)
      "main" prio=10 tid=0x00007f4f2c009800 nid=0x3778 in Object.wait() [0x00007f4f33ce9000]
         java.lang.Thread.State: WAITING (on object monitor)
      at java.lang.Object.wait(Native Method)
      - waiting on <0x0000000746002b40> (a sun.nio.ch.NativeThreadSet)
      at java.lang.Object.wait(Object.java:503)
      at sun.nio.ch.NativeThreadSet.signalAndWait(NativeThreadSet.java:102)
      - locked <0x0000000746002b40> (a sun.nio.ch.NativeThreadSet)
      at sun.nio.ch.FileChannelImpl.implCloseChannel(FileChannelImpl.java:119)
      at java.nio.channels.spi.AbstractInterruptibleChannel$1.interrupt(AbstractInterruptibleChannel.java:165)
      - locked <0x0000000746002ae8> (a java.lang.Object)
      at java.lang.Thread.interrupt(Thread.java:958)
      - locked <0x0000000746002c10> (a java.lang.Object)
      at InterruptDeadlock.main(InterruptDeadlock.java:43)
      ---%<---

      Also possible:

      ---%<---
      "Mapper" prio=10 tid=0x00007f9bec0c6800 nid=0x3722 in Object.wait() [0x00007f9be2322000]
         java.lang.Thread.State: WAITING (on object monitor)
      at java.lang.Object.wait(Native Method)
      - waiting on <0x000000074603d950> (a sun.nio.ch.NativeThreadSet)
      at java.lang.Object.wait(Object.java:503)
      at sun.nio.ch.NativeThreadSet.signalAndWait(NativeThreadSet.java:102)
      - locked <0x000000074603d950> (a sun.nio.ch.NativeThreadSet)
      at sun.nio.ch.FileChannelImpl.implCloseChannel(FileChannelImpl.java:119)
      at java.nio.channels.spi.AbstractInterruptibleChannel$1.interrupt(AbstractInterruptibleChannel.java:165)
      - locked <0x000000074603d8c0> (a java.lang.Object)
      at java.nio.channels.spi.AbstractInterruptibleChannel.begin(AbstractInterruptibleChannel.java:173)
      at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:302)
      - locked <0x000000074603d968> (a java.lang.Object)
      at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:849)
      at InterruptDeadlock$Mapper.run(InterruptDeadlock.java:17)
      "main" prio=10 tid=0x00007f9bec009800 nid=0x3715 waiting for monitor entry [0x00007f9bf3767000]
         java.lang.Thread.State: BLOCKED (on object monitor)
      at java.nio.channels.spi.AbstractInterruptibleChannel.close(AbstractInterruptibleChannel.java:112)
      - waiting to lock <0x000000074603d8c0> (a java.lang.Object)
      at InterruptDeadlock.main(InterruptDeadlock.java:48)
      ---%<---

      or

      ---%<---
      "Mapper" prio=10 tid=0x00007f98c00db000 nid=0x3960 waiting for monitor entry [0x00007f98b8c0b000]
         java.lang.Thread.State: BLOCKED (on object monitor)
      at java.lang.Thread.blockedOn(Thread.java:240)
      - waiting to lock <0x000000074601cb80> (a java.lang.Object)
      at java.lang.System$2.blockedOn(System.java:1192)
      at java.nio.channels.spi.AbstractInterruptibleChannel.blockedOn(AbstractInterruptibleChannel.java:211)
      at java.nio.channels.spi.AbstractInterruptibleChannel.begin(AbstractInterruptibleChannel.java:170)
      at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:302)
      - locked <0x000000074601ca78> (a java.lang.Object)
      at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:849)
      at InterruptDeadlock$Mapper.run(InterruptDeadlock.java:17)
      "Mapper" prio=10 tid=0x00007f98c00c8000 nid=0x395d waiting for monitor entry [0x00007f98b8f0e000]
         java.lang.Thread.State: BLOCKED (on object monitor)
      at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:299)
      - waiting to lock <0x000000074601ca78> (a java.lang.Object)
      at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:849)
      at InterruptDeadlock$Mapper.run(InterruptDeadlock.java:17)
      "main" prio=10 tid=0x00007f98c0009800 nid=0x3950 in Object.wait() [0x00007f98c633c000]
         java.lang.Thread.State: WAITING (on object monitor)
      at java.lang.Object.wait(Native Method)
      - waiting on <0x000000074601ca10> (a sun.nio.ch.NativeThreadSet)
      at java.lang.Object.wait(Object.java:503)
      at sun.nio.ch.NativeThreadSet.signalAndWait(NativeThreadSet.java:102)
      - locked <0x000000074601ca10> (a sun.nio.ch.NativeThreadSet)
      at sun.nio.ch.FileChannelImpl.implCloseChannel(FileChannelImpl.java:119)
      at java.nio.channels.spi.AbstractInterruptibleChannel$1.interrupt(AbstractInterruptibleChannel.java:165)
      - locked <0x000000074601c9b8> (a java.lang.Object)
      at java.lang.Thread.interrupt(Thread.java:958)
      - locked <0x000000074601cb80> (a java.lang.Object)
      at InterruptDeadlock.main(InterruptDeadlock.java:43)
      ---%<---

      or

      ---%<---
      "Mapper" prio=10 tid=0x00007ff2a80d9000 nid=0x3994 waiting for monitor entry [0x00007ff29f3ce000]
         java.lang.Thread.State: BLOCKED (on object monitor)
      at java.lang.Thread.blockedOn(Thread.java:240)
      - waiting to lock <0x0000000746041840> (a java.lang.Object)
      at java.lang.System$2.blockedOn(System.java:1192)
      at java.nio.channels.spi.AbstractInterruptibleChannel.blockedOn(AbstractInterruptibleChannel.java:211)
      at java.nio.channels.spi.AbstractInterruptibleChannel.begin(AbstractInterruptibleChannel.java:170)
      at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:302)
      - locked <0x0000000746041a28> (a java.lang.Object)
      at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:849)
      at InterruptDeadlock$Mapper.run(InterruptDeadlock.java:17)
      "Mapper" prio=10 tid=0x00007ff2a80d7000 nid=0x3993 waiting for monitor entry [0x00007ff29f4cf000]
         java.lang.Thread.State: BLOCKED (on object monitor)
      at java.nio.channels.spi.AbstractInterruptibleChannel$1.interrupt(AbstractInterruptibleChannel.java:160)
      - waiting to lock <0x0000000746041988> (a java.lang.Object)
      at java.nio.channels.spi.AbstractInterruptibleChannel.begin(AbstractInterruptibleChannel.java:173)
      at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:845)
      at InterruptDeadlock$Mapper.run(InterruptDeadlock.java:17)
      "main" prio=10 tid=0x00007ff2a8009800 nid=0x3981 in Object.wait() [0x00007ff2b0bb9000]
         java.lang.Thread.State: WAITING (on object monitor)
      at java.lang.Object.wait(Native Method)
      - waiting on <0x00000007460419e0> (a sun.nio.ch.NativeThreadSet)
      at java.lang.Object.wait(Object.java:503)
      at sun.nio.ch.NativeThreadSet.signalAndWait(NativeThreadSet.java:102)
      - locked <0x00000007460419e0> (a sun.nio.ch.NativeThreadSet)
      at sun.nio.ch.FileChannelImpl.implCloseChannel(FileChannelImpl.java:119)
      at java.nio.channels.spi.AbstractInterruptibleChannel$1.interrupt(AbstractInterruptibleChannel.java:165)
      - locked <0x0000000746041988> (a java.lang.Object)
      at java.lang.Thread.interrupt(Thread.java:958)
      - locked <0x0000000746041840> (a java.lang.Object)
      at InterruptDeadlock.main(InterruptDeadlock.java:43)
      ---%<---

      REPRODUCIBILITY :
      This bug can be reproduced rarely.

      ---------- BEGIN SOURCE ----------
      Derived from the test case for #8012019:

      ---%<---
      import java.nio.ByteBuffer;
      import java.nio.channels.ClosedChannelException;
      import java.nio.channels.FileChannel;
      import java.nio.file.Path;
      import java.nio.file.Paths;
      import static java.nio.file.StandardOpenOption.*;
      public class InterruptDeadlock {
          static class Mapper extends Thread {
              final FileChannel fc;
              Mapper(FileChannel fc) {
                  super("Mapper");
                  this.fc = fc;
              }
              @Override public void run() {
                  try {
                      for (;;) {
                          fc.map(FileChannel.MapMode.READ_ONLY, 0, 1);
                          System.gc();
                      }
                  } catch (ClosedChannelException x) {
                      System.out.println(x.getClass() + " (expected)");
                  } catch (Exception unexpected) {
                      unexpected.printStackTrace();
                      System.exit(1);
                  }
              }
          }
          private static final int MAPPER_COUNT = 4;
          public static void main(String[] args) throws Exception {
              Path file = Paths.get("data.txt");
              try (FileChannel fc = FileChannel.open(file, CREATE, TRUNCATE_EXISTING, WRITE)) {
                  fc.write(ByteBuffer.wrap(new byte[1]));
              }
              Mapper[] mappers = new Mapper[MAPPER_COUNT];
              for (int i = 1; i <= 10; i++) {
                  System.out.format("Iteration: %s%n", i);
                  try (FileChannel fc = FileChannel.open(file)) {
                      for (int j = 0; j < MAPPER_COUNT; j++) {
                          (mappers[j] = new Mapper(fc)).start();
                      }
                      Thread.sleep(100);
                      for (Mapper r: mappers) {
                          r.interrupt();
                      }
                      for (Mapper r: mappers) {
                          r.join(10000);
                      }
                  }
              }
          }
      }
      ---%<---
      ---------- END SOURCE ----------

      CUSTOMER SUBMITTED WORKAROUND :
      None known, other than upgrading to Java 8.

            Unassigned Unassigned
            webbuggrp Webbug Group
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved: