You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@kafka.apache.org by "Garrett Barton (JIRA)" <ji...@apache.org> on 2013/07/03 21:04:21 UTC
[jira] [Updated] (KAFKA-961) state.change.logger: Error on broker 1
while processing LeaderAndIsr request correlationId 6 received from
controller 1 epoch 1 for partition (page_visits,0)
[ https://issues.apache.org/jira/browse/KAFKA-961?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Garrett Barton updated KAFKA-961:
---------------------------------
Description:
Been having issues embedding 0.8 servers into some Yarn stuff I'm doing. I just pulled the latest from git, did a ./sbt +package, followed by ./sbt assembly-package-dependency. And pushed core/target/scala-2.8.0/kafka_2.8.0-0.8.0-beta1.jar into my local mvn repo. Here is sample code ripped out to little classes to show my error:
Starting up a broker embedded in java, with the following code:
...
Properties props = new Properties();
// dont set so it binds to all interfaces
// props.setProperty("hostname", hostName);
props.setProperty("port", 9999);
props.setProperty("broker.id", "1");
props.setProperty("log.dir", "/tmp/embeddedkafka/" + randId);
// TODO: hardcode bad
props.setProperty("zookeeper.connect", "localhost:2181/" + randId);
KafkaConfig kconf = new KafkaConfig(props);
server = new KafkaServer(kconf, null);
server.startup();
LOG.info("Broker online");
Sample Producer has the following code:
...
Properties props = new Properties();
props.put("metadata.broker.list", "gman-minty:9999");
props.put("serializer.class", "kafka.serializer.StringEncoder");
props.put("partitioner.class", "com.gman.broker.SimplePartitioner");
props.put("request.required.acks", "1");
ProducerConfig config = new ProducerConfig(props);
Producer<String, String> producer = new Producer<String, String>(config);
LOG.info("producer created");
KeyedMessage<String, String> data = new KeyedMessage<String, String>("page_visits", "key1", "value1");
producer.send(data);
LOG.info("wrote message: " + data);
And here is the server log:
INFO 2013-07-03 13:47:30,538 [Thread-0] kafka.utils.VerifiableProperties: Verifying properties
INFO 2013-07-03 13:47:30,568 [Thread-0] kafka.utils.VerifiableProperties: Property port is overridden to 9999
INFO 2013-07-03 13:47:30,568 [Thread-0] kafka.utils.VerifiableProperties: Property broker.id is overridden to 1
INFO 2013-07-03 13:47:30,568 [Thread-0] kafka.utils.VerifiableProperties: Property zookeeper.connect is overridden to localhost:2181/kafkatest
INFO 2013-07-03 13:47:30,569 [Thread-0] kafka.utils.VerifiableProperties: Property log.dir is overridden to \tmp\embeddedkafka\1372873650268
INFO 2013-07-03 13:47:30,574 [Thread-0] kafka.server.KafkaServer: [Kafka Server 1], Starting
INFO 2013-07-03 13:47:30,609 [Thread-0] kafka.log.LogManager: [Log Manager on Broker 1] Log directory '/home/gman/workspace/distributed_parser/\tmp\embeddedkafka\1372873650268' not found, creating it.
INFO 2013-07-03 13:47:30,619 [Thread-0] kafka.log.LogManager: [Log Manager on Broker 1] Starting log cleaner every 600000 ms
INFO 2013-07-03 13:47:30,630 [Thread-0] kafka.log.LogManager: [Log Manager on Broker 1] Starting log flusher every 3000 ms with the following overrides Map()
INFO 2013-07-03 13:47:30,687 [Thread-0] kafka.network.Acceptor: Awaiting socket connections on 0.0.0.0:9999.
INFO 2013-07-03 13:47:30,688 [Thread-0] kafka.network.SocketServer: [Socket Server on Broker 1], Started
INFO 2013-07-03 13:47:30,696 [Thread-0] kafka.server.KafkaZooKeeper: connecting to ZK: localhost:2181/kafkatest
INFO 2013-07-03 13:47:30,707 [ZkClient-EventThread-17-localhost:2181/kafkatest] org.I0Itec.zkclient.ZkEventThread: Starting ZkClient event thread.
INFO 2013-07-03 13:47:30,716 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:zookeeper.version=3.4.2-1221870, built on 12/21/2011 20:46 GMT
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:host.name=gman-minty
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.version=1.6.0_27
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.vendor=Sun Microsystems Inc.
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.home=/usr/lib/jvm/java-6-openjdk-amd64/jre
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.class.path=/home/gman/workspace/distributed_parser/target/classes:/home/gman/.m2/repository/org/slf4j/slf4j-api/1.6.1/slf4j-api-1.6.1.jar:/home/gman/.m2/repository/org/slf4j/slf4j-log4j12/1.6.1/slf4j-log4j12-1.6.1.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-annotations/2.0.5-alpha/hadoop-annotations-2.0.5-alpha.jar:/home/gman/.m2/repository/jdk/tools/jdk.tools/1.6/jdk.tools-1.6.jar:/home/gman/.m2/repository/com/google/inject/extensions/guice-servlet/3.0/guice-servlet-3.0.jar:/home/gman/.m2/repository/io/netty/netty/3.5.11.Final/netty-3.5.11.Final.jar:/home/gman/.m2/repository/com/google/protobuf/protobuf-java/2.4.0a/protobuf-java-2.4.0a.jar:/home/gman/.m2/repository/commons-io/commons-io/2.1/commons-io-2.1.jar:/home/gman/.m2/repository/com/google/inject/guice/3.0/guice-3.0.jar:/home/gman/.m2/repository/javax/inject/javax.inject/1/javax.inject-1.jar:/home/gman/.m2/repository/aopalliance/aopalliance/1.0/aopalliance-1.0.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-test-framework/jersey-test-framework-grizzly2/1.8/jersey-test-framework-grizzly2-1.8.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-test-framework/jersey-test-framework-core/1.8/jersey-test-framework-core-1.8.jar:/home/gman/.m2/repository/org/glassfish/javax.servlet/3.0/javax.servlet-3.0.jar:/home/gman/.m2/repository/junit/junit/4.8.2/junit-4.8.2.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-client/1.8/jersey-client-1.8.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-grizzly2/1.8/jersey-grizzly2-1.8.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-http/2.1.1/grizzly-http-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-framework/2.1.1/grizzly-framework-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/gmbal/gmbal-api-only/3.0.0-b023/gmbal-api-only-3.0.0-b023.jar:/home/gman/.m2/repository/org/glassfish/external/management-api/3.0.0-b012/management-api-3.0.0-b012.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-http-server/2.1.1/grizzly-http-server-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-rcm/2.1.1/grizzly-rcm-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-http-servlet/2.1.1/grizzly-http-servlet-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-framework/2.1.1/grizzly-framework-2.1.1-tests.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-server/1.8/jersey-server-1.8.jar:/home/gman/.m2/repository/asm/asm/3.1/asm-3.1.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-json/1.8/jersey-json-1.8.jar:/home/gman/.m2/repository/org/codehaus/jettison/jettison/1.1/jettison-1.1.jar:/home/gman/.m2/repository/stax/stax-api/1.0.1/stax-api-1.0.1.jar:/home/gman/.m2/repository/com/sun/xml/bind/jaxb-impl/2.2.3-1/jaxb-impl-2.2.3-1.jar:/home/gman/.m2/repository/javax/xml/bind/jaxb-api/2.2.2/jaxb-api-2.2.2.jar:/home/gman/.m2/repository/javax/activation/activation/1.1/activation-1.1.jar:/home/gman/.m2/repository/org/codehaus/jackson/jackson-jaxrs/1.7.1/jackson-jaxrs-1.7.1.jar:/home/gman/.m2/repository/org/codehaus/jackson/jackson-xc/1.7.1/jackson-xc-1.7.1.jar:/home/gman/.m2/repository/com/sun/jersey/contribs/jersey-guice/1.8/jersey-guice-1.8.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-yarn-applications-distributedshell/2.0.5-alpha/hadoop-yarn-applications-distributedshell-2.0.5-alpha.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-yarn-common/2.0.5-alpha/hadoop-yarn-common-2.0.5-alpha.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-common/2.0.5-alpha/hadoop-common-2.0.5-alpha.jar:/home/gman/.m2/repository/com/google/guava/guava/11.0.2/guava-11.0.2.jar:/home/gman/.m2/repository/com/google/code/findbugs/jsr305/1.3.9/jsr305-1.3.9.jar:/home/gman/.m2/repository/commons-cli/commons-cli/1.2/commons-cli-1.2.jar:/home/gman/.m2/repository/org/apache/commons/commons-math/2.1/commons-math-2.1.jar:/home/gman/.m2/repository/xmlenc/xmlenc/0.52/xmlenc-0.52.jar:/home/gman/.m2/repository/commons-httpclient/commons-httpclient/3.1/commons-httpclient-3.1.jar:/home/gman/.m2/repository/commons-codec/commons-codec/1.4/commons-codec-1.4.jar:/home/gman/.m2/repository/commons-net/commons-net/3.1/commons-net-3.1.jar:/home/gman/.m2/repository/javax/servlet/servlet-api/2.5/servlet-api-2.5.jar:/home/gman/.m2/repository/org/mortbay/jetty/jetty/6.1.26/jetty-6.1.26.jar:/home/gman/.m2/repository/org/mortbay/jetty/jetty-util/6.1.26/jetty-util-6.1.26.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-core/1.8/jersey-core-1.8.jar:/home/gman/.m2/repository/tomcat/jasper-compiler/5.5.23/jasper-compiler-5.5.23.jar:/home/gman/.m2/repository/tomcat/jasper-runtime/5.5.23/jasper-runtime-5.5.23.jar:/home/gman/.m2/repository/javax/servlet/jsp/jsp-api/2.1/jsp-api-2.1.jar:/home/gman/.m2/repository/commons-el/commons-el/1.0/commons-el-1.0.jar:/home/gman/.m2/repository/commons-logging/commons-logging/1.1.1/commons-logging-1.1.1.jar:/home/gman/.m2/repository/net/java/dev/jets3t/jets3t/0.6.1/jets3t-0.6.1.jar:/home/gman/.m2/repository/commons-lang/commons-lang/2.5/commons-lang-2.5.jar:/home/gman/.m2/repository/commons-configuration/commons-configuration/1.6/commons-configuration-1.6.jar:/home/gman/.m2/repository/commons-collections/commons-collections/3.2.1/commons-collections-3.2.1.jar:/home/gman/.m2/repository/commons-digester/commons-digester/1.8/commons-digester-1.8.jar:/home/gman/.m2/repository/commons-beanutils/commons-beanutils/1.7.0/commons-beanutils-1.7.0.jar:/home/gman/.m2/repository/commons-beanutils/commons-beanutils-core/1.8.0/commons-beanutils-core-1.8.0.jar:/home/gman/.m2/repository/org/codehaus/jackson/jackson-core-asl/1.8.8/jackson-core-asl-1.8.8.jar:/home/gman/.m2/repository/org/codehaus/jackson/jackson-mapper-asl/1.8.8/jackson-mapper-asl-1.8.8.jar:/home/gman/.m2/repository/org/apache/avro/avro/1.5.3/avro-1.5.3.jar:/home/gman/.m2/repository/com/thoughtworks/paranamer/paranamer/2.3/paranamer-2.3.jar:/home/gman/.m2/repository/org/xerial/snappy/snappy-java/1.0.3.2/snappy-java-1.0.3.2.jar:/home/gman/.m2/repository/net/sf/kosmosfs/kfs/0.3/kfs-0.3.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-auth/2.0.5-alpha/hadoop-auth-2.0.5-alpha.jar:/home/gman/.m2/repository/com/jcraft/jsch/0.1.42/jsch-0.1.42.jar:/home/gman/.m2/repository/org/apache/zookeeper/zookeeper/3.4.2/zookeeper-3.4.2.jar:/home/gman/.m2/repository/log4j/log4j/1.2.17/log4j-1.2.17.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-hdfs/2.0.5-alpha/hadoop-hdfs-2.0.5-alpha.jar:/home/gman/.m2/repository/commons-daemon/commons-daemon/1.0.13/commons-daemon-1.0.13.jar:/home/gman/.m2/repository/org/apache/kafka/0.8/kafka-0.8.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-yarn-api/2.0.5-alpha/hadoop-yarn-api-2.0.5-alpha.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-yarn-client/2.0.5-alpha/hadoop-yarn-client-2.0.5-alpha.jar:/home/gman/.m2/repository/org/scala-lang/scala-library/2.8.0/scala-library-2.8.0.jar:/home/gman/.m2/repository/com/yammer/metrics/metrics-core/2.2.0/metrics-core-2.2.0.jar:/home/gman/.m2/repository/com/101tec/zkclient/0.3/zkclient-0.3.jar:/home/gman/.m2/repository/net/sf/jopt-simple/jopt-simple/4.5/jopt-simple-4.5.jar
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.library.path=/usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/server:/usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64:/usr/lib/jvm/java-6-openjdk-amd64/jre/../lib/amd64:/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.io.tmpdir=/tmp
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.compiler=<NA>
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:os.name=Linux
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:os.arch=amd64
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:os.version=3.8.0-19-generic
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:user.name=gman
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:user.home=/home/gman
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:user.dir=/home/gman/workspace/distributed_parser
INFO 2013-07-03 13:47:30,719 [Thread-0] org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=localhost:2181/kafkatest sessionTimeout=6000 watcher=org.I0Itec.zkclient.ZkClient@661736e
INFO 2013-07-03 13:47:30,735 [Thread-0-SendThread()] org.apache.zookeeper.ClientCnxn: Opening socket connection to server /127.0.0.1:2181
INFO 2013-07-03 13:47:30,744 [Thread-0-SendThread(localhost:2181)] org.apache.zookeeper.ClientCnxn: Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2013-07-03 13:47:30,750 [Thread-0-SendThread(localhost:2181)] org.apache.zookeeper.ClientCnxn: Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13f9c3e2c100075, negotiated timeout = 6000
INFO 2013-07-03 13:47:30,752 [Thread-0-EventThread] org.I0Itec.zkclient.ZkClient: zookeeper state changed (SyncConnected)
INFO 2013-07-03 13:47:30,805 [Thread-0] kafka.utils.ZkUtils$: Registered broker 1 at path /brokers/ids/1 with address gman-minty:9999.
INFO 2013-07-03 13:47:30,806 [Thread-0] kafka.server.KafkaServer: [Kafka Server 1], Connecting to ZK: localhost:2181/kafkatest
INFO 2013-07-03 13:47:30,907 [Thread-0] kafka.utils.Mx4jLoader$: Will not load MX4J, mx4j-tools.jar is not in the classpath
INFO 2013-07-03 13:47:30,908 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Controller starting up
INFO 2013-07-03 13:47:30,913 [Thread-0] kafka.server.ZookeeperLeaderElector: 1 successfully elected as leader
INFO 2013-07-03 13:47:30,914 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Broker 1 starting become controller state transition
INFO 2013-07-03 13:47:30,923 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Controller 1 incremented epoch to 1
INFO 2013-07-03 13:47:31,085 [Controller-1-to-broker-1-send-thread] kafka.controller.RequestSendThread: [Controller-1-to-broker-1-send-thread], Starting
INFO 2013-07-03 13:47:31,085 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Currently active brokers in the cluster: Set(1)
INFO 2013-07-03 13:47:31,086 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Currently shutting brokers in the cluster: Set()
INFO 2013-07-03 13:47:31,086 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Current list of topics in the cluster: Set()
INFO 2013-07-03 13:47:31,089 [Thread-0] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: No state transitions triggered since no partitions are assigned to brokers 1
INFO 2013-07-03 13:47:31,091 [Thread-0] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: Invoking state change to OnlineReplica for replicas
INFO 2013-07-03 13:47:31,094 [Thread-0] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: Started replica state machine with initial state -> Map()
INFO 2013-07-03 13:47:31,096 [Thread-0] kafka.controller.PartitionStateMachine: [Partition state machine on Controller 1]: Started partition state machine with initial state -> Map()
INFO 2013-07-03 13:47:31,097 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Broker 1 is ready to serve as the new controller with epoch 1
INFO 2013-07-03 13:47:31,101 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Partitions being reassigned: Map()
INFO 2013-07-03 13:47:31,101 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Partitions already reassigned: List()
INFO 2013-07-03 13:47:31,102 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Resuming reassignment of partitions: Map()
INFO 2013-07-03 13:47:31,104 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Partitions undergoing preferred replica election:
INFO 2013-07-03 13:47:31,105 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Partitions that completed preferred replica election:
INFO 2013-07-03 13:47:31,106 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Resuming preferred replica election for partitions:
INFO 2013-07-03 13:47:31,107 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Starting preferred replica leader election for partitions
INFO 2013-07-03 13:47:31,108 [Thread-0] kafka.controller.PartitionStateMachine: [Partition state machine on Controller 1]: Invoking state change to OnlinePartition for partitions
INFO 2013-07-03 13:47:31,113 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Controller startup complete
INFO 2013-07-03 13:47:31,114 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.server.ZookeeperLeaderElector$LeaderChangeListener: New leader is 1
INFO 2013-07-03 13:47:31,118 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.ControllerEpochListener: [ControllerEpochListener on 1]: Initialized controller epoch to 1 and zk version 0
INFO 2013-07-03 13:47:31,128 [Thread-0] kafka.server.KafkaServer: [Kafka Server 1], Started
INFO 2013-07-03 13:47:31,128 [Thread-0] com.gman.broker.StandaloneBroker: Broker online
INFO 2013-07-03 13:47:35,663 [kafka-request-handler-0] kafka.server.KafkaApis: [KafkaApi-1] Auto creation of topic page_visits with 1 partitions and replication factor 1 is successful!
INFO 2013-07-03 13:47:35,681 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.PartitionStateMachine$TopicChangeListener: [TopicChangeListener on Controller 1]: New topics: [Set(page_visits)], deleted topics: [Set()], new partition replica assignment [Map([page_visits,0] -> List(1))]
INFO 2013-07-03 13:47:35,683 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.KafkaController: [Controller 1]: New topic creation callback for [page_visits,0]
INFO 2013-07-03 13:47:35,688 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.KafkaController: [Controller 1]: New partition creation callback for [page_visits,0]
INFO 2013-07-03 13:47:35,689 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.PartitionStateMachine: [Partition state machine on Controller 1]: Invoking state change to NewPartition for partitions [page_visits,0]
INFO 2013-07-03 13:47:35,726 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: Invoking state change to NewReplica for replicas PartitionAndReplica(page_visits,0,1)
INFO 2013-07-03 13:47:35,729 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.PartitionStateMachine: [Partition state machine on Controller 1]: Invoking state change to OnlinePartition for partitions [page_visits,0]
INFO 2013-07-03 13:47:35,752 [kafka-processor-9999-1] kafka.network.Processor: Closing socket connection to /127.0.0.1.
INFO 2013-07-03 13:47:35,763 [kafka-request-handler-1] kafka.server.ReplicaManager: [Replica Manager on Broker 1]: Handling LeaderAndIsr request Name:LeaderAndIsrRequest;Version:0;Controller:1;ControllerEpoch:1;CorrelationId:6;ClientId:id_1-host_null-port_9999;PartitionState:(page_visits,0) -> (LeaderAndIsrInfo:(Leader:1,ISR:1,LeaderEpoch:0,ControllerEpoch:1),ReplicationFactor:1),AllReplicas:1);Leaders:id:1,host:gman-minty,port:9999
INFO 2013-07-03 13:47:35,768 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: Invoking state change to OnlineReplica for replicas PartitionAndReplica(page_visits,0,1)
INFO 2013-07-03 13:47:35,773 [kafka-request-handler-1] kafka.server.ReplicaFetcherManager: [ReplicaFetcherManager on broker 1] Removing fetcher for partition [page_visits,0]
INFO 2013-07-03 13:47:35,815 [kafka-processor-9999-2] kafka.network.Processor: Closing socket connection to /127.0.0.1.
INFO 2013-07-03 13:47:35,821 [kafka-request-handler-1] kafka.log.Log: [Kafka Log on Broker 1], Completed load of log page_visits-0 with log end offset 0
INFO 2013-07-03 13:47:35,822 [kafka-request-handler-1] kafka.log.LogManager: [Log Manager on Broker 1] Created log for partition [page_visits,0] in /home/gman/workspace/distributed_parser/\tmp\embeddedkafka\1372873650268.
WARN 2013-07-03 13:47:35,823 [kafka-request-handler-1] kafka.server.HighwaterMarkCheckpoint: No highwatermark file is found. Returning 0 as the highwatermark for partition [page_visits,0]
ERROR 2013-07-03 13:47:35,826 [kafka-request-handler-1] state.change.logger: Error on broker 1 while processing LeaderAndIsr request correlationId 6 received from controller 1 epoch 1 for partition (page_visits,0)
java.lang.NullPointerException
at kafka.cluster.Replica.<init>(Replica.scala:35)
at kafka.cluster.Partition.getOrCreateReplica(Partition.scala:84)
at kafka.cluster.Partition$$anonfun$1.apply(Partition.scala:149)
at kafka.cluster.Partition$$anonfun$1.apply(Partition.scala:149)
at scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:206)
at scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:206)
at scala.collection.LinearSeqOptimized$class.foreach(LinearSeqOptimized.scala:61)
at scala.collection.immutable.List.foreach(List.scala:45)
at scala.collection.TraversableLike$class.map(TraversableLike.scala:206)
at scala.collection.immutable.List.map(List.scala:45)
at kafka.cluster.Partition.makeLeader(Partition.scala:149)
at kafka.server.ReplicaManager.kafka$server$ReplicaManager$$makeLeader(ReplicaManager.scala:257)
at kafka.server.ReplicaManager$$anonfun$becomeLeaderOrFollower$3.apply(ReplicaManager.scala:221)
at kafka.server.ReplicaManager$$anonfun$becomeLeaderOrFollower$3.apply(ReplicaManager.scala:213)
at scala.collection.immutable.Map$Map1.foreach(Map.scala:105)
at kafka.server.ReplicaManager.becomeLeaderOrFollower(ReplicaManager.scala:213)
at kafka.server.KafkaApis.handleLeaderAndIsrRequest(KafkaApis.scala:87)
at kafka.server.KafkaApis.handle(KafkaApis.scala:70)
at kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:42)
at java.lang.Thread.run(Thread.java:679)
INFO 2013-07-03 13:47:35,830 [kafka-request-handler-1] kafka.server.ReplicaManager: [Replica Manager on Broker 1]: Handled leader and isr request Name:LeaderAndIsrRequest;Version:0;Controller:1;ControllerEpoch:1;CorrelationId:6;ClientId:id_1-host_null-port_9999;PartitionState:(page_visits,0) -> (LeaderAndIsrInfo:(Leader:1,ISR:1,LeaderEpoch:0,ControllerEpoch:1),ReplicationFactor:1),AllReplicas:1);Leaders:id:1,host:gman-minty,port:9999
INFO 2013-07-03 13:47:35,957 [kafka-processor-9999-0] kafka.network.Processor: Closing socket connection to /127.0.0.1.
WARN 2013-07-03 13:47:35,999 [kafka-request-handler-5] kafka.server.KafkaApis: [KafkaApi-1] Produce request with correlation id 4 from client on partition [page_visits,0] failed due to Leader not local for partition [page_visits,0] on broker 1
INFO 2013-07-03 13:47:36,125 [kafka-processor-9999-2] kafka.network.Processor: Closing socket connection to /127.0.0.1.
INFO 2013-07-03 13:47:36,126 [kafka-processor-9999-1] kafka.network.Processor: Closing socket connection to /127.0.0.1.
WARN 2013-07-03 13:47:36,127 [kafka-request-handler-7] kafka.server.KafkaApis: [KafkaApi-1] Produce request with correlation id 7 from client on partition [page_visits,0] failed due to Leader not local for partition [page_visits,0] on broker 1
INFO 2013-07-03 13:47:36,238 [kafka-processor-9999-0] kafka.network.Processor: Closing socket connection to /127.0.0.1.
INFO 2013-07-03 13:47:36,238 [kafka-processor-9999-1] kafka.network.Processor: Closing socket connection to /127.0.0.1.
WARN 2013-07-03 13:47:36,242 [kafka-request-handler-3] kafka.server.KafkaApis: [KafkaApi-1] Produce request with correlation id 10 from client on partition [page_visits,0] failed due to Leader not local for partition [page_visits,0] on broker 1
INFO 2013-07-03 13:47:36,351 [kafka-processor-9999-2] kafka.network.Processor: Closing socket connection to /127.0.0.1.
INFO 2013-07-03 13:47:36,352 [kafka-processor-9999-0] kafka.network.Processor: Closing socket connection to /127.0.0.1.
was:
Been having issues embedding 0.8 servers into some Yarn stuff I'm doing. I just pulled the latest from git, did a ./sbt +package, followed by ./sbt assembly-package-dependency. And pushed core/target/scala-2.8.0/kafka_2.8.0-0.8.0-beta1.jar into my local mvn repo. Here is sample code ripped out to little classes to show my error:
Starting up a broker embedded in java, with the following code:
...
Properties props = new Properties();
// dont set so it binds to all interfaces
// props.setProperty("hostname", hostName);
props.setProperty("port", 9999);
props.setProperty("broker.id", "1");
props.setProperty("log.dir", "/tmp/embeddedkafka/" + randId);
// TODO: hardcode bad
props.setProperty("zookeeper.connect", "localhost:2181/" + randId);
KafkaConfig kconf = new KafkaConfig(props);
server = new KafkaServer(kconf, null);
server.startup();
LOG.info("Broker online");
Sample Producer has the following code:
Properties props = new Properties();
props.put("metadata.broker.list", "gman-minty:9999");
props.put("serializer.class", "kafka.serializer.StringEncoder");
props.put("partitioner.class", "com.gman.broker.SimplePartitioner");
props.put("request.required.acks", "1");
ProducerConfig config = new ProducerConfig(props);
Producer<String, String> producer = new Producer<String, String>(config);
LOG.info("producer created");
KeyedMessage<String, String> data = new KeyedMessage<String, String>("page_visits", "key1", "value1");
producer.send(data);
LOG.info("wrote message: " + data);
And here is the server log:
INFO 2013-07-03 13:47:30,538 [Thread-0] kafka.utils.VerifiableProperties: Verifying properties
INFO 2013-07-03 13:47:30,568 [Thread-0] kafka.utils.VerifiableProperties: Property port is overridden to 9999
INFO 2013-07-03 13:47:30,568 [Thread-0] kafka.utils.VerifiableProperties: Property broker.id is overridden to 1
INFO 2013-07-03 13:47:30,568 [Thread-0] kafka.utils.VerifiableProperties: Property zookeeper.connect is overridden to localhost:2181/kafkatest
INFO 2013-07-03 13:47:30,569 [Thread-0] kafka.utils.VerifiableProperties: Property log.dir is overridden to \tmp\embeddedkafka\1372873650268
INFO 2013-07-03 13:47:30,574 [Thread-0] kafka.server.KafkaServer: [Kafka Server 1], Starting
INFO 2013-07-03 13:47:30,609 [Thread-0] kafka.log.LogManager: [Log Manager on Broker 1] Log directory '/home/gman/workspace/distributed_parser/\tmp\embeddedkafka\1372873650268' not found, creating it.
INFO 2013-07-03 13:47:30,619 [Thread-0] kafka.log.LogManager: [Log Manager on Broker 1] Starting log cleaner every 600000 ms
INFO 2013-07-03 13:47:30,630 [Thread-0] kafka.log.LogManager: [Log Manager on Broker 1] Starting log flusher every 3000 ms with the following overrides Map()
INFO 2013-07-03 13:47:30,687 [Thread-0] kafka.network.Acceptor: Awaiting socket connections on 0.0.0.0:9999.
INFO 2013-07-03 13:47:30,688 [Thread-0] kafka.network.SocketServer: [Socket Server on Broker 1], Started
INFO 2013-07-03 13:47:30,696 [Thread-0] kafka.server.KafkaZooKeeper: connecting to ZK: localhost:2181/kafkatest
INFO 2013-07-03 13:47:30,707 [ZkClient-EventThread-17-localhost:2181/kafkatest] org.I0Itec.zkclient.ZkEventThread: Starting ZkClient event thread.
INFO 2013-07-03 13:47:30,716 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:zookeeper.version=3.4.2-1221870, built on 12/21/2011 20:46 GMT
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:host.name=gman-minty
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.version=1.6.0_27
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.vendor=Sun Microsystems Inc.
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.home=/usr/lib/jvm/java-6-openjdk-amd64/jre
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.class.path=/home/gman/workspace/distributed_parser/target/classes:/home/gman/.m2/repository/org/slf4j/slf4j-api/1.6.1/slf4j-api-1.6.1.jar:/home/gman/.m2/repository/org/slf4j/slf4j-log4j12/1.6.1/slf4j-log4j12-1.6.1.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-annotations/2.0.5-alpha/hadoop-annotations-2.0.5-alpha.jar:/home/gman/.m2/repository/jdk/tools/jdk.tools/1.6/jdk.tools-1.6.jar:/home/gman/.m2/repository/com/google/inject/extensions/guice-servlet/3.0/guice-servlet-3.0.jar:/home/gman/.m2/repository/io/netty/netty/3.5.11.Final/netty-3.5.11.Final.jar:/home/gman/.m2/repository/com/google/protobuf/protobuf-java/2.4.0a/protobuf-java-2.4.0a.jar:/home/gman/.m2/repository/commons-io/commons-io/2.1/commons-io-2.1.jar:/home/gman/.m2/repository/com/google/inject/guice/3.0/guice-3.0.jar:/home/gman/.m2/repository/javax/inject/javax.inject/1/javax.inject-1.jar:/home/gman/.m2/repository/aopalliance/aopalliance/1.0/aopalliance-1.0.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-test-framework/jersey-test-framework-grizzly2/1.8/jersey-test-framework-grizzly2-1.8.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-test-framework/jersey-test-framework-core/1.8/jersey-test-framework-core-1.8.jar:/home/gman/.m2/repository/org/glassfish/javax.servlet/3.0/javax.servlet-3.0.jar:/home/gman/.m2/repository/junit/junit/4.8.2/junit-4.8.2.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-client/1.8/jersey-client-1.8.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-grizzly2/1.8/jersey-grizzly2-1.8.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-http/2.1.1/grizzly-http-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-framework/2.1.1/grizzly-framework-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/gmbal/gmbal-api-only/3.0.0-b023/gmbal-api-only-3.0.0-b023.jar:/home/gman/.m2/repository/org/glassfish/external/management-api/3.0.0-b012/management-api-3.0.0-b012.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-http-server/2.1.1/grizzly-http-server-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-rcm/2.1.1/grizzly-rcm-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-http-servlet/2.1.1/grizzly-http-servlet-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-framework/2.1.1/grizzly-framework-2.1.1-tests.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-server/1.8/jersey-server-1.8.jar:/home/gman/.m2/repository/asm/asm/3.1/asm-3.1.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-json/1.8/jersey-json-1.8.jar:/home/gman/.m2/repository/org/codehaus/jettison/jettison/1.1/jettison-1.1.jar:/home/gman/.m2/repository/stax/stax-api/1.0.1/stax-api-1.0.1.jar:/home/gman/.m2/repository/com/sun/xml/bind/jaxb-impl/2.2.3-1/jaxb-impl-2.2.3-1.jar:/home/gman/.m2/repository/javax/xml/bind/jaxb-api/2.2.2/jaxb-api-2.2.2.jar:/home/gman/.m2/repository/javax/activation/activation/1.1/activation-1.1.jar:/home/gman/.m2/repository/org/codehaus/jackson/jackson-jaxrs/1.7.1/jackson-jaxrs-1.7.1.jar:/home/gman/.m2/repository/org/codehaus/jackson/jackson-xc/1.7.1/jackson-xc-1.7.1.jar:/home/gman/.m2/repository/com/sun/jersey/contribs/jersey-guice/1.8/jersey-guice-1.8.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-yarn-applications-distributedshell/2.0.5-alpha/hadoop-yarn-applications-distributedshell-2.0.5-alpha.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-yarn-common/2.0.5-alpha/hadoop-yarn-common-2.0.5-alpha.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-common/2.0.5-alpha/hadoop-common-2.0.5-alpha.jar:/home/gman/.m2/repository/com/google/guava/guava/11.0.2/guava-11.0.2.jar:/home/gman/.m2/repository/com/google/code/findbugs/jsr305/1.3.9/jsr305-1.3.9.jar:/home/gman/.m2/repository/commons-cli/commons-cli/1.2/commons-cli-1.2.jar:/home/gman/.m2/repository/org/apache/commons/commons-math/2.1/commons-math-2.1.jar:/home/gman/.m2/repository/xmlenc/xmlenc/0.52/xmlenc-0.52.jar:/home/gman/.m2/repository/commons-httpclient/commons-httpclient/3.1/commons-httpclient-3.1.jar:/home/gman/.m2/repository/commons-codec/commons-codec/1.4/commons-codec-1.4.jar:/home/gman/.m2/repository/commons-net/commons-net/3.1/commons-net-3.1.jar:/home/gman/.m2/repository/javax/servlet/servlet-api/2.5/servlet-api-2.5.jar:/home/gman/.m2/repository/org/mortbay/jetty/jetty/6.1.26/jetty-6.1.26.jar:/home/gman/.m2/repository/org/mortbay/jetty/jetty-util/6.1.26/jetty-util-6.1.26.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-core/1.8/jersey-core-1.8.jar:/home/gman/.m2/repository/tomcat/jasper-compiler/5.5.23/jasper-compiler-5.5.23.jar:/home/gman/.m2/repository/tomcat/jasper-runtime/5.5.23/jasper-runtime-5.5.23.jar:/home/gman/.m2/repository/javax/servlet/jsp/jsp-api/2.1/jsp-api-2.1.jar:/home/gman/.m2/repository/commons-el/commons-el/1.0/commons-el-1.0.jar:/home/gman/.m2/repository/commons-logging/commons-logging/1.1.1/commons-logging-1.1.1.jar:/home/gman/.m2/repository/net/java/dev/jets3t/jets3t/0.6.1/jets3t-0.6.1.jar:/home/gman/.m2/repository/commons-lang/commons-lang/2.5/commons-lang-2.5.jar:/home/gman/.m2/repository/commons-configuration/commons-configuration/1.6/commons-configuration-1.6.jar:/home/gman/.m2/repository/commons-collections/commons-collections/3.2.1/commons-collections-3.2.1.jar:/home/gman/.m2/repository/commons-digester/commons-digester/1.8/commons-digester-1.8.jar:/home/gman/.m2/repository/commons-beanutils/commons-beanutils/1.7.0/commons-beanutils-1.7.0.jar:/home/gman/.m2/repository/commons-beanutils/commons-beanutils-core/1.8.0/commons-beanutils-core-1.8.0.jar:/home/gman/.m2/repository/org/codehaus/jackson/jackson-core-asl/1.8.8/jackson-core-asl-1.8.8.jar:/home/gman/.m2/repository/org/codehaus/jackson/jackson-mapper-asl/1.8.8/jackson-mapper-asl-1.8.8.jar:/home/gman/.m2/repository/org/apache/avro/avro/1.5.3/avro-1.5.3.jar:/home/gman/.m2/repository/com/thoughtworks/paranamer/paranamer/2.3/paranamer-2.3.jar:/home/gman/.m2/repository/org/xerial/snappy/snappy-java/1.0.3.2/snappy-java-1.0.3.2.jar:/home/gman/.m2/repository/net/sf/kosmosfs/kfs/0.3/kfs-0.3.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-auth/2.0.5-alpha/hadoop-auth-2.0.5-alpha.jar:/home/gman/.m2/repository/com/jcraft/jsch/0.1.42/jsch-0.1.42.jar:/home/gman/.m2/repository/org/apache/zookeeper/zookeeper/3.4.2/zookeeper-3.4.2.jar:/home/gman/.m2/repository/log4j/log4j/1.2.17/log4j-1.2.17.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-hdfs/2.0.5-alpha/hadoop-hdfs-2.0.5-alpha.jar:/home/gman/.m2/repository/commons-daemon/commons-daemon/1.0.13/commons-daemon-1.0.13.jar:/home/gman/.m2/repository/org/apache/kafka/0.8/kafka-0.8.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-yarn-api/2.0.5-alpha/hadoop-yarn-api-2.0.5-alpha.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-yarn-client/2.0.5-alpha/hadoop-yarn-client-2.0.5-alpha.jar:/home/gman/.m2/repository/org/scala-lang/scala-library/2.8.0/scala-library-2.8.0.jar:/home/gman/.m2/repository/com/yammer/metrics/metrics-core/2.2.0/metrics-core-2.2.0.jar:/home/gman/.m2/repository/com/101tec/zkclient/0.3/zkclient-0.3.jar:/home/gman/.m2/repository/net/sf/jopt-simple/jopt-simple/4.5/jopt-simple-4.5.jar
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.library.path=/usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/server:/usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64:/usr/lib/jvm/java-6-openjdk-amd64/jre/../lib/amd64:/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.io.tmpdir=/tmp
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.compiler=<NA>
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:os.name=Linux
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:os.arch=amd64
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:os.version=3.8.0-19-generic
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:user.name=gman
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:user.home=/home/gman
INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:user.dir=/home/gman/workspace/distributed_parser
INFO 2013-07-03 13:47:30,719 [Thread-0] org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=localhost:2181/kafkatest sessionTimeout=6000 watcher=org.I0Itec.zkclient.ZkClient@661736e
INFO 2013-07-03 13:47:30,735 [Thread-0-SendThread()] org.apache.zookeeper.ClientCnxn: Opening socket connection to server /127.0.0.1:2181
INFO 2013-07-03 13:47:30,744 [Thread-0-SendThread(localhost:2181)] org.apache.zookeeper.ClientCnxn: Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2013-07-03 13:47:30,750 [Thread-0-SendThread(localhost:2181)] org.apache.zookeeper.ClientCnxn: Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13f9c3e2c100075, negotiated timeout = 6000
INFO 2013-07-03 13:47:30,752 [Thread-0-EventThread] org.I0Itec.zkclient.ZkClient: zookeeper state changed (SyncConnected)
INFO 2013-07-03 13:47:30,805 [Thread-0] kafka.utils.ZkUtils$: Registered broker 1 at path /brokers/ids/1 with address gman-minty:9999.
INFO 2013-07-03 13:47:30,806 [Thread-0] kafka.server.KafkaServer: [Kafka Server 1], Connecting to ZK: localhost:2181/kafkatest
INFO 2013-07-03 13:47:30,907 [Thread-0] kafka.utils.Mx4jLoader$: Will not load MX4J, mx4j-tools.jar is not in the classpath
INFO 2013-07-03 13:47:30,908 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Controller starting up
INFO 2013-07-03 13:47:30,913 [Thread-0] kafka.server.ZookeeperLeaderElector: 1 successfully elected as leader
INFO 2013-07-03 13:47:30,914 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Broker 1 starting become controller state transition
INFO 2013-07-03 13:47:30,923 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Controller 1 incremented epoch to 1
INFO 2013-07-03 13:47:31,085 [Controller-1-to-broker-1-send-thread] kafka.controller.RequestSendThread: [Controller-1-to-broker-1-send-thread], Starting
INFO 2013-07-03 13:47:31,085 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Currently active brokers in the cluster: Set(1)
INFO 2013-07-03 13:47:31,086 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Currently shutting brokers in the cluster: Set()
INFO 2013-07-03 13:47:31,086 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Current list of topics in the cluster: Set()
INFO 2013-07-03 13:47:31,089 [Thread-0] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: No state transitions triggered since no partitions are assigned to brokers 1
INFO 2013-07-03 13:47:31,091 [Thread-0] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: Invoking state change to OnlineReplica for replicas
INFO 2013-07-03 13:47:31,094 [Thread-0] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: Started replica state machine with initial state -> Map()
INFO 2013-07-03 13:47:31,096 [Thread-0] kafka.controller.PartitionStateMachine: [Partition state machine on Controller 1]: Started partition state machine with initial state -> Map()
INFO 2013-07-03 13:47:31,097 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Broker 1 is ready to serve as the new controller with epoch 1
INFO 2013-07-03 13:47:31,101 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Partitions being reassigned: Map()
INFO 2013-07-03 13:47:31,101 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Partitions already reassigned: List()
INFO 2013-07-03 13:47:31,102 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Resuming reassignment of partitions: Map()
INFO 2013-07-03 13:47:31,104 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Partitions undergoing preferred replica election:
INFO 2013-07-03 13:47:31,105 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Partitions that completed preferred replica election:
INFO 2013-07-03 13:47:31,106 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Resuming preferred replica election for partitions:
INFO 2013-07-03 13:47:31,107 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Starting preferred replica leader election for partitions
INFO 2013-07-03 13:47:31,108 [Thread-0] kafka.controller.PartitionStateMachine: [Partition state machine on Controller 1]: Invoking state change to OnlinePartition for partitions
INFO 2013-07-03 13:47:31,113 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Controller startup complete
INFO 2013-07-03 13:47:31,114 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.server.ZookeeperLeaderElector$LeaderChangeListener: New leader is 1
INFO 2013-07-03 13:47:31,118 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.ControllerEpochListener: [ControllerEpochListener on 1]: Initialized controller epoch to 1 and zk version 0
INFO 2013-07-03 13:47:31,128 [Thread-0] kafka.server.KafkaServer: [Kafka Server 1], Started
INFO 2013-07-03 13:47:31,128 [Thread-0] com.gman.broker.StandaloneBroker: Broker online
INFO 2013-07-03 13:47:35,663 [kafka-request-handler-0] kafka.server.KafkaApis: [KafkaApi-1] Auto creation of topic page_visits with 1 partitions and replication factor 1 is successful!
INFO 2013-07-03 13:47:35,681 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.PartitionStateMachine$TopicChangeListener: [TopicChangeListener on Controller 1]: New topics: [Set(page_visits)], deleted topics: [Set()], new partition replica assignment [Map([page_visits,0] -> List(1))]
INFO 2013-07-03 13:47:35,683 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.KafkaController: [Controller 1]: New topic creation callback for [page_visits,0]
INFO 2013-07-03 13:47:35,688 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.KafkaController: [Controller 1]: New partition creation callback for [page_visits,0]
INFO 2013-07-03 13:47:35,689 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.PartitionStateMachine: [Partition state machine on Controller 1]: Invoking state change to NewPartition for partitions [page_visits,0]
INFO 2013-07-03 13:47:35,726 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: Invoking state change to NewReplica for replicas PartitionAndReplica(page_visits,0,1)
INFO 2013-07-03 13:47:35,729 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.PartitionStateMachine: [Partition state machine on Controller 1]: Invoking state change to OnlinePartition for partitions [page_visits,0]
INFO 2013-07-03 13:47:35,752 [kafka-processor-9999-1] kafka.network.Processor: Closing socket connection to /127.0.0.1.
INFO 2013-07-03 13:47:35,763 [kafka-request-handler-1] kafka.server.ReplicaManager: [Replica Manager on Broker 1]: Handling LeaderAndIsr request Name:LeaderAndIsrRequest;Version:0;Controller:1;ControllerEpoch:1;CorrelationId:6;ClientId:id_1-host_null-port_9999;PartitionState:(page_visits,0) -> (LeaderAndIsrInfo:(Leader:1,ISR:1,LeaderEpoch:0,ControllerEpoch:1),ReplicationFactor:1),AllReplicas:1);Leaders:id:1,host:gman-minty,port:9999
INFO 2013-07-03 13:47:35,768 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: Invoking state change to OnlineReplica for replicas PartitionAndReplica(page_visits,0,1)
INFO 2013-07-03 13:47:35,773 [kafka-request-handler-1] kafka.server.ReplicaFetcherManager: [ReplicaFetcherManager on broker 1] Removing fetcher for partition [page_visits,0]
INFO 2013-07-03 13:47:35,815 [kafka-processor-9999-2] kafka.network.Processor: Closing socket connection to /127.0.0.1.
INFO 2013-07-03 13:47:35,821 [kafka-request-handler-1] kafka.log.Log: [Kafka Log on Broker 1], Completed load of log page_visits-0 with log end offset 0
INFO 2013-07-03 13:47:35,822 [kafka-request-handler-1] kafka.log.LogManager: [Log Manager on Broker 1] Created log for partition [page_visits,0] in /home/gman/workspace/distributed_parser/\tmp\embeddedkafka\1372873650268.
WARN 2013-07-03 13:47:35,823 [kafka-request-handler-1] kafka.server.HighwaterMarkCheckpoint: No highwatermark file is found. Returning 0 as the highwatermark for partition [page_visits,0]
ERROR 2013-07-03 13:47:35,826 [kafka-request-handler-1] state.change.logger: Error on broker 1 while processing LeaderAndIsr request correlationId 6 received from controller 1 epoch 1 for partition (page_visits,0)
java.lang.NullPointerException
at kafka.cluster.Replica.<init>(Replica.scala:35)
at kafka.cluster.Partition.getOrCreateReplica(Partition.scala:84)
at kafka.cluster.Partition$$anonfun$1.apply(Partition.scala:149)
at kafka.cluster.Partition$$anonfun$1.apply(Partition.scala:149)
at scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:206)
at scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:206)
at scala.collection.LinearSeqOptimized$class.foreach(LinearSeqOptimized.scala:61)
at scala.collection.immutable.List.foreach(List.scala:45)
at scala.collection.TraversableLike$class.map(TraversableLike.scala:206)
at scala.collection.immutable.List.map(List.scala:45)
at kafka.cluster.Partition.makeLeader(Partition.scala:149)
at kafka.server.ReplicaManager.kafka$server$ReplicaManager$$makeLeader(ReplicaManager.scala:257)
at kafka.server.ReplicaManager$$anonfun$becomeLeaderOrFollower$3.apply(ReplicaManager.scala:221)
at kafka.server.ReplicaManager$$anonfun$becomeLeaderOrFollower$3.apply(ReplicaManager.scala:213)
at scala.collection.immutable.Map$Map1.foreach(Map.scala:105)
at kafka.server.ReplicaManager.becomeLeaderOrFollower(ReplicaManager.scala:213)
at kafka.server.KafkaApis.handleLeaderAndIsrRequest(KafkaApis.scala:87)
at kafka.server.KafkaApis.handle(KafkaApis.scala:70)
at kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:42)
at java.lang.Thread.run(Thread.java:679)
INFO 2013-07-03 13:47:35,830 [kafka-request-handler-1] kafka.server.ReplicaManager: [Replica Manager on Broker 1]: Handled leader and isr request Name:LeaderAndIsrRequest;Version:0;Controller:1;ControllerEpoch:1;CorrelationId:6;ClientId:id_1-host_null-port_9999;PartitionState:(page_visits,0) -> (LeaderAndIsrInfo:(Leader:1,ISR:1,LeaderEpoch:0,ControllerEpoch:1),ReplicationFactor:1),AllReplicas:1);Leaders:id:1,host:gman-minty,port:9999
INFO 2013-07-03 13:47:35,957 [kafka-processor-9999-0] kafka.network.Processor: Closing socket connection to /127.0.0.1.
WARN 2013-07-03 13:47:35,999 [kafka-request-handler-5] kafka.server.KafkaApis: [KafkaApi-1] Produce request with correlation id 4 from client on partition [page_visits,0] failed due to Leader not local for partition [page_visits,0] on broker 1
INFO 2013-07-03 13:47:36,125 [kafka-processor-9999-2] kafka.network.Processor: Closing socket connection to /127.0.0.1.
INFO 2013-07-03 13:47:36,126 [kafka-processor-9999-1] kafka.network.Processor: Closing socket connection to /127.0.0.1.
WARN 2013-07-03 13:47:36,127 [kafka-request-handler-7] kafka.server.KafkaApis: [KafkaApi-1] Produce request with correlation id 7 from client on partition [page_visits,0] failed due to Leader not local for partition [page_visits,0] on broker 1
INFO 2013-07-03 13:47:36,238 [kafka-processor-9999-0] kafka.network.Processor: Closing socket connection to /127.0.0.1.
INFO 2013-07-03 13:47:36,238 [kafka-processor-9999-1] kafka.network.Processor: Closing socket connection to /127.0.0.1.
WARN 2013-07-03 13:47:36,242 [kafka-request-handler-3] kafka.server.KafkaApis: [KafkaApi-1] Produce request with correlation id 10 from client on partition [page_visits,0] failed due to Leader not local for partition [page_visits,0] on broker 1
INFO 2013-07-03 13:47:36,351 [kafka-processor-9999-2] kafka.network.Processor: Closing socket connection to /127.0.0.1.
INFO 2013-07-03 13:47:36,352 [kafka-processor-9999-0] kafka.network.Processor: Closing socket connection to /127.0.0.1.
> state.change.logger: Error on broker 1 while processing LeaderAndIsr request correlationId 6 received from controller 1 epoch 1 for partition (page_visits,0)
> -------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: KAFKA-961
> URL: https://issues.apache.org/jira/browse/KAFKA-961
> Project: Kafka
> Issue Type: Bug
> Affects Versions: 0.8
> Environment: Linux gman-minty 3.8.0-19-generic #29-Ubuntu SMP Wed Apr 17 18:16:28 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux
> Reporter: Garrett Barton
>
> Been having issues embedding 0.8 servers into some Yarn stuff I'm doing. I just pulled the latest from git, did a ./sbt +package, followed by ./sbt assembly-package-dependency. And pushed core/target/scala-2.8.0/kafka_2.8.0-0.8.0-beta1.jar into my local mvn repo. Here is sample code ripped out to little classes to show my error:
> Starting up a broker embedded in java, with the following code:
> ...
> Properties props = new Properties();
> // dont set so it binds to all interfaces
> // props.setProperty("hostname", hostName);
> props.setProperty("port", 9999);
> props.setProperty("broker.id", "1");
> props.setProperty("log.dir", "/tmp/embeddedkafka/" + randId);
> // TODO: hardcode bad
> props.setProperty("zookeeper.connect", "localhost:2181/" + randId);
> KafkaConfig kconf = new KafkaConfig(props);
>
> server = new KafkaServer(kconf, null);
> server.startup();
> LOG.info("Broker online");
> Sample Producer has the following code:
> ...
> Properties props = new Properties();
> props.put("metadata.broker.list", "gman-minty:9999");
> props.put("serializer.class", "kafka.serializer.StringEncoder");
> props.put("partitioner.class", "com.gman.broker.SimplePartitioner");
> props.put("request.required.acks", "1");
> ProducerConfig config = new ProducerConfig(props);
>
> Producer<String, String> producer = new Producer<String, String>(config);
> LOG.info("producer created");
> KeyedMessage<String, String> data = new KeyedMessage<String, String>("page_visits", "key1", "value1");
> producer.send(data);
> LOG.info("wrote message: " + data);
> And here is the server log:
> INFO 2013-07-03 13:47:30,538 [Thread-0] kafka.utils.VerifiableProperties: Verifying properties
> INFO 2013-07-03 13:47:30,568 [Thread-0] kafka.utils.VerifiableProperties: Property port is overridden to 9999
> INFO 2013-07-03 13:47:30,568 [Thread-0] kafka.utils.VerifiableProperties: Property broker.id is overridden to 1
> INFO 2013-07-03 13:47:30,568 [Thread-0] kafka.utils.VerifiableProperties: Property zookeeper.connect is overridden to localhost:2181/kafkatest
> INFO 2013-07-03 13:47:30,569 [Thread-0] kafka.utils.VerifiableProperties: Property log.dir is overridden to \tmp\embeddedkafka\1372873650268
> INFO 2013-07-03 13:47:30,574 [Thread-0] kafka.server.KafkaServer: [Kafka Server 1], Starting
> INFO 2013-07-03 13:47:30,609 [Thread-0] kafka.log.LogManager: [Log Manager on Broker 1] Log directory '/home/gman/workspace/distributed_parser/\tmp\embeddedkafka\1372873650268' not found, creating it.
> INFO 2013-07-03 13:47:30,619 [Thread-0] kafka.log.LogManager: [Log Manager on Broker 1] Starting log cleaner every 600000 ms
> INFO 2013-07-03 13:47:30,630 [Thread-0] kafka.log.LogManager: [Log Manager on Broker 1] Starting log flusher every 3000 ms with the following overrides Map()
> INFO 2013-07-03 13:47:30,687 [Thread-0] kafka.network.Acceptor: Awaiting socket connections on 0.0.0.0:9999.
> INFO 2013-07-03 13:47:30,688 [Thread-0] kafka.network.SocketServer: [Socket Server on Broker 1], Started
> INFO 2013-07-03 13:47:30,696 [Thread-0] kafka.server.KafkaZooKeeper: connecting to ZK: localhost:2181/kafkatest
> INFO 2013-07-03 13:47:30,707 [ZkClient-EventThread-17-localhost:2181/kafkatest] org.I0Itec.zkclient.ZkEventThread: Starting ZkClient event thread.
> INFO 2013-07-03 13:47:30,716 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:zookeeper.version=3.4.2-1221870, built on 12/21/2011 20:46 GMT
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:host.name=gman-minty
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.version=1.6.0_27
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.vendor=Sun Microsystems Inc.
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.home=/usr/lib/jvm/java-6-openjdk-amd64/jre
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.class.path=/home/gman/workspace/distributed_parser/target/classes:/home/gman/.m2/repository/org/slf4j/slf4j-api/1.6.1/slf4j-api-1.6.1.jar:/home/gman/.m2/repository/org/slf4j/slf4j-log4j12/1.6.1/slf4j-log4j12-1.6.1.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-annotations/2.0.5-alpha/hadoop-annotations-2.0.5-alpha.jar:/home/gman/.m2/repository/jdk/tools/jdk.tools/1.6/jdk.tools-1.6.jar:/home/gman/.m2/repository/com/google/inject/extensions/guice-servlet/3.0/guice-servlet-3.0.jar:/home/gman/.m2/repository/io/netty/netty/3.5.11.Final/netty-3.5.11.Final.jar:/home/gman/.m2/repository/com/google/protobuf/protobuf-java/2.4.0a/protobuf-java-2.4.0a.jar:/home/gman/.m2/repository/commons-io/commons-io/2.1/commons-io-2.1.jar:/home/gman/.m2/repository/com/google/inject/guice/3.0/guice-3.0.jar:/home/gman/.m2/repository/javax/inject/javax.inject/1/javax.inject-1.jar:/home/gman/.m2/repository/aopalliance/aopalliance/1.0/aopalliance-1.0.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-test-framework/jersey-test-framework-grizzly2/1.8/jersey-test-framework-grizzly2-1.8.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-test-framework/jersey-test-framework-core/1.8/jersey-test-framework-core-1.8.jar:/home/gman/.m2/repository/org/glassfish/javax.servlet/3.0/javax.servlet-3.0.jar:/home/gman/.m2/repository/junit/junit/4.8.2/junit-4.8.2.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-client/1.8/jersey-client-1.8.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-grizzly2/1.8/jersey-grizzly2-1.8.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-http/2.1.1/grizzly-http-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-framework/2.1.1/grizzly-framework-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/gmbal/gmbal-api-only/3.0.0-b023/gmbal-api-only-3.0.0-b023.jar:/home/gman/.m2/repository/org/glassfish/external/management-api/3.0.0-b012/management-api-3.0.0-b012.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-http-server/2.1.1/grizzly-http-server-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-rcm/2.1.1/grizzly-rcm-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-http-servlet/2.1.1/grizzly-http-servlet-2.1.1.jar:/home/gman/.m2/repository/org/glassfish/grizzly/grizzly-framework/2.1.1/grizzly-framework-2.1.1-tests.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-server/1.8/jersey-server-1.8.jar:/home/gman/.m2/repository/asm/asm/3.1/asm-3.1.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-json/1.8/jersey-json-1.8.jar:/home/gman/.m2/repository/org/codehaus/jettison/jettison/1.1/jettison-1.1.jar:/home/gman/.m2/repository/stax/stax-api/1.0.1/stax-api-1.0.1.jar:/home/gman/.m2/repository/com/sun/xml/bind/jaxb-impl/2.2.3-1/jaxb-impl-2.2.3-1.jar:/home/gman/.m2/repository/javax/xml/bind/jaxb-api/2.2.2/jaxb-api-2.2.2.jar:/home/gman/.m2/repository/javax/activation/activation/1.1/activation-1.1.jar:/home/gman/.m2/repository/org/codehaus/jackson/jackson-jaxrs/1.7.1/jackson-jaxrs-1.7.1.jar:/home/gman/.m2/repository/org/codehaus/jackson/jackson-xc/1.7.1/jackson-xc-1.7.1.jar:/home/gman/.m2/repository/com/sun/jersey/contribs/jersey-guice/1.8/jersey-guice-1.8.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-yarn-applications-distributedshell/2.0.5-alpha/hadoop-yarn-applications-distributedshell-2.0.5-alpha.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-yarn-common/2.0.5-alpha/hadoop-yarn-common-2.0.5-alpha.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-common/2.0.5-alpha/hadoop-common-2.0.5-alpha.jar:/home/gman/.m2/repository/com/google/guava/guava/11.0.2/guava-11.0.2.jar:/home/gman/.m2/repository/com/google/code/findbugs/jsr305/1.3.9/jsr305-1.3.9.jar:/home/gman/.m2/repository/commons-cli/commons-cli/1.2/commons-cli-1.2.jar:/home/gman/.m2/repository/org/apache/commons/commons-math/2.1/commons-math-2.1.jar:/home/gman/.m2/repository/xmlenc/xmlenc/0.52/xmlenc-0.52.jar:/home/gman/.m2/repository/commons-httpclient/commons-httpclient/3.1/commons-httpclient-3.1.jar:/home/gman/.m2/repository/commons-codec/commons-codec/1.4/commons-codec-1.4.jar:/home/gman/.m2/repository/commons-net/commons-net/3.1/commons-net-3.1.jar:/home/gman/.m2/repository/javax/servlet/servlet-api/2.5/servlet-api-2.5.jar:/home/gman/.m2/repository/org/mortbay/jetty/jetty/6.1.26/jetty-6.1.26.jar:/home/gman/.m2/repository/org/mortbay/jetty/jetty-util/6.1.26/jetty-util-6.1.26.jar:/home/gman/.m2/repository/com/sun/jersey/jersey-core/1.8/jersey-core-1.8.jar:/home/gman/.m2/repository/tomcat/jasper-compiler/5.5.23/jasper-compiler-5.5.23.jar:/home/gman/.m2/repository/tomcat/jasper-runtime/5.5.23/jasper-runtime-5.5.23.jar:/home/gman/.m2/repository/javax/servlet/jsp/jsp-api/2.1/jsp-api-2.1.jar:/home/gman/.m2/repository/commons-el/commons-el/1.0/commons-el-1.0.jar:/home/gman/.m2/repository/commons-logging/commons-logging/1.1.1/commons-logging-1.1.1.jar:/home/gman/.m2/repository/net/java/dev/jets3t/jets3t/0.6.1/jets3t-0.6.1.jar:/home/gman/.m2/repository/commons-lang/commons-lang/2.5/commons-lang-2.5.jar:/home/gman/.m2/repository/commons-configuration/commons-configuration/1.6/commons-configuration-1.6.jar:/home/gman/.m2/repository/commons-collections/commons-collections/3.2.1/commons-collections-3.2.1.jar:/home/gman/.m2/repository/commons-digester/commons-digester/1.8/commons-digester-1.8.jar:/home/gman/.m2/repository/commons-beanutils/commons-beanutils/1.7.0/commons-beanutils-1.7.0.jar:/home/gman/.m2/repository/commons-beanutils/commons-beanutils-core/1.8.0/commons-beanutils-core-1.8.0.jar:/home/gman/.m2/repository/org/codehaus/jackson/jackson-core-asl/1.8.8/jackson-core-asl-1.8.8.jar:/home/gman/.m2/repository/org/codehaus/jackson/jackson-mapper-asl/1.8.8/jackson-mapper-asl-1.8.8.jar:/home/gman/.m2/repository/org/apache/avro/avro/1.5.3/avro-1.5.3.jar:/home/gman/.m2/repository/com/thoughtworks/paranamer/paranamer/2.3/paranamer-2.3.jar:/home/gman/.m2/repository/org/xerial/snappy/snappy-java/1.0.3.2/snappy-java-1.0.3.2.jar:/home/gman/.m2/repository/net/sf/kosmosfs/kfs/0.3/kfs-0.3.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-auth/2.0.5-alpha/hadoop-auth-2.0.5-alpha.jar:/home/gman/.m2/repository/com/jcraft/jsch/0.1.42/jsch-0.1.42.jar:/home/gman/.m2/repository/org/apache/zookeeper/zookeeper/3.4.2/zookeeper-3.4.2.jar:/home/gman/.m2/repository/log4j/log4j/1.2.17/log4j-1.2.17.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-hdfs/2.0.5-alpha/hadoop-hdfs-2.0.5-alpha.jar:/home/gman/.m2/repository/commons-daemon/commons-daemon/1.0.13/commons-daemon-1.0.13.jar:/home/gman/.m2/repository/org/apache/kafka/0.8/kafka-0.8.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-yarn-api/2.0.5-alpha/hadoop-yarn-api-2.0.5-alpha.jar:/home/gman/.m2/repository/org/apache/hadoop/hadoop-yarn-client/2.0.5-alpha/hadoop-yarn-client-2.0.5-alpha.jar:/home/gman/.m2/repository/org/scala-lang/scala-library/2.8.0/scala-library-2.8.0.jar:/home/gman/.m2/repository/com/yammer/metrics/metrics-core/2.2.0/metrics-core-2.2.0.jar:/home/gman/.m2/repository/com/101tec/zkclient/0.3/zkclient-0.3.jar:/home/gman/.m2/repository/net/sf/jopt-simple/jopt-simple/4.5/jopt-simple-4.5.jar
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.library.path=/usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64/server:/usr/lib/jvm/java-6-openjdk-amd64/jre/lib/amd64:/usr/lib/jvm/java-6-openjdk-amd64/jre/../lib/amd64:/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.io.tmpdir=/tmp
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:java.compiler=<NA>
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:os.name=Linux
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:os.arch=amd64
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:os.version=3.8.0-19-generic
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:user.name=gman
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:user.home=/home/gman
> INFO 2013-07-03 13:47:30,717 [Thread-0] org.apache.zookeeper.ZooKeeper: Client environment:user.dir=/home/gman/workspace/distributed_parser
> INFO 2013-07-03 13:47:30,719 [Thread-0] org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=localhost:2181/kafkatest sessionTimeout=6000 watcher=org.I0Itec.zkclient.ZkClient@661736e
> INFO 2013-07-03 13:47:30,735 [Thread-0-SendThread()] org.apache.zookeeper.ClientCnxn: Opening socket connection to server /127.0.0.1:2181
> INFO 2013-07-03 13:47:30,744 [Thread-0-SendThread(localhost:2181)] org.apache.zookeeper.ClientCnxn: Socket connection established to localhost/127.0.0.1:2181, initiating session
> INFO 2013-07-03 13:47:30,750 [Thread-0-SendThread(localhost:2181)] org.apache.zookeeper.ClientCnxn: Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13f9c3e2c100075, negotiated timeout = 6000
> INFO 2013-07-03 13:47:30,752 [Thread-0-EventThread] org.I0Itec.zkclient.ZkClient: zookeeper state changed (SyncConnected)
> INFO 2013-07-03 13:47:30,805 [Thread-0] kafka.utils.ZkUtils$: Registered broker 1 at path /brokers/ids/1 with address gman-minty:9999.
> INFO 2013-07-03 13:47:30,806 [Thread-0] kafka.server.KafkaServer: [Kafka Server 1], Connecting to ZK: localhost:2181/kafkatest
> INFO 2013-07-03 13:47:30,907 [Thread-0] kafka.utils.Mx4jLoader$: Will not load MX4J, mx4j-tools.jar is not in the classpath
> INFO 2013-07-03 13:47:30,908 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Controller starting up
> INFO 2013-07-03 13:47:30,913 [Thread-0] kafka.server.ZookeeperLeaderElector: 1 successfully elected as leader
> INFO 2013-07-03 13:47:30,914 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Broker 1 starting become controller state transition
> INFO 2013-07-03 13:47:30,923 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Controller 1 incremented epoch to 1
> INFO 2013-07-03 13:47:31,085 [Controller-1-to-broker-1-send-thread] kafka.controller.RequestSendThread: [Controller-1-to-broker-1-send-thread], Starting
> INFO 2013-07-03 13:47:31,085 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Currently active brokers in the cluster: Set(1)
> INFO 2013-07-03 13:47:31,086 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Currently shutting brokers in the cluster: Set()
> INFO 2013-07-03 13:47:31,086 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Current list of topics in the cluster: Set()
> INFO 2013-07-03 13:47:31,089 [Thread-0] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: No state transitions triggered since no partitions are assigned to brokers 1
> INFO 2013-07-03 13:47:31,091 [Thread-0] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: Invoking state change to OnlineReplica for replicas
> INFO 2013-07-03 13:47:31,094 [Thread-0] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: Started replica state machine with initial state -> Map()
> INFO 2013-07-03 13:47:31,096 [Thread-0] kafka.controller.PartitionStateMachine: [Partition state machine on Controller 1]: Started partition state machine with initial state -> Map()
> INFO 2013-07-03 13:47:31,097 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Broker 1 is ready to serve as the new controller with epoch 1
> INFO 2013-07-03 13:47:31,101 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Partitions being reassigned: Map()
> INFO 2013-07-03 13:47:31,101 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Partitions already reassigned: List()
> INFO 2013-07-03 13:47:31,102 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Resuming reassignment of partitions: Map()
> INFO 2013-07-03 13:47:31,104 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Partitions undergoing preferred replica election:
> INFO 2013-07-03 13:47:31,105 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Partitions that completed preferred replica election:
> INFO 2013-07-03 13:47:31,106 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Resuming preferred replica election for partitions:
> INFO 2013-07-03 13:47:31,107 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Starting preferred replica leader election for partitions
> INFO 2013-07-03 13:47:31,108 [Thread-0] kafka.controller.PartitionStateMachine: [Partition state machine on Controller 1]: Invoking state change to OnlinePartition for partitions
> INFO 2013-07-03 13:47:31,113 [Thread-0] kafka.controller.KafkaController: [Controller 1]: Controller startup complete
> INFO 2013-07-03 13:47:31,114 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.server.ZookeeperLeaderElector$LeaderChangeListener: New leader is 1
> INFO 2013-07-03 13:47:31,118 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.ControllerEpochListener: [ControllerEpochListener on 1]: Initialized controller epoch to 1 and zk version 0
> INFO 2013-07-03 13:47:31,128 [Thread-0] kafka.server.KafkaServer: [Kafka Server 1], Started
> INFO 2013-07-03 13:47:31,128 [Thread-0] com.gman.broker.StandaloneBroker: Broker online
> INFO 2013-07-03 13:47:35,663 [kafka-request-handler-0] kafka.server.KafkaApis: [KafkaApi-1] Auto creation of topic page_visits with 1 partitions and replication factor 1 is successful!
> INFO 2013-07-03 13:47:35,681 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.PartitionStateMachine$TopicChangeListener: [TopicChangeListener on Controller 1]: New topics: [Set(page_visits)], deleted topics: [Set()], new partition replica assignment [Map([page_visits,0] -> List(1))]
> INFO 2013-07-03 13:47:35,683 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.KafkaController: [Controller 1]: New topic creation callback for [page_visits,0]
> INFO 2013-07-03 13:47:35,688 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.KafkaController: [Controller 1]: New partition creation callback for [page_visits,0]
> INFO 2013-07-03 13:47:35,689 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.PartitionStateMachine: [Partition state machine on Controller 1]: Invoking state change to NewPartition for partitions [page_visits,0]
> INFO 2013-07-03 13:47:35,726 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: Invoking state change to NewReplica for replicas PartitionAndReplica(page_visits,0,1)
> INFO 2013-07-03 13:47:35,729 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.PartitionStateMachine: [Partition state machine on Controller 1]: Invoking state change to OnlinePartition for partitions [page_visits,0]
> INFO 2013-07-03 13:47:35,752 [kafka-processor-9999-1] kafka.network.Processor: Closing socket connection to /127.0.0.1.
> INFO 2013-07-03 13:47:35,763 [kafka-request-handler-1] kafka.server.ReplicaManager: [Replica Manager on Broker 1]: Handling LeaderAndIsr request Name:LeaderAndIsrRequest;Version:0;Controller:1;ControllerEpoch:1;CorrelationId:6;ClientId:id_1-host_null-port_9999;PartitionState:(page_visits,0) -> (LeaderAndIsrInfo:(Leader:1,ISR:1,LeaderEpoch:0,ControllerEpoch:1),ReplicationFactor:1),AllReplicas:1);Leaders:id:1,host:gman-minty,port:9999
> INFO 2013-07-03 13:47:35,768 [ZkClient-EventThread-17-localhost:2181/kafkatest] kafka.controller.ReplicaStateMachine: [Replica state machine on controller 1]: Invoking state change to OnlineReplica for replicas PartitionAndReplica(page_visits,0,1)
> INFO 2013-07-03 13:47:35,773 [kafka-request-handler-1] kafka.server.ReplicaFetcherManager: [ReplicaFetcherManager on broker 1] Removing fetcher for partition [page_visits,0]
> INFO 2013-07-03 13:47:35,815 [kafka-processor-9999-2] kafka.network.Processor: Closing socket connection to /127.0.0.1.
> INFO 2013-07-03 13:47:35,821 [kafka-request-handler-1] kafka.log.Log: [Kafka Log on Broker 1], Completed load of log page_visits-0 with log end offset 0
> INFO 2013-07-03 13:47:35,822 [kafka-request-handler-1] kafka.log.LogManager: [Log Manager on Broker 1] Created log for partition [page_visits,0] in /home/gman/workspace/distributed_parser/\tmp\embeddedkafka\1372873650268.
> WARN 2013-07-03 13:47:35,823 [kafka-request-handler-1] kafka.server.HighwaterMarkCheckpoint: No highwatermark file is found. Returning 0 as the highwatermark for partition [page_visits,0]
> ERROR 2013-07-03 13:47:35,826 [kafka-request-handler-1] state.change.logger: Error on broker 1 while processing LeaderAndIsr request correlationId 6 received from controller 1 epoch 1 for partition (page_visits,0)
> java.lang.NullPointerException
> at kafka.cluster.Replica.<init>(Replica.scala:35)
> at kafka.cluster.Partition.getOrCreateReplica(Partition.scala:84)
> at kafka.cluster.Partition$$anonfun$1.apply(Partition.scala:149)
> at kafka.cluster.Partition$$anonfun$1.apply(Partition.scala:149)
> at scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:206)
> at scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:206)
> at scala.collection.LinearSeqOptimized$class.foreach(LinearSeqOptimized.scala:61)
> at scala.collection.immutable.List.foreach(List.scala:45)
> at scala.collection.TraversableLike$class.map(TraversableLike.scala:206)
> at scala.collection.immutable.List.map(List.scala:45)
> at kafka.cluster.Partition.makeLeader(Partition.scala:149)
> at kafka.server.ReplicaManager.kafka$server$ReplicaManager$$makeLeader(ReplicaManager.scala:257)
> at kafka.server.ReplicaManager$$anonfun$becomeLeaderOrFollower$3.apply(ReplicaManager.scala:221)
> at kafka.server.ReplicaManager$$anonfun$becomeLeaderOrFollower$3.apply(ReplicaManager.scala:213)
> at scala.collection.immutable.Map$Map1.foreach(Map.scala:105)
> at kafka.server.ReplicaManager.becomeLeaderOrFollower(ReplicaManager.scala:213)
> at kafka.server.KafkaApis.handleLeaderAndIsrRequest(KafkaApis.scala:87)
> at kafka.server.KafkaApis.handle(KafkaApis.scala:70)
> at kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:42)
> at java.lang.Thread.run(Thread.java:679)
> INFO 2013-07-03 13:47:35,830 [kafka-request-handler-1] kafka.server.ReplicaManager: [Replica Manager on Broker 1]: Handled leader and isr request Name:LeaderAndIsrRequest;Version:0;Controller:1;ControllerEpoch:1;CorrelationId:6;ClientId:id_1-host_null-port_9999;PartitionState:(page_visits,0) -> (LeaderAndIsrInfo:(Leader:1,ISR:1,LeaderEpoch:0,ControllerEpoch:1),ReplicationFactor:1),AllReplicas:1);Leaders:id:1,host:gman-minty,port:9999
> INFO 2013-07-03 13:47:35,957 [kafka-processor-9999-0] kafka.network.Processor: Closing socket connection to /127.0.0.1.
> WARN 2013-07-03 13:47:35,999 [kafka-request-handler-5] kafka.server.KafkaApis: [KafkaApi-1] Produce request with correlation id 4 from client on partition [page_visits,0] failed due to Leader not local for partition [page_visits,0] on broker 1
> INFO 2013-07-03 13:47:36,125 [kafka-processor-9999-2] kafka.network.Processor: Closing socket connection to /127.0.0.1.
> INFO 2013-07-03 13:47:36,126 [kafka-processor-9999-1] kafka.network.Processor: Closing socket connection to /127.0.0.1.
> WARN 2013-07-03 13:47:36,127 [kafka-request-handler-7] kafka.server.KafkaApis: [KafkaApi-1] Produce request with correlation id 7 from client on partition [page_visits,0] failed due to Leader not local for partition [page_visits,0] on broker 1
> INFO 2013-07-03 13:47:36,238 [kafka-processor-9999-0] kafka.network.Processor: Closing socket connection to /127.0.0.1.
> INFO 2013-07-03 13:47:36,238 [kafka-processor-9999-1] kafka.network.Processor: Closing socket connection to /127.0.0.1.
> WARN 2013-07-03 13:47:36,242 [kafka-request-handler-3] kafka.server.KafkaApis: [KafkaApi-1] Produce request with correlation id 10 from client on partition [page_visits,0] failed due to Leader not local for partition [page_visits,0] on broker 1
> INFO 2013-07-03 13:47:36,351 [kafka-processor-9999-2] kafka.network.Processor: Closing socket connection to /127.0.0.1.
> INFO 2013-07-03 13:47:36,352 [kafka-processor-9999-0] kafka.network.Processor: Closing socket connection to /127.0.0.1.
--
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