为何ClickHouse中部分查询耗时超过max_execution_time设置值？

问题背景 #

通过clickhouse_sqlalchemy连接ClickHouse时已设置max_execution_time=10，但从system.processes中查到某查询的elapsed已达22秒仍未被终止，手动执行该查询仅需0.135秒。相关查询信息如下：

select elapsed, query, ProfileEvents, Settings from system.processes where elapsed>10\G;

输出结果：

Row 1:
──────
elapsed:              22.066440963
query:                SELECT * FROM A WHERE toDate(A."Time") = '2023-05-26' FORMAT TabSeparatedWithNamesAndTypes
ProfileEvents:        {'Query':1,'SelectQuery':1,'ReadBufferFromFileDescriptorReadBytes':528770,'ReadCompressedBytes':528319,'CompressedReadBufferBlocks':48,'CompressedReadBufferBytes':3044524,'OpenedFileCacheHits':14,'IOBufferAllocs':37,'IOBufferAllocBytes':12735376,'FunctionExecute':32,'MarkCacheHits':14,'CreatedReadBufferOrdinary':14,'DiskReadElapsedMicroseconds':358,'NetworkReceiveElapsedMicroseconds':9948,'NetworkReceiveBytes':1122,'SelectedParts':2,'SelectedRanges':2,'SelectedMarks':5,'SelectedRows':29454,'SelectedBytes':4880428,'WaitMarksLoadMicroseconds':59,'ContextLock':64,'RWLockAcquiredReadLocks':2,'RealTimeMicroseconds':9852,'UserTimeMicroseconds':6895,'SystemTimeMicroseconds':134,'SoftPageFaults':1108,'OSCPUVirtualTimeMicroseconds':7024,'OSWriteBytes':4096,'OSReadChars':542614,'OSWriteChars':4470,'CannotWriteToWriteBufferDiscard':90,'QueryProfilerRuns':88,'ThreadPoolReaderPageCacheMiss':15,'ThreadPoolReaderPageCacheMissBytes':528770,'ThreadPoolReaderPageCacheMissElapsedMicroseconds':358}
Settings:             {'max_query_size':'8589934592','receive_timeout':'10','send_timeout':'10','load_balancing':'random','http_send_timeout':'10','http_receive_timeout':'10','max_execution_time':'10','readonly':'2','max_memory_usage':'64424509440'}

可能的原因及验证方向 #

1. 网络/客户端接收延迟拉长了elapsed统计 #

ClickHouse的elapsed字段统计的是从查询启动到当前的总时长，包含查询执行和结果传输到客户端的全流程。从ProfileEvents中的RealTimeMicroseconds（9852微秒，约0.01秒）可以看出，服务端的查询执行本身已经快速完成，后续的22秒耗时实际是结果在网络传输或客户端接收处理阶段的延迟。这种情况下，服务端不会触发max_execution_time的终止逻辑，因为查询执行阶段早已结束。

2. 并发资源竞争导致查询等待 #

如果查询执行时集群处于高负载状态（比如线程池满、磁盘IO排队），该查询可能会在等待资源分配的过程中被阻塞，导致elapsed包含等待时间。而手动执行时集群负载较低，所以查询能快速完成。可以通过system.metrics查看当时的ThreadsActive、DiskReadBytes等指标，确认是否存在资源竞争。

3. 客户端配置需确认参数传递有效性 #

虽然system.processes显示服务端已接收max_execution_time=10，仍需确认clickhouse_sqlalchemy的配置是否正确传递了参数。比如是否通过连接URL的查询参数设置：

from sqlalchemy import create_engine
engine = create_engine('clickhouse://user:password@host:port/database?max_execution_time=10')

另外，客户端的receive_timeout等设置仅控制客户端侧的等待时间，不会影响服务端的查询执行超时逻辑。

验证建议 #

• 重点关注ProfileEvents中的RealTimeMicroseconds值，确认服务端实际执行时长是否远小于max_execution_time，以此区分是执行延迟还是传输延迟。
• 检查客户端（clickhouse_sqlalchemy）的结果处理逻辑，是否存在阻塞或慢处理的情况，导致结果接收缓慢。
• 监控集群在问题查询执行时的负载指标，排查资源竞争问题。

内容的提问来源于stack exchange，提问作者Stygian Smash