-
Bug
-
Resolution: Fixed
-
P4
-
13, 17, 20, 21
-
b22
Issue | Fix Version | Assignee | Priority | Status | Resolution | Resolved In Build |
---|---|---|---|---|---|---|
JDK-8308418 | 20.0.2 | Daniel Fuchs | P4 | Resolved | Fixed | b06 |
JDK-8308717 | 17.0.9-oracle | Weibing Xiao | P4 | Resolved | Fixed | b01 |
JDK-8308280 | 17.0.8 | Aleksey Shipilev | P4 | Resolved | Fixed | b04 |
One of our migrations to JDK 17 revealed an issue in
```
import java.io.*;
import java.net.*;
public class ReadSingle {
public static void main(String[] args) throws Exception {
Socket s = new Socket("shipilev.net", 443);
s.setSoTimeout(1);
s.getOutputStream().write(1);
InputStream is = s.getInputStream();
System.out.println("Starting single byte read");
is.read();
}
}
```
With current JDK:
```
% strace -f build/linux-x86_64-server-release/images/jdk/bin/java ReadSingle.java 2>&1 | grep poll
[pid 35427] poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=4, revents=POLLIN}])
[pid 35427] poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 35427] poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout)
```
With JDK 17:
```
% strace -f ../shipilev-jdk17u-dev/build/linux-x86_64-server-release/images/jdk/bin/java ReadSingle.java 2>&1 | grep poll
[pid 34344] poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
[pid 34344] poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=4, revents=POLLIN}])
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
[pid 34344] poll([{fd=4, events=POLLIN}], 1, 0) = 0 (Timeout)
```
With JDK 17 and `-Djdk.net.usePlainSocketImpl`:
```
% strace -f ../shipilev-jdk17u-dev/build/linux-x86_64-server-release/images/jdk/bin/java -Djdk.net.usePlainSocketImpl ReadSingle.java 2>&1 | grep poll
[pid 34653] poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=4, revents=POLLIN}])
[pid 34653] poll([{fd=4, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
[pid 34653] poll([{fd=6, events=POLLIN|POLLERR}], 1, 1) = 0 (Timeout)
```
This looks like a regression since
```
private void park(FileDescriptor fd, int event, long nanos) throws IOException {
Thread t = Thread.currentThread();
if (t.isVirtual()) {
...
} else {
long millis;
if (nanos == 0) {
millis = -1;
} else {
millis = NANOSECONDS.toMillis(nanos); // <--- here
}
Net.poll(fd, event, millis);
}
}
```
Note it would happen in nearly all cases where we timeout the read, as there will be a hot loop in the final sub-millisecond section which will truncate to zero millis. The read timeout would be more likely with smaller timeouts, but larger timeouts are also affected by this.
This looks similar to
- backported by
-
JDK-8308280 Socket input stream read burns CPU cycles with back-to-back poll(0) calls
- Resolved
-
JDK-8308418 Socket input stream read burns CPU cycles with back-to-back poll(0) calls
- Resolved
-
JDK-8308717 Socket input stream read burns CPU cycles with back-to-back poll(0) calls
- Resolved
- relates to
-
JDK-8221481 Reimplement the Legacy Socket API
- Resolved
- links to
-
Commit openjdk/jdk17u-dev/76108622
-
Commit openjdk/jdk20u/23024545
-
Commit openjdk/jdk/73ac7105
-
Review openjdk/jdk17u-dev/1341
-
Review openjdk/jdk20u/80
-
Review openjdk/jdk/13798