[
https://issues.apache.org/jira/browse/KAFKA-666?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Neha Narkhede updated KAFKA-666:
--------------------------------
Description:
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
was:
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: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 20:59:22,611] TRACE Completed request with correlation id 0 and
client replica-fetcher-host_172.20.72.48-port_9092: FetchRequest:3301,
queueTime:1, localTime:3118, remoteTime:181, 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: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
> 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
> Reporter: Neha Narkhede
> Priority: Critical
> Labels: replication-performance
> Fix For: 0.8
>
>
> 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 is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira