Details
-
Bug
-
Status: Resolved
-
P4
-
Resolution: Fixed
-
13, 17, 20, 21
-
b22
Backports
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 |
Description
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
Attachments
Issue Links
- 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