RFR: 8307425 - Socket input stream read burns CPU cycles with back-to-back poll(0) calls [v3]

[olivergillespie]

> As described in https://bugs.openjdk.org/browse/JDK-8307425, fix two places where nanoseconds are rounded *down* to milliseconds, leading to expensive tight poll/read loops in some scenarios.
> 
> 
> import java.io.InputStream;
> import java.net.Socket;
> 
> public class ReadSingle {
>     public static void main(String[] args) throws Exception {
>         Socket s = new Socket("httpbin.org", 443);
>         s.setSoTimeout(2); s.getOutputStream().write(1);
>         InputStream is = s.getInputStream();
>         System.out.println("Starting single byte read");
>         is.read();
>         s.close();
>     }
> }
> 
> 
> Before (first poll with 1ms timeout, then tight loop of poll/read for the remainder):
> 
> strace -ftT -e trace=poll,read java ReadSingle
> ...
> Starting single byte read
> [pid 20963] 10:38:04 read(5, 0x7fd14c191cb0, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000017>
> [pid 20963] 10:38:04 poll([{fd=5, events=POLLIN}], 1, 1) = 0 (Timeout) <0.001071>
>                                         1ms timeout --^
> [pid 20963] 10:38:04 read(5, 0x7fd14c191cb0, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000014>
> [pid 20963] 10:38:04 poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout) <0.000013>
>                     0ms timeout (tight loop begins) --^
> [pid 20963] 10:38:04 read(5, 0x7fd14c191cb0, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000013>
> [pid 20963] 10:38:04 poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout) <0.000013>
> [pid 20963] 10:38:04 read(5, 0x7fd14c191cb0, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000013>
> [pid 20963] 10:38:04 poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout) <0.000013>
> [pid 20963] 10:38:04 read(5, 0x7fd14c191cb0, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000013>
> [pid 20963] 10:38:04 poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout) <0.000014>
> [pid 20963] 10:38:04 read(5, 0x7fd14c191cb0, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000013>
> [pid 20963] 10:38:04 poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout) <0.000013>
> [pid 20963] 10:38:04 read(5, 0x7fd14c191cb0, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000013>
> [pid 20963] 10:38:04 poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout) <0.000013>
> [pid 20963] 10:38:04 read(5, 0x7fd14c191cb0, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000014>
> [pid 20963] 10:38:04 poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout) <0.000014>
> [pid 20963] 10:38:04 read(5, 0x7fd14c191cb0, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000014>
> [pid 20963] 10:38:04 poll([{fd=5, events=POLLIN}], 1, 0) = 0 (Timeout) <0.000014>
> [pid 20963] 10:38:04 read(5, 0x7fd14c191cb0, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000013>
> Exception in thread "main" java.net.SocketTimeoutException: Read timed out
> 	at java.base/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:273)
> 	at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:299)
> 	at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:341)
> 	at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:791)
> 	at java.base/java.net.Socket$SocketInputStream.read(Socket.java:1099)
> 	at java.base/java.net.Socket$SocketInputStream.read(Socket.java:1093)
> 	at ReadSingle.main(ReadSingle.java:10)
> 
> 
> After (single poll with 2ms timeout):
> 
> strace -ftT -e trace=poll,read java ReadSingle
> ...
> Starting single byte read
> [pid 21831] 10:39:13 read(5, 0x7fae1c199a10, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000014>
> [pid 21831] 10:39:13 poll([{fd=5, events=POLLIN}], 1, 2) = 0 (Timeout) <0.002072>
>                                         2ms timeout --^
> [pid 21831] 10:39:13 read(5, 0x7fae1c199a10, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000012>
> Exception in thread "main" java.net.SocketTimeoutException: Read timed out
> 	at java.base/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:279)
> 	at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:305)
> 	at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:347)
> 	at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:797)
> 	at java.base/java.net.Socket$SocketInputStream.read(Socket.java:1099)
> 	at java.base/java.net.Socket$SocketInputStream.read(Socket.java:1093)
> 	at ReadSingle.main(ReadSingle.java:10)

olivergillespie has updated the pull request incrementally with one additional commit since the last revision:

  Update copyright

-------------

Changes:
  - all: https://git.openjdk.org/jdk/pull/13798/files
  - new: https://git.openjdk.org/jdk/pull/13798/files/0bbd890d..7c551e21

Webrevs:
 - full: https://webrevs.openjdk.org/?repo=jdk&pr=13798&range=02
 - incr: https://webrevs.openjdk.org/?repo=jdk&pr=13798&range=01-02

  Stats: 1 line in 1 file changed: 0 ins; 0 del; 1 mod
  Patch: https://git.openjdk.org/jdk/pull/13798.diff
  Fetch: git fetch https://git.openjdk.org/jdk.git pull/13798/head:pull/13798

PR: https://git.openjdk.org/jdk/pull/13798