Flaky 01290_max_execution_speed_distributed (TOO_SLOW) #71366
Description
test fails with executeQuery: Code: 160. DB::Exception: Estimated query execution time (11653.719987120001 seconds) is too long. Maximum: 600. Estimated rows to process: 869678: While executing MergeTreeSelect(pool: ReadPool, algorithm: Thread). (TOO_SLOW), usually on s3 run.
My assumption was that it's because of reading from s3 is slower, however, checked profile events, no remote reads:
ProfileEvents
{'Query':1,'SelectQuery':1,'InitialQuery':1,'QueriesWithSubqueries':1,'SelectQueriesWithSubqueries':1,'SelectQueriesWithPrimaryKeyUsage':1,'FileOpen':7,'ReadBufferFromFileDescriptorRead':9,'ReadBufferFromFileDescriptorReadBytes':76724,'ReadCompressedBytes':76468,'CompressedReadBufferBlocks':4,'CompressedReadBufferBytes':138163,'OpenedFileCacheHits':2,'OpenedFileCacheMisses':7,'OpenedFileCacheMicroseconds':16,'IOBufferAllocs':13,'IOBufferAllocBytes':215898,'FunctionExecute':9,'MarkCacheHits':5,'MarkCacheMisses':1,'CreatedReadBufferOrdinary':9,'DiskReadElapsedMicroseconds':37,'NetworkReceiveElapsedMicroseconds':15,'NetworkSendElapsedMicroseconds':436,'NetworkSendBytes':14859,'GlobalThreadPoolJobs':14,'LocalThreadPoolExpansions':13,'LocalThreadPoolShrinks':13,'LocalThreadPoolThreadCreationMicroseconds':46,'LocalThreadPoolJobs':20,'LocalReadThrottlerBytes':76468,'SelectedParts':12,'SelectedPartsTotal':12,'SelectedRanges':12,'SelectedMarks':121,'SelectedMarksTotal':121,'RowsReadByPrewhereReaders':200,'WaitMarksLoadMicroseconds':432085,'BackgroundLoadingMarksTasks':6,'LoadedMarksCount':9,'LoadedMarksMemoryBytes':144,'ContextLock':54,'RWLockAcquiredReadLocks':1,'PartsLockHoldMicroseconds':21,'RealTimeMicroseconds':6039066,'UserTimeMicroseconds':7266,'SystemTimeMicroseconds':3840,'SoftPageFaults':3,'OSCPUWaitMicroseconds':1869,'OSCPUVirtualTimeMicroseconds':11065,'OSWriteBytes':28672,'OSReadChars':75776,'OSWriteChars':35840,'QueryProfilerRuns':7,'CachedReadBufferReadFromCacheHits':4,'CachedReadBufferReadFromCacheMicroseconds':32,'CachedReadBufferReadFromCacheBytes':76468,'CachedReadBufferCreateBufferMicroseconds':76,'FilesystemCacheGetOrSetMicroseconds':20,'FileSegmentWaitMicroseconds':905834,'FileSegmentUseMicroseconds':1,'FileSegmentFailToIncreasePriority':4,'FilesystemCacheHoldFileSegments':4,'FilesystemCacheUnusedHoldFileSegments':1,'RemoteFSPrefetches':2,'RemoteFSPrefetchedReads':2,'RemoteFSPrefetchedBytes':73436,'RemoteFSUnprefetchedReads':3,'RemoteFSUnprefetchedBytes':3032,'RemoteFSBuffers':4,'ThreadpoolReaderTaskMicroseconds':906099,'ThreadpoolReaderReadBytes':76468,'ThreadpoolReaderSubmit':7,'ThreadpoolReaderSubmitReadSynchronously':1,'ThreadpoolReaderSubmitReadSynchronouslyBytes':37526,'ThreadpoolReaderSubmitReadSynchronouslyMicroseconds':24,'ThreadpoolReaderSubmitLookupInCacheMicroseconds':27,'FileSegmentWaitReadBufferMicroseconds':905949,'AsynchronousRemoteReadWaitMicroseconds':611196,'SynchronousRemoteReadWaitMicroseconds':294975,'LogTrace':76,'LogDebug':5,'InterfaceNativeSendBytes':14859,'ConcurrencyControlSlotsGranted':1,'ConcurrencyControlSlotsDelayed':15,'ConcurrencyControlSlotsAcquired':1,'ConcurrencyControlQueriesDelayed':1}
Details
Lets first add a bit more info to error message: #71365