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

[Vyom Tewari]

On Fri, 5 May 2023 11:20:35 GMT, olivergillespie <duke at openjdk.org> wrote:

>> 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

Looks OK to me.

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

PR Review: https://git.openjdk.org/jdk/pull/13798#pullrequestreview-1415698383