You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@kafka.apache.org by "Neha Narkhede (JIRA)" <ji...@apache.org> on 2014/02/01 21:12:08 UTC
[jira] [Resolved] (KAFKA-666) Fetch requests from the replicas take
several seconds to complete on the leader
[ https://issues.apache.org/jira/browse/KAFKA-666?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Neha Narkhede resolved KAFKA-666.
---------------------------------
Resolution: Incomplete
Fix Version/s: (was: 0.8.1)
Need more information to understand the issue
> Fetch requests from the replicas take several seconds to complete on the leader
> -------------------------------------------------------------------------------
>
> Key: KAFKA-666
> URL: https://issues.apache.org/jira/browse/KAFKA-666
> Project: Kafka
> Issue Type: Bug
> Affects Versions: 0.8.0
> Reporter: Neha Narkhede
> Priority: Critical
> Labels: replication-performance
>
> I've seen that fetch requests from the replicas take several seconds to complete. The nature of the latency breakdown is different, sometimes they spend too long sitting in the request/response queue, sometimes the local/remote time is too large -
> [2012-12-07 20:14:51,233] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.45-port_9092: FetchRequest:9967, queueTime:0, localTime:4, remoteTime:9963, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 20:14:51,236] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.45-port_9092: FetchRequest:9967, queueTime:1, localTime:3, remoteTime:9963, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 20:14:51,239] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.45-port_9092: FetchRequest:9966, queueTime:0, localTime:2, remoteTime:9964, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 20:16:07,643] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.45-port_9092: FetchRequest:9996, queueTime:1, localTime:2, remoteTime:9992, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 20:16:07,645] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.45-port_9092: FetchRequest:9999, queueTime:0, localTime:4, remoteTime:9994, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 20:59:22,424] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3502, queueTime:1, localTime:1, remoteTime:3500, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:13:35,042] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3981, queueTime:0, localTime:1, remoteTime:3979, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:13:35,042] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4095, queueTime:1, localTime:6, remoteTime:4088, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:13:57,254] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4116, queueTime:1, localTime:1, remoteTime:4113, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:13:57,300] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3844, queueTime:1, localTime:3795, remoteTime:48, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:14:19,645] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4239, queueTime:1, localTime:1, remoteTime:4236, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:14:19,689] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3977, queueTime:3931, localTime:8, remoteTime:38, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:23:58,427] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3940, queueTime:1, localTime:1, remoteTime:3938, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:23:58,435] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3858, queueTime:1, localTime:6, remoteTime:3851, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:24:21,575] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4037, queueTime:0, localTime:1, remoteTime:4036, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:24:21,583] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3962, queueTime:1, localTime:4, remoteTime:3956, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:24:43,965] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4294, queueTime:1, localTime:1, remoteTime:4292, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:24:44,013] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3962, queueTime:1, localTime:3919, remoteTime:41, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:25:06,157] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4587, queueTime:1, localTime:1, remoteTime:4585, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:25:06,162] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4276, queueTime:1, localTime:6, remoteTime:4268, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:25:28,943] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3986, queueTime:1, localTime:1, remoteTime:3984, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:25:28,953] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3940, queueTime:3929, localTime:6, remoteTime:5, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:25:51,374] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4319, queueTime:0, localTime:1, remoteTime:4318, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:25:51,374] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4328, queueTime:1, localTime:6, remoteTime:4320, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:26:13,934] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3949, queueTime:0, localTime:1, remoteTime:3948, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:26:13,934] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4412, queueTime:1, localTime:6, remoteTime:4404, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:26:36,268] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4227, queueTime:0, localTime:2, remoteTime:4224, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:26:36,268] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4573, queueTime:1, localTime:6, remoteTime:4565, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:26:59,503] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3996, queueTime:0, localTime:2, remoteTime:3994, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:26:59,504] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4457, queueTime:1, localTime:4, remoteTime:504, sendTime:3948 (kafka.network.RequestChannel$)
> [2012-12-07 21:27:21,624] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4010, queueTime:0, localTime:1, remoteTime:4009, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:27:21,704] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4036, queueTime:3955, localTime:8, remoteTime:72, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:27:42,374] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4429, queueTime:1, localTime:1, remoteTime:4427, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:27:42,381] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4290, queueTime:1, localTime:4, remoteTime:4284, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:28:03,198] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4229, queueTime:0, localTime:1, remoteTime:4228, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:28:25,540] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4054, queueTime:1, localTime:1, remoteTime:4052, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:28:25,540] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4203, queueTime:1, localTime:5, remoteTime:4196, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:28:45,923] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4289, queueTime:0, localTime:1, remoteTime:4288, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:28:45,930] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4004, queueTime:1, localTime:4002, remoteTime:0, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:29:07,457] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4438, queueTime:0, localTime:1, remoteTime:4436, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:29:07,463] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4028, queueTime:1, localTime:6, remoteTime:4020, sendTime:1 (kafka.network.RequestChannel$)
> [2012-12-07 21:29:29,017] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4463, queueTime:0, localTime:1, remoteTime:4462, sendTime:0 (kafka.network.RequestChannel$)
> [2012-12-07 21:29:29,018] TRACE Completed request with correlation id 0 and client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:4524, queueTime:1, localTime:6, remoteTime:4515, sendTime:2 (kafka.network.RequestChannel$)
> This is probably a performance issue in the replica fetch code path on the leader
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)