[
https://issues.apache.org/jira/browse/KAFKA-1352?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13967265#comment-13967265
]
Guozhang Wang commented on KAFKA-1352:
--------------------------------------
The proposed RB was mainly on reducing redundant connection exceptions logs on
both server and producer with one peer server in the cluster is offline. I also
did the experiments Neha suggested, and here are the results (log4j level set
to INFO):
1. Broker restart with no topics in the cluster:
Server:
{quote}
[2014-04-11 15:17:41,450] INFO Verifying properties
(kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,490] INFO Property broker.id is overridden to 0
(kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,490] INFO Property log.cleaner.enable is overridden to
false (kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,490] INFO Property log.dirs is overridden to
/tmp/kafka-logs (kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,490] INFO Property log.retention.check.interval.ms is
overridden to 60000 (kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,490] INFO Property log.retention.hours is overridden to
168 (kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,491] INFO Property log.segment.bytes is overridden to
536870912 (kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,491] INFO Property num.io.threads is overridden to 8
(kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,491] INFO Property num.network.threads is overridden to 2
(kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,491] INFO Property num.partitions is overridden to 2
(kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,491] INFO Property port is overridden to 9092
(kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,491] INFO Property socket.receive.buffer.bytes is
overridden to 1048576 (kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,492] INFO Property socket.request.max.bytes is overridden
to 104857600 (kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,492] INFO Property socket.send.buffer.bytes is overridden
to 1048576 (kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,492] INFO Property zookeeper.connect is overridden to
localhost:2181 (kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,492] INFO Property zookeeper.connection.timeout.ms is
overridden to 1000000 (kafka.utils.VerifiableProperties)
[2014-04-11 15:17:41,507] INFO [Kafka Server 0], starting
(kafka.server.KafkaServer)
[2014-04-11 15:17:41,509] INFO [Kafka Server 0], Connecting to zookeeper on
localhost:2181 (kafka.server.KafkaServer)
[2014-04-11 15:17:41,520] INFO Starting ZkClient event thread.
(org.I0Itec.zkclient.ZkEventThread)
[2014-04-11 15:17:41,526] INFO Client
environment:zookeeper.version=3.3.3-1203054, built on 11/17/2011 05:47 GMT
(org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,526] INFO Client
environment:host.name=guwang-ld2.linkedin.biz (org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,526] INFO Client environment:java.version=1.6.0_38-ea
(org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,526] INFO Client environment:java.vendor=Sun Microsystems
Inc. (org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,526] INFO Client
environment:java.home=/usr/java/jdk1.6.0_38/jre (org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,526] INFO Client
environment:java.class.path=:/home/guwang/Workspace/apache/kafka/bin/../core/build/dependant-libs-2.8.0/jopt-simple-3.2.jar:/home/guwang/Workspace/apache/kafka/bin/../core/build/dependant-libs-2.8.0/log4j-1.2.15.jar:/home/guwang/Workspace/apache/kafka/bin/../core/build/dependant-libs-2.8.0/metrics-core-2.2.0.jar:/home/guwang/Workspace/apache/kafka/bin/../core/build/dependant-libs-2.8.0/scala-library-2.8.0.jar:/home/guwang/Workspace/apache/kafka/bin/../core/build/dependant-libs-2.8.0/slf4j-api-1.7.6.jar:/home/guwang/Workspace/apache/kafka/bin/../core/build/dependant-libs-2.8.0/slf4j-log4j12-1.7.6.jar:/home/guwang/Workspace/apache/kafka/bin/../core/build/dependant-libs-2.8.0/snappy-java-1.0.5.jar:/home/guwang/Workspace/apache/kafka/bin/../core/build/dependant-libs-2.8.0/zkclient-0.3.jar:/home/guwang/Workspace/apache/kafka/bin/../core/build/dependant-libs-2.8.0/zookeeper-3.3.4.jar:/home/guwang/Workspace/apache/kafka/bin/../perf/build/libs//kafka-perf_2.8.0-0.8.1.jar:/home/guwang/Workspace/apache/kafka/bin/../examples/build/libs//kafka-examples-0.8.1.jar:/home/guwang/Workspace/apache/kafka/bin/../contrib/hadoop-consumer/build/libs//kafka-hadoop-consumer-0.8.1.jar:/home/guwang/Workspace/apache/kafka/bin/../contrib/hadoop-producer/build/libs//kafka-hadoop-producer-0.8.1.jar:/home/guwang/Workspace/apache/kafka/bin/../clients/build/libs/kafka-clients-0.8.1.jar:/home/guwang/Workspace/apache/kafka/bin/../libs/*.jar:/home/guwang/Workspace/apache/kafka/bin/../core/build/libs/kafka_2.8.0-0.8.1.jar
(org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,526] INFO Client
environment:java.library.path=/usr/java/jdk1.6.0_38/jre/lib/amd64/server:/usr/java/jdk1.6.0_38/jre/lib/amd64:/usr/java/jdk1.6.0_38/jre/../lib/amd64:/export/apps/xtools/oracle-instant-client_10.2:/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
(org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,526] INFO Client environment:java.io.tmpdir=/tmp
(org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,526] INFO Client environment:java.compiler=<NA>
(org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,526] INFO Client environment:os.name=Linux
(org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,527] INFO Client environment:os.arch=amd64
(org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,527] INFO Client
environment:os.version=2.6.32-131.4.1.el6.x86_64
(org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,527] INFO Client environment:user.name=guwang
(org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,527] INFO Client environment:user.home=/home/guwang
(org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,527] INFO Client
environment:user.dir=/home/guwang/Workspace/apache/kafka
(org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,527] INFO Initiating client connection,
connectString=localhost:2181 sessionTimeout=6000
watcher=org.I0Itec.zkclient.ZkClient@6a6779e6 (org.apache.zookeeper.ZooKeeper)
[2014-04-11 15:17:41,546] INFO Opening socket connection to server
localhost/0:0:0:0:0:0:0:1:2181 (org.apache.zookeeper.ClientCnxn)
[2014-04-11 15:17:41,551] INFO Socket connection established to
localhost/0:0:0:0:0:0:0:1:2181, initiating session
(org.apache.zookeeper.ClientCnxn)
[2014-04-11 15:17:41,562] INFO Session establishment complete on server
localhost/0:0:0:0:0:0:0:1:2181, sessionid = 0x14552dde3620001, negotiated
timeout = 6000 (org.apache.zookeeper.ClientCnxn)
[2014-04-11 15:17:41,565] INFO zookeeper state changed (SyncConnected)
(org.I0Itec.zkclient.ZkClient)
[2014-04-11 15:17:41,647] INFO Found clean shutdown file. Skipping recovery for
all logs in data directory '/tmp/kafka-logs' (kafka.log.LogManager)
[2014-04-11 15:17:41,648] INFO Starting log cleanup with a period of 60000 ms.
(kafka.log.LogManager)
[2014-04-11 15:17:41,652] INFO Starting log flusher with a default period of
9223372036854775807 ms. (kafka.log.LogManager)
[2014-04-11 15:17:41,694] INFO Awaiting socket connections on 0.0.0.0:9092.
(kafka.network.Acceptor)
[2014-04-11 15:17:41,695] INFO [Socket Server on Broker 0], Started
(kafka.network.SocketServer)
[2014-04-11 15:17:41,793] INFO Will not load MX4J, mx4j-tools.jar is not in the
classpath (kafka.utils.Mx4jLoader$)
[2014-04-11 15:17:41,840] INFO 0 successfully elected as leader
(kafka.server.ZookeeperLeaderElector)
[2014-04-11 15:17:41,955] INFO Registered broker 0 at path /brokers/ids/0 with
address guwang-ld2.linkedin.biz:9092. (kafka.utils.ZkUtils$)
[2014-04-11 15:17:41,983] INFO [Kafka Server 0], started
(kafka.server.KafkaServer)
[2014-04-11 15:17:42,039] INFO New leader is 0
(kafka.server.ZookeeperLeaderElector$LeaderChangeListener)
{quote}
Controller:
{quote}
[2014-04-11 15:17:24,520] DEBUG preRegister called.
Server=com.sun.jmx.mbeanserver.JmxMBeanServer@7aab853b,
name=log4j:logger=kafka.controller (kafka.controller)
[2014-04-11 15:17:30,898] INFO [Controller 0]: Controller starting up
(kafka.controller.KafkaController)
[2014-04-11 15:17:30,932] INFO [Controller 0]: Broker 0 starting become
controller state transition (kafka.controller.KafkaController)
[2014-04-11 15:17:30,946] INFO [Controller 0]: Controller 0 incremented epoch
to 1 (kafka.controller.KafkaController)
[2014-04-11 15:17:30,982] INFO [Controller 0]: Partitions undergoing preferred
replica election: (kafka.controller.KafkaController)
[2014-04-11 15:17:30,983] INFO [Controller 0]: Partitions that completed
preferred replica election: (kafka.controller.KafkaController)
[2014-04-11 15:17:30,983] INFO [Controller 0]: Resuming preferred replica
election for partitions: (kafka.controller.KafkaController)
[2014-04-11 15:17:30,988] INFO [Controller 0]: Partitions being reassigned:
Map() (kafka.controller.KafkaController)
[2014-04-11 15:17:30,988] INFO [Controller 0]: Partitions already reassigned:
List() (kafka.controller.KafkaController)
[2014-04-11 15:17:30,989] INFO [Controller 0]: Resuming reassignment of
partitions: Map() (kafka.controller.KafkaController)
[2014-04-11 15:17:30,992] INFO [Controller 0]: List of topics to be deleted:
(kafka.controller.KafkaController)
[2014-04-11 15:17:30,992] INFO [Controller 0]: List of topics ineligible for
deletion: (kafka.controller.KafkaController)
[2014-04-11 15:17:30,996] INFO [Controller 0]: Currently active brokers in the
cluster: Set() (kafka.controller.KafkaController)
[2014-04-11 15:17:30,997] INFO [Controller 0]: Currently shutting brokers in
the cluster: Set() (kafka.controller.KafkaController)
[2014-04-11 15:17:30,997] INFO [Controller 0]: Current list of topics in the
cluster: Set() (kafka.controller.KafkaController)
[2014-04-11 15:17:31,000] INFO [Replica state machine on controller 0]: Started
replica state machine with initial state -> Map()
(kafka.controller.ReplicaStateMachine)
[2014-04-11 15:17:31,005] INFO [Partition state machine on Controller 0]:
Started partition state machine with initial state -> Map()
(kafka.controller.PartitionStateMachine)
[2014-04-11 15:17:31,006] INFO [Controller 0]: Broker 0 is ready to serve as
the new controller with epoch 1 (kafka.controller.KafkaController)
[2014-04-11 15:17:31,007] INFO [Controller 0]: Starting preferred replica
leader election for partitions (kafka.controller.KafkaController)
[2014-04-11 15:17:31,008] INFO [Partition state machine on Controller 0]:
Invoking state change to OnlinePartition for partitions
(kafka.controller.PartitionStateMachine)
[2014-04-11 15:17:31,019] INFO [Controller 0]: Controller startup complete
(kafka.controller.KafkaController)
[2014-04-11 15:17:31,133] DEBUG [ControllerEpochListener on 0]: Controller
epoch listener fired with new epoch 1 (kafka.controller.ControllerEpochListener)
[2014-04-11 15:17:31,144] INFO [ControllerEpochListener on 0]: Initialized
controller epoch to 1 and zk version 0
(kafka.controller.ControllerEpochListener)
[2014-04-11 15:17:31,148] INFO [BrokerChangeListener on Controller 0]: Broker
change listener fired for path /brokers/ids with children 0
(kafka.controller.ReplicaStateMachine$BrokerChangeListener)
[2014-04-11 15:17:31,203] INFO [BrokerChangeListener on Controller 0]: Newly
added brokers: 0, deleted brokers: , all live brokers: 0
(kafka.controller.ReplicaStateMachine$BrokerChangeListener)
[2014-04-11 15:17:31,205] DEBUG [Channel manager on controller 0]: Controller 0
trying to connect to broker 0 (kafka.controller.ControllerChannelManager)
[2014-04-11 15:17:31,210] INFO [Controller-0-to-broker-0-send-thread],
Controller 0 connected to id:0,host:guwang-ld2.linkedin.biz,port:9092 for
sending state change requests (kafka.controller.RequestSendThread)
[2014-04-11 15:17:31,212] INFO [Controller-0-to-broker-0-send-thread], Starting
(kafka.controller.RequestSendThread)
[2014-04-11 15:17:31,212] INFO [Controller 0]: New broker startup callback for
0 (kafka.controller.KafkaController)
[2014-04-11 15:17:36,049] INFO [BrokerChangeListener on Controller 0]: Broker
change listener fired for path /brokers/ids with children
(kafka.controller.ReplicaStateMachine$BrokerChangeListener)
[2014-04-11 15:17:36,050] INFO [BrokerChangeListener on Controller 0]: Newly
added brokers: , deleted brokers: 0, all live brokers:
(kafka.controller.ReplicaStateMachine$BrokerChangeListener)
[2014-04-11 15:17:36,059] INFO [Controller-0-to-broker-0-send-thread], Shutting
down (kafka.controller.RequestSendThread)
[2014-04-11 15:17:36,060] INFO [Controller-0-to-broker-0-send-thread], Shutdown
completed (kafka.controller.RequestSendThread)
[2014-04-11 15:17:36,061] INFO [Controller-0-to-broker-0-send-thread], Stopped
(kafka.controller.RequestSendThread)
[2014-04-11 15:17:36,061] INFO [Controller 0]: Broker failure callback for 0
(kafka.controller.KafkaController)
[2014-04-11 15:17:36,064] INFO [Controller 0]: Removed List() from list of
shutting down brokers. (kafka.controller.KafkaController)
[2014-04-11 15:17:36,067] INFO [Partition state machine on Controller 0]:
Invoking state change to OfflinePartition for partitions
(kafka.controller.PartitionStateMachine)
[2014-04-11 15:17:41,755] INFO [ControllerEpochListener on 0]: Initialized
controller epoch to 1 and zk version 0
(kafka.controller.ControllerEpochListener)
[2014-04-11 15:17:41,795] INFO [Controller 0]: Controller starting up
(kafka.controller.KafkaController)
[2014-04-11 15:17:41,841] INFO [Controller 0]: Broker 0 starting become
controller state transition (kafka.controller.KafkaController)
[2014-04-11 15:17:41,852] INFO [Controller 0]: Controller 0 incremented epoch
to 2 (kafka.controller.KafkaController)
[2014-04-11 15:17:41,884] INFO [Controller 0]: Partitions undergoing preferred
replica election: (kafka.controller.KafkaController)
[2014-04-11 15:17:41,885] INFO [Controller 0]: Partitions that completed
preferred replica election: (kafka.controller.KafkaController)
[2014-04-11 15:17:41,885] INFO [Controller 0]: Resuming preferred replica
election for partitions: (kafka.controller.KafkaController)
[2014-04-11 15:17:41,889] INFO [Controller 0]: Partitions being reassigned:
Map() (kafka.controller.KafkaController)
[2014-04-11 15:17:41,890] INFO [Controller 0]: Partitions already reassigned:
List() (kafka.controller.KafkaController)
[2014-04-11 15:17:41,891] INFO [Controller 0]: Resuming reassignment of
partitions: Map() (kafka.controller.KafkaController)
[2014-04-11 15:17:41,894] INFO [Controller 0]: List of topics to be deleted:
(kafka.controller.KafkaController)
[2014-04-11 15:17:41,894] INFO [Controller 0]: List of topics ineligible for
deletion: (kafka.controller.KafkaController)
[2014-04-11 15:17:41,898] INFO [Controller 0]: Currently active brokers in the
cluster: Set() (kafka.controller.KafkaController)
[2014-04-11 15:17:41,898] INFO [Controller 0]: Currently shutting brokers in
the cluster: Set() (kafka.controller.KafkaController)
[2014-04-11 15:17:41,899] INFO [Controller 0]: Current list of topics in the
cluster: Set() (kafka.controller.KafkaController)
[2014-04-11 15:17:41,902] INFO [Replica state machine on controller 0]: Started
replica state machine with initial state -> Map()
(kafka.controller.ReplicaStateMachine)
[2014-04-11 15:17:41,906] INFO [Partition state machine on Controller 0]:
Started partition state machine with initial state -> Map()
(kafka.controller.PartitionStateMachine)
[2014-04-11 15:17:41,908] INFO [Controller 0]: Broker 0 is ready to serve as
the new controller with epoch 2 (kafka.controller.KafkaController)
[2014-04-11 15:17:41,909] INFO [Controller 0]: Starting preferred replica
leader election for partitions (kafka.controller.KafkaController)
[2014-04-11 15:17:41,910] INFO [Partition state machine on Controller 0]:
Invoking state change to OnlinePartition for partitions
(kafka.controller.PartitionStateMachine)
[2014-04-11 15:17:41,920] INFO [Controller 0]: Controller startup complete
(kafka.controller.KafkaController)
[2014-04-11 15:17:42,042] DEBUG [ControllerEpochListener on 0]: Controller
epoch listener fired with new epoch 2 (kafka.controller.ControllerEpochListener)
[2014-04-11 15:17:42,045] INFO [ControllerEpochListener on 0]: Initialized
controller epoch to 2 and zk version 1
(kafka.controller.ControllerEpochListener)
[2014-04-11 15:17:42,049] INFO [BrokerChangeListener on Controller 0]: Broker
change listener fired for path /brokers/ids with children 0
(kafka.controller.ReplicaStateMachine$BrokerChangeListener)
[2014-04-11 15:17:42,103] INFO [BrokerChangeListener on Controller 0]: Newly
added brokers: 0, deleted brokers: , all live brokers: 0
(kafka.controller.ReplicaStateMachine$BrokerChangeListener)
[2014-04-11 15:17:42,104] DEBUG [Channel manager on controller 0]: Controller 0
trying to connect to broker 0 (kafka.controller.ControllerChannelManager)
[2014-04-11 15:17:42,109] INFO [Controller-0-to-broker-0-send-thread],
Controller 0 connected to id:0,host:guwang-ld2.linkedin.biz,port:9092 for
sending state change requests (kafka.controller.RequestSendThread)
[2014-04-11 15:17:42,111] INFO [Controller-0-to-broker-0-send-thread], Starting
(kafka.controller.RequestSendThread)
[2014-04-11 15:17:42,111] INFO [Controller 0]: New broker startup callback for
0 (kafka.controller.KafkaController)
{quote}
2. Topic creation
Server:
{quote}
[2014-04-11 15:19:46,428] INFO [ReplicaFetcherManager on broker 0] Removed
fetcher for partitions [test,0] (kafka.server.ReplicaFetcherManager)
[2014-04-11 15:19:46,455] INFO Completed load of log test-0 with log end offset
0 (kafka.log.Log)
[2014-04-11 15:19:46,460] INFO Created log for partition [test,0] in
/tmp/kafka-logs with properties {segment.index.bytes -> 10485760,
file.delete.delay.ms -> 60000, segment.bytes -> 536870912, flush.ms ->
9223372036854775807, delete.retention.ms -> 86400000, index.interval.bytes ->
4096, retention.bytes -> -1, cleanup.policy -> delete,
unclean.leader.election.enable -> true, segment.ms -> 604800000,
max.message.bytes -> 1000012, flush.messages -> 9223372036854775807,
min.cleanable.dirty.ratio -> 0.5, retention.ms -> 604800000}.
(kafka.log.LogManager)
[2014-04-11 15:19:46,461] WARN Partition [test,0] on broker 0: No checkpointed
highwatermark is found for partition [test,0] (kafka.cluster.Partition)
{quote}
State-change:
{quote}
[2014-04-11 15:17:24,517] DEBUG preRegister called.
Server=com.sun.jmx.mbeanserver.JmxMBeanServer@7aab853b,
name=log4j:logger=state.change.logger (state.change.logger)
[2014-04-11 15:19:46,327] TRACE Controller 0 epoch 2 changed partition [test,0]
state from NonExistentPartition to NewPartition with assigned replicas 0
(state.change.logger)
[2014-04-11 15:19:46,333] TRACE Controller 0 epoch 2 changed state of replica 0
for partition [test,0] from NonExistentReplica to NewReplica
(state.change.logger)
[2014-04-11 15:19:46,365] TRACE Controller 0 epoch 2 changed partition [test,0]
from NewPartition to OnlinePartition with leader 0 (state.change.logger)
[2014-04-11 15:19:46,374] TRACE Controller 0 epoch 2 sending become-leader
LeaderAndIsr request (Leader:0,ISR:0,LeaderEpoch:0,ControllerEpoch:2) with
correlationId 7 to broker 0 for partition [test,0] (state.change.logger)
[2014-04-11 15:19:46,377] TRACE Controller 0 epoch 2 sending UpdateMetadata
request (Leader:0,ISR:0,LeaderEpoch:0,ControllerEpoch:2) with correlationId 7
to broker 0 for partition [test,0] (state.change.logger)
[2014-04-11 15:19:46,380] TRACE Controller 0 epoch 2 changed state of replica 0
for partition [test,0] from NewReplica to OnlineReplica (state.change.logger)
[2014-04-11 15:19:46,408] TRACE Broker 0 received LeaderAndIsr request
(LeaderAndIsrInfo:(Leader:0,ISR:0,LeaderEpoch:0,ControllerEpoch:2),ReplicationFactor:1),AllReplicas:0)
correlation id 7 from controller 0 epoch 2 for partition [test,0]
(state.change.logger)
[2014-04-11 15:19:46,418] TRACE Broker 0 handling LeaderAndIsr request
correlationId 7 from controller 0 epoch 2 starting the become-leader transition
for partition [test,0] (state.change.logger)
[2014-04-11 15:19:46,429] TRACE Broker 0 stopped fetchers as part of
become-leader request from controller 0 epoch 2 with correlation id 7 for
partition [test,0] (state.change.logger)
[2014-04-11 15:19:46,473] TRACE Broker 0 completed LeaderAndIsr request
correlationId 7 from controller 0 epoch 2 for the become-leader transition for
partition [test,0] (state.change.logger)
[2014-04-11 15:19:46,486] TRACE Controller 0 epoch 2 received response
correlationId 7 for a request sent to broker
id:0,host:guwang-ld2.linkedin.biz,port:9092 (state.change.logger)
[2014-04-11 15:19:46,509] TRACE Broker 0 cached leader info
(LeaderAndIsrInfo:(Leader:0,ISR:0,LeaderEpoch:0,ControllerEpoch:2),ReplicationFactor:1),AllReplicas:0)
for partition [test,0] in response to UpdateMetadata request sent by
controller 0 epoch 2 with correlation id 7 (state.change.logger)
[2014-04-11 15:19:46,511] TRACE Controller 0 epoch 2 received response
correlationId 7 for a request sent to broker
id:0,host:guwang-ld2.linkedin.biz,port:9092 (state.change.logger)
{quote}
Controller:
{quote}
[2014-04-11 15:19:46,294] DEBUG [TopicChangeListener on Controller 0]: Topic
change listener fired for path /brokers/topics with children test
(kafka.controller.PartitionStateMachine$TopicChangeListener)
[2014-04-11 15:19:46,312] INFO [TopicChangeListener on Controller 0]: New
topics: [Set(test)], deleted topics: [Set()], new partition replica assignment
[Map([test,0] -> List(0))]
(kafka.controller.PartitionStateMachine$TopicChangeListener)
[2014-04-11 15:19:46,313] INFO [Controller 0]: New topic creation callback for
[test,0] (kafka.controller.KafkaController)
[2014-04-11 15:19:46,316] INFO [Controller 0]: New partition creation callback
for [test,0] (kafka.controller.KafkaController)
[2014-04-11 15:19:46,317] INFO [Partition state machine on Controller 0]:
Invoking state change to NewPartition for partitions [test,0]
(kafka.controller.PartitionStateMachine)
[2014-04-11 15:19:46,330] INFO [Replica state machine on controller 0]:
Invoking state change to NewReplica for replicas
[Topic=test,Partition=0,Replica=0] (kafka.controller.ReplicaStateMachine)
[2014-04-11 15:19:46,333] INFO [Partition state machine on Controller 0]:
Invoking state change to OnlinePartition for partitions [test,0]
(kafka.controller.PartitionStateMachine)
[2014-04-11 15:19:46,335] DEBUG [Partition state machine on Controller 0]: Live
assigned replicas for partition [test,0] are: [List(0)]
(kafka.controller.PartitionStateMachine)
[2014-04-11 15:19:46,337] DEBUG [Partition state machine on Controller 0]:
Initializing leader and isr for partition [test,0] to
(Leader:0,ISR:0,LeaderEpoch:0,ControllerEpoch:2)
(kafka.controller.PartitionStateMachine)
[2014-04-11 15:19:46,377] INFO [Replica state machine on controller 0]:
Invoking state change to OnlineReplica for replicas
[Topic=test,Partition=0,Replica=0] (kafka.controller.ReplicaStateMachine)
{quote}
3. Send messages: nearly no logs except one in kafka-request.
4. Receive messages: nearly no logs in kafka-request and
{quote}
[2014-04-11 16:59:12,262] ERROR Closing socket for /127.0.0.1 because of error
java.io.IOException: Connection reset by peer (kafka.network.Processor)
{quote}
When consumer closed.
5. Leader failover
{quote}
{quote}
6. Controller failover
{quote}
{quote}
> Reduce logging on the server
> ----------------------------
>
> Key: KAFKA-1352
> URL: https://issues.apache.org/jira/browse/KAFKA-1352
> Project: Kafka
> Issue Type: Bug
> Components: core
> Affects Versions: 0.8.0, 0.8.1
> Reporter: Neha Narkhede
> Assignee: Ivan Lyutov
> Labels: newbie, usability
> Fix For: 0.8.2
>
> Attachments: KAFKA-1352.patch, KAFKA-1352.patch,
> KAFKA-1352_2014-04-04_21:20:31.patch
>
>
> We have excessive logging in the server, making the logs unreadable and also
> affecting the performance of the server in practice. We need to clean the
> logs to address these issues.
--
This message was sent by Atlassian JIRA
(v6.2#6252)
