Even more instrumentation

src/Common/CurrentMetrics.cpp

@@ -76,6 +76,7 @@
     M(ActiveAsyncDrainedConnections, "Number of active connections drained asynchronously.") \
     M(SyncDrainedConnections, "Number of connections drained synchronously.") \
     M(ActiveSyncDrainedConnections, "Number of active connections drained synchronously.") \
+    M(AsynchronousReadWait, "Number of threads waiting for asynchronous read.") \
 
 namespace CurrentMetrics
 {

src/Common/ProfileEvents.cpp

@@ -258,6 +258,8 @@
     M(ThreadPoolReaderPageCacheMiss, "Number of times the read inside ThreadPoolReader was not done from page cache and was hand off to thread pool.") \
     M(ThreadPoolReaderPageCacheMissBytes, "Number of bytes read inside ThreadPoolReader when read was not done from page cache and was hand off to thread pool.") \
     M(ThreadPoolReaderPageCacheMissElapsedMicroseconds, "Time spent reading data inside the asynchronous job in ThreadPoolReader - when read was not done from page cache.") \
+    \
+    M(AsynchronousReadWaitMicroseconds, "Time spent in waiting for asynchronous reads.") \
 
 
 namespace ProfileEvents

src/IO/AsynchronousReadBufferFromFileDescriptor.cpp

@@ -9,6 +9,17 @@
 #include <IO/WriteHelpers.h>
 
 
+namespace ProfileEvents
+{
+    extern const Event AsynchronousReadWaitMicroseconds;
+}
+
+namespace CurrentMetrics
+{
+    extern const Metric AsynchronousReadWait;
+}
+
+
 namespace DB
 {
 
@@ -54,7 +65,14 @@ bool AsynchronousReadBufferFromFileDescriptor::nextImpl()
     {
         /// Read request already in flight. Wait for its completion.
 
-        auto size = prefetch_future.get();
+        size_t size = 0;
+        {
+            Stopwatch watch;
+            CurrentMetrics::Increment metric_increment{CurrentMetrics::AsynchronousReadWait};
+            size = prefetch_future.get();
+            ProfileEvents::increment(ProfileEvents::AsynchronousReadWaitMicroseconds, watch.elapsedMicroseconds());
+        }
+
         prefetch_future = {};
         file_offset_of_buffer_end += size;