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.