You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@twill.apache.org by Madhu G <ma...@gmail.com> on 2015/08/24 08:23:21 UTC

Kafka errors with hello world example

I am running the hello world example and running into this error

 /usr/java/jdk1.7.0_67-cloudera/bin/java -cp $CP
org.apache.twill.example.yarn.HelloWorld twill-demo-1.mycluster.com:2181



The YARN app runs fine but here is the error


23:11:53.715 [Kafka-Consumer-log-0] INFO
 o.a.t.i.k.client.SimpleKafkaConsumer - Exception when fetching message on
TopicPartition{topic=log, partition=0}.

java.net.ConnectException: Connection refused

at sun.nio.ch.Net.connect0(Native Method) ~[na:1.7.0_67]

at sun.nio.ch.Net.connect(Net.java:465) ~[na:1.7.0_67]

at sun.nio.ch.Net.connect(Net.java:457) ~[na:1.7.0_67]

at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:670)
~[na:1.7.0_67]

at kafka.network.BlockingChannel.connect(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer.connect(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer.reconnect(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer.liftedTree1$1(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at
kafka.consumer.SimpleConsumer.kafka$consumer$SimpleConsumer$$sendRequest(Unknown
Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at
kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply$mcV$sp(Unknown
Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at
kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(Unknown
Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at
kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(Unknown
Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.metrics.KafkaTimer.time(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply$mcV$sp(Unknown
Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.metrics.KafkaTimer.time(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer.fetch(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.javaapi.consumer.SimpleConsumer.fetch(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at
org.apache.twill.internal.kafka.client.SimpleKafkaConsumer$ConsumerThread.fetchMessages(SimpleKafkaConsumer.java:419)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at
org.apache.twill.internal.kafka.client.SimpleKafkaConsumer$ConsumerThread.run(SimpleKafkaConsumer.java:355)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]


----------------------

To give more context, here is the meaningful part of the logs


2015-08-24T06:11:50,807Z INFO  o.a.t.i.a.ApplicationMasterService [
twill-demo-2.mycluster.com] [ApplicationMasterService]
ApplicationMasterService:handleCompleted(ApplicationMasterService.java:449)
- Container container_1440313579459_0019_01_000002 completed with COMPLETE:.

2015-08-24T06:11:50,811Z INFO  o.a.t.i.a.RunningContainers [
twill-demo-2.mycluster.com] [ApplicationMasterService]
RunningContainers:handleCompleted(RunningContainers.java:393) - Container
container_1440313579459_0019_01_000002 exited normally with state COMPLETE

2015-08-24T06:11:50,824Z INFO  o.a.t.i.a.ApplicationMasterService [
twill-demo-2.mycluster.com] [ApplicationMasterService]
ApplicationMasterService:doRun(ApplicationMasterService.java:362) - All
containers completed. Shutting down application master.

2015-08-24T06:11:50,826Z INFO  o.a.t.i.a.ApplicationMasterService [
twill-demo-2.mycluster.com] [ApplicationMasterService]
ApplicationMasterService:doStop(ApplicationMasterService.java:238) - Stop
application master with spec:
{"name":"HelloWorldRunnable","runnables":{"HelloWorldRunnable":{"name":"HelloWorldRunnable","runnable":{"classname":"org.apache.twill.example.yarn.HelloWorld$HelloWorldRunnable","name":"HelloWorldRunnable","arguments":{}},"resources":{"cores":1,"memorySize":512,"instances":1,"uplink":-1,"downlink":-1},"files":[]}},"orders":[{"names":["HelloWorldRunnable"],"type":"STARTED"}],"placementPolicies":[],"handler":{"classname":"org.apache.twill.internal.LogOnlyEventHandler","configs":{}}}

2015-08-24T06:11:50,829Z INFO  o.a.t.i.a.RunningContainers [
twill-demo-2.mycluster.com] [ApplicationMasterService]
RunningContainers:stopAll(RunningContainers.java:332) - Stopping all
instances of HelloWorldRunnable

2015-08-24T06:11:50,829Z INFO  o.a.t.i.a.RunningContainers [
twill-demo-2.mycluster.com] [ApplicationMasterService]
RunningContainers:stopAll(RunningContainers.java:342) - Terminated all
instances of HelloWorldRunnable

2015-08-24T06:11:50,848Z INFO  o.a.t.i.a.ApplicationMasterService [
twill-demo-2.mycluster.com] [ApplicationMasterService]
ApplicationMasterService:cleanupDir(ApplicationMasterService.java:326) -
Application directory deleted: hdfs://
twill-demo-1.mycluster.com:8020/user/root/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871

2015-08-24T06:11:50,848Z INFO  o.a.t.i.AbstractTwillService [
twill-demo-2.mycluster.com] [ApplicationMasterService]
AbstractTwillService:removeLiveNode(AbstractTwillService.java:209) - Remove
live node
twill-demo-1.mycluster.com:2181/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871

2015-08-24T06:11:50,851Z INFO  o.a.t.i.AbstractTwillService [
twill-demo-2.mycluster.com] [ApplicationMasterService]
AbstractTwillService:shutDown(AbstractTwillService.java:190) - Service
ApplicationMasterService with runId 526a193b-e9e0-40ce-99f9-a79b174d2871
shutdown completed

2015-08-24T06:11:50,852Z INFO  o.a.t.i.ServiceMain [
twill-demo-2.mycluster.com] [main] ServiceMain:doMain(ServiceMain.java:100)
- Service ApplicationMasterService [TERMINATED] completed.

23:11:51.859 [IPC Parameter Sending Thread #0] DEBUG
org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032 from root sending #48

23:11:51.861 [IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032 from root got value #48

23:11:51.861
[HelloWorldRunnable-application_1440313579459_0019-yarn-poller] DEBUG
o.a.hadoop.ipc.ProtobufRpcEngine - Call: getApplicationReport took 2ms

23:11:51.863 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
org.apache.zookeeper.ClientCnxn - Reading reply
sessionid:0x14eb5f8db18012f, packet::
clientPath:/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
serverPath:/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
finished:false header:: 34,3  replyHeader:: 34,139514,-101  request::
'/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871,F
 response::

23:11:52.864 [IPC Parameter Sending Thread #0] DEBUG
org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032 from root sending #49

23:11:52.865 [IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032 from root got value #49

23:11:52.866
[HelloWorldRunnable-application_1440313579459_0019-yarn-poller] DEBUG
o.a.hadoop.ipc.ProtobufRpcEngine - Call: getApplicationReport took 3ms

23:11:52.866 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
org.apache.zookeeper.ClientCnxn - Got notification
sessionid:0x14eb5f8db18012f

23:11:52.866 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
org.apache.zookeeper.ClientCnxn - Got WatchedEvent state:SyncConnected
type:NodeDeleted
path:/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/ids/1
for sessionid 0x14eb5f8db18012f

23:11:52.868 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
org.apache.zookeeper.ClientCnxn - Reading reply
sessionid:0x14eb5f8db18012f, packet::
clientPath:/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
serverPath:/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
finished:false header:: 35,3  replyHeader:: 35,139515,-101  request::
'/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871,F
 response::

23:11:53.180 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
org.apache.zookeeper.ClientCnxn - Got notification
sessionid:0x14eb5f8db18012f

23:11:53.180 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
org.apache.zookeeper.ClientCnxn - Got WatchedEvent state:SyncConnected
type:NodeDeleted
path:/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/topics/log/partitions/0/state
for sessionid 0x14eb5f8db18012f

15/08/23 23:11:53 INFO consumer.SimpleConsumer: Reconnect due to socket
error: Connection reset by peer

23:11:53.715 [Kafka-Consumer-log-0] INFO
 o.a.t.i.k.client.SimpleKafkaConsumer - Exception when fetching message on
TopicPartition{topic=log, partition=0}.

java.net.ConnectException: Connection refused

at sun.nio.ch.Net.connect0(Native Method) ~[na:1.7.0_67]

at sun.nio.ch.Net.connect(Net.java:465) ~[na:1.7.0_67]

at sun.nio.ch.Net.connect(Net.java:457) ~[na:1.7.0_67]

at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:670)
~[na:1.7.0_67]

at kafka.network.BlockingChannel.connect(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer.connect(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer.reconnect(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer.liftedTree1$1(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at
kafka.consumer.SimpleConsumer.kafka$consumer$SimpleConsumer$$sendRequest(Unknown
Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at
kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply$mcV$sp(Unknown
Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at
kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(Unknown
Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at
kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(Unknown
Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.metrics.KafkaTimer.time(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply$mcV$sp(Unknown
Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.metrics.KafkaTimer.time(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.consumer.SimpleConsumer.fetch(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at kafka.javaapi.consumer.SimpleConsumer.fetch(Unknown Source)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at
org.apache.twill.internal.kafka.client.SimpleKafkaConsumer$ConsumerThread.fetchMessages(SimpleKafkaConsumer.java:419)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

at
org.apache.twill.internal.kafka.client.SimpleKafkaConsumer$ConsumerThread.run(SimpleKafkaConsumer.java:355)
~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]

23:11:53.719 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
org.apache.zookeeper.ClientCnxn - Reading reply
sessionid:0x14eb5f8db18012f, packet::
clientPath:/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/ids/1
serverPath:/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/ids/1
finished:false header:: 36,3  replyHeader:: 36,139540,-101  request::
'/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/ids/1,T
 response::

23:11:53.720 [Kafka-Consumer-log-0] DEBUG
o.a.t.i.k.client.SimpleKafkaConsumer - No leader for topic partition
TopicPartition{topic=log, partition=0}.

23:11:53.870 [IPC Parameter Sending Thread #0] DEBUG
org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032 from root sending #50

23:11:53.872 [IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032 from root got value #50

23:11:53.872
[HelloWorldRunnable-application_1440313579459_0019-yarn-poller] DEBUG
o.a.hadoop.ipc.ProtobufRpcEngine - Call: getApplicationReport took 2ms

23:11:53.872
[HelloWorldRunnable-application_1440313579459_0019-yarn-poller] DEBUG
o.a.twill.yarn.YarnTwillController - Stop polling status from Yarn for
HelloWorldRunnable application_1440313579459_0019.

23:11:53.873
[HelloWorldRunnable-application_1440313579459_0019-yarn-poller] INFO
 o.a.twill.yarn.YarnTwillController - Yarn application HelloWorldRunnable
application_1440313579459_0019 completed. Shutting down controller.

23:11:53.879 [IPC Parameter Sending Thread #0] DEBUG
org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032 from root sending #51

23:11:53.880 [IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032 from root got value #51

23:11:53.880 [ STOPPING] DEBUG o.a.hadoop.ipc.ProtobufRpcEngine - Call:
getApplicationReport took 1ms

23:11:53.881 [ STOPPING] DEBUG o.a.twill.yarn.YarnTwillController - Yarn
application HelloWorldRunnable application_1440313579459_0019 completed
with status SUCCEEDED

23:11:53.881 [ STOPPING] INFO  o.a.t.i.k.client.SimpleKafkaConsumer -
Requesting stop of all consumer threads.

23:11:53.881 [ STOPPING] INFO  o.a.t.i.k.client.SimpleKafkaConsumer -
Terminate requested Kafka-Consumer-log-0

23:11:53.882 [ STOPPING] INFO  o.a.t.i.k.client.SimpleKafkaConsumer - Wait
for all consumer threads to stop.

23:11:53.882 [ STOPPING] INFO  o.a.t.i.k.client.SimpleKafkaConsumer - All
consumer threads stopped.

23:11:53.886 [ZKKafkaClientService STOPPING] INFO
 o.a.t.i.k.c.ZKKafkaClientService - Stopping KafkaClientService

23:11:53.886 [ZKKafkaClientService STOPPING] INFO
 o.a.t.i.k.client.SimpleKafkaConsumer - Stopping Kafka consumer

23:11:53.886 [ZKKafkaClientService STOPPING] INFO
 o.a.t.i.k.client.SimpleKafkaConsumer - Kafka Consumer stopped

23:11:53.888 [ZKKafkaClientService STOPPING] INFO
 o.a.t.i.k.c.ZKKafkaClientService - KafkaClientService stopped

23:11:53.960 [Thread-2] DEBUG org.apache.hadoop.ipc.Client - stopping
client from cache: org.apache.hadoop.ipc.Client@231556b

23:11:53.975 [zk-client-EventThread] DEBUG org.apache.zookeeper.ZooKeeper -
Closing session: 0x14eb5f8db18012f

23:11:53.975 [zk-client-EventThread] DEBUG org.apache.zookeeper.ClientCnxn
- Closing client for session: 0x14eb5f8db18012f

23:11:53.977 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
org.apache.zookeeper.ClientCnxn - Reading reply
sessionid:0x14eb5f8db18012f, packet:: clientPath:null serverPath:null
finished:false header:: 37,-11  replyHeader:: 37,139541,0  request:: null
response:: null

23:11:53.977 [zk-client-EventThread] DEBUG org.apache.zookeeper.ClientCnxn
- Disconnecting client for session: 0x14eb5f8db18012f

23:11:53.977 [zk-client-EventThread] INFO  org.apache.zookeeper.ZooKeeper -
Session: 0x14eb5f8db18012f closed

23:11:53.977 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
org.apache.zookeeper.ClientCnxn - An exception was thrown while closing
send thread for session 0x14eb5f8db18012f : Unable to read additional data
from server sessionid 0x14eb5f8db18012f, likely server has closed socket

23:11:53.977 [ STARTING-EventThread] INFO  org.apache.zookeeper.ClientCnxn
- EventThread shut down

23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
o.a.hadoop.service.AbstractService - Service:
org.apache.hadoop.yarn.client.api.impl.YarnClientImpl entered state STOPPED

23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
org.apache.hadoop.ipc.Client - stopping client from cache:
org.apache.hadoop.ipc.Client@231556b

23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
org.apache.hadoop.ipc.Client - removing client from cache:
org.apache.hadoop.ipc.Client@231556b

23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
org.apache.hadoop.ipc.Client - stopping actual client because no more
references remain: org.apache.hadoop.ipc.Client@231556b

23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
org.apache.hadoop.ipc.Client - Stopping client

23:11:53.979 [IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032 from root: closed

23:11:53.979 [IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
twill-demo-1.mycluster.com/172.26.22.109:8032 from root: stopped, remaining
connections 0

Re: Kafka errors with hello world example

Posted by gowrishankar p <go...@gmail.com>.
Hi Madhu,

In HelloWorld app, we add LogHanlder to print log messages to stdout
``addLogHandler(new PrinterLogHandler(new PrintWriter(System.out, true)))``

when we add LogHandler, We start a Kafka Consumer thread in Client that
polls Kafka Server (Started when AM Starts) and prints the fetched log
messages to stdout.

When the AM stops, we stop the kafka server, the stack trace is because
there is a race where we make request to fetch message after the Kafka
Server has stopped. We can improve the error logging in this case to make
this clearer, but this does not impact the functionality.

I have created an issue to improve error logging here -
https://issues.apache.org/jira/browse/TWILL-151

Thanks
Shankar

On Mon, Aug 24, 2015 at 1:21 PM, Henry Saputra <he...@gmail.com>
wrote:

> Hi Madhu,
>
> This is probably come from embed Kafka running in Twill application.
>
> Will take a look more to see if I could reproduce.
>
> - Henry
>
> On Sun, Aug 23, 2015 at 11:23 PM, Madhu G <ma...@gmail.com> wrote:
> > I am running the hello world example and running into this error
> >
> >  /usr/java/jdk1.7.0_67-cloudera/bin/java -cp $CP
> > org.apache.twill.example.yarn.HelloWorld twill-demo-1.mycluster.com:2181
> >
> >
> >
> > The YARN app runs fine but here is the error
> >
> >
> > 23:11:53.715 [Kafka-Consumer-log-0] INFO
> >  o.a.t.i.k.client.SimpleKafkaConsumer - Exception when fetching message
> on
> > TopicPartition{topic=log, partition=0}.
> >
> > java.net.ConnectException: Connection refused
> >
> > at sun.nio.ch.Net.connect0(Native Method) ~[na:1.7.0_67]
> >
> > at sun.nio.ch.Net.connect(Net.java:465) ~[na:1.7.0_67]
> >
> > at sun.nio.ch.Net.connect(Net.java:457) ~[na:1.7.0_67]
> >
> > at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:670)
> > ~[na:1.7.0_67]
> >
> > at kafka.network.BlockingChannel.connect(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer.connect(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer.reconnect(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer.liftedTree1$1(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at
> >
> kafka.consumer.SimpleConsumer.kafka$consumer$SimpleConsumer$$sendRequest(Unknown
> > Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at
> >
> kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply$mcV$sp(Unknown
> > Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at
> >
> kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(Unknown
> > Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at
> >
> kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(Unknown
> > Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.metrics.KafkaTimer.time(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply$mcV$sp(Unknown
> > Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.metrics.KafkaTimer.time(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer.fetch(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.javaapi.consumer.SimpleConsumer.fetch(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at
> >
> org.apache.twill.internal.kafka.client.SimpleKafkaConsumer$ConsumerThread.fetchMessages(SimpleKafkaConsumer.java:419)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at
> >
> org.apache.twill.internal.kafka.client.SimpleKafkaConsumer$ConsumerThread.run(SimpleKafkaConsumer.java:355)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> >
> > ----------------------
> >
> > To give more context, here is the meaningful part of the logs
> >
> >
> > 2015-08-24T06:11:50,807Z INFO  o.a.t.i.a.ApplicationMasterService [
> > twill-demo-2.mycluster.com] [ApplicationMasterService]
> >
> ApplicationMasterService:handleCompleted(ApplicationMasterService.java:449)
> > - Container container_1440313579459_0019_01_000002 completed with
> COMPLETE:.
> >
> > 2015-08-24T06:11:50,811Z INFO  o.a.t.i.a.RunningContainers [
> > twill-demo-2.mycluster.com] [ApplicationMasterService]
> > RunningContainers:handleCompleted(RunningContainers.java:393) - Container
> > container_1440313579459_0019_01_000002 exited normally with state
> COMPLETE
> >
> > 2015-08-24T06:11:50,824Z INFO  o.a.t.i.a.ApplicationMasterService [
> > twill-demo-2.mycluster.com] [ApplicationMasterService]
> > ApplicationMasterService:doRun(ApplicationMasterService.java:362) - All
> > containers completed. Shutting down application master.
> >
> > 2015-08-24T06:11:50,826Z INFO  o.a.t.i.a.ApplicationMasterService [
> > twill-demo-2.mycluster.com] [ApplicationMasterService]
> > ApplicationMasterService:doStop(ApplicationMasterService.java:238) - Stop
> > application master with spec:
> >
> {"name":"HelloWorldRunnable","runnables":{"HelloWorldRunnable":{"name":"HelloWorldRunnable","runnable":{"classname":"org.apache.twill.example.yarn.HelloWorld$HelloWorldRunnable","name":"HelloWorldRunnable","arguments":{}},"resources":{"cores":1,"memorySize":512,"instances":1,"uplink":-1,"downlink":-1},"files":[]}},"orders":[{"names":["HelloWorldRunnable"],"type":"STARTED"}],"placementPolicies":[],"handler":{"classname":"org.apache.twill.internal.LogOnlyEventHandler","configs":{}}}
> >
> > 2015-08-24T06:11:50,829Z INFO  o.a.t.i.a.RunningContainers [
> > twill-demo-2.mycluster.com] [ApplicationMasterService]
> > RunningContainers:stopAll(RunningContainers.java:332) - Stopping all
> > instances of HelloWorldRunnable
> >
> > 2015-08-24T06:11:50,829Z INFO  o.a.t.i.a.RunningContainers [
> > twill-demo-2.mycluster.com] [ApplicationMasterService]
> > RunningContainers:stopAll(RunningContainers.java:342) - Terminated all
> > instances of HelloWorldRunnable
> >
> > 2015-08-24T06:11:50,848Z INFO  o.a.t.i.a.ApplicationMasterService [
> > twill-demo-2.mycluster.com] [ApplicationMasterService]
> > ApplicationMasterService:cleanupDir(ApplicationMasterService.java:326) -
> > Application directory deleted: hdfs://
> >
> twill-demo-1.mycluster.com:8020/user/root/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871
> >
> > 2015-08-24T06:11:50,848Z INFO  o.a.t.i.AbstractTwillService [
> > twill-demo-2.mycluster.com] [ApplicationMasterService]
> > AbstractTwillService:removeLiveNode(AbstractTwillService.java:209) -
> Remove
> > live node
> >
> twill-demo-1.mycluster.com:2181/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
> >
> > 2015-08-24T06:11:50,851Z INFO  o.a.t.i.AbstractTwillService [
> > twill-demo-2.mycluster.com] [ApplicationMasterService]
> > AbstractTwillService:shutDown(AbstractTwillService.java:190) - Service
> > ApplicationMasterService with runId 526a193b-e9e0-40ce-99f9-a79b174d2871
> > shutdown completed
> >
> > 2015-08-24T06:11:50,852Z INFO  o.a.t.i.ServiceMain [
> > twill-demo-2.mycluster.com] [main]
> ServiceMain:doMain(ServiceMain.java:100)
> > - Service ApplicationMasterService [TERMINATED] completed.
> >
> > 23:11:51.859 [IPC Parameter Sending Thread #0] DEBUG
> > org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032 from root sending #48
> >
> > 23:11:51.861 [IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
> > org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032 from root got value #48
> >
> > 23:11:51.861
> > [HelloWorldRunnable-application_1440313579459_0019-yarn-poller] DEBUG
> > o.a.hadoop.ipc.ProtobufRpcEngine - Call: getApplicationReport took 2ms
> >
> > 23:11:51.863 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)]
> DEBUG
> > org.apache.zookeeper.ClientCnxn - Reading reply
> > sessionid:0x14eb5f8db18012f, packet::
> >
> clientPath:/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
> >
> serverPath:/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
> > finished:false header:: 34,3  replyHeader:: 34,139514,-101  request::
> > '/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871,F
> >  response::
> >
> > 23:11:52.864 [IPC Parameter Sending Thread #0] DEBUG
> > org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032 from root sending #49
> >
> > 23:11:52.865 [IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
> > org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032 from root got value #49
> >
> > 23:11:52.866
> > [HelloWorldRunnable-application_1440313579459_0019-yarn-poller] DEBUG
> > o.a.hadoop.ipc.ProtobufRpcEngine - Call: getApplicationReport took 3ms
> >
> > 23:11:52.866 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)]
> DEBUG
> > org.apache.zookeeper.ClientCnxn - Got notification
> > sessionid:0x14eb5f8db18012f
> >
> > 23:11:52.866 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)]
> DEBUG
> > org.apache.zookeeper.ClientCnxn - Got WatchedEvent state:SyncConnected
> > type:NodeDeleted
> >
> path:/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/ids/1
> > for sessionid 0x14eb5f8db18012f
> >
> > 23:11:52.868 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)]
> DEBUG
> > org.apache.zookeeper.ClientCnxn - Reading reply
> > sessionid:0x14eb5f8db18012f, packet::
> >
> clientPath:/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
> >
> serverPath:/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
> > finished:false header:: 35,3  replyHeader:: 35,139515,-101  request::
> > '/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871,F
> >  response::
> >
> > 23:11:53.180 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)]
> DEBUG
> > org.apache.zookeeper.ClientCnxn - Got notification
> > sessionid:0x14eb5f8db18012f
> >
> > 23:11:53.180 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)]
> DEBUG
> > org.apache.zookeeper.ClientCnxn - Got WatchedEvent state:SyncConnected
> > type:NodeDeleted
> >
> path:/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/topics/log/partitions/0/state
> > for sessionid 0x14eb5f8db18012f
> >
> > 15/08/23 23:11:53 INFO consumer.SimpleConsumer: Reconnect due to socket
> > error: Connection reset by peer
> >
> > 23:11:53.715 [Kafka-Consumer-log-0] INFO
> >  o.a.t.i.k.client.SimpleKafkaConsumer - Exception when fetching message
> on
> > TopicPartition{topic=log, partition=0}.
> >
> > java.net.ConnectException: Connection refused
> >
> > at sun.nio.ch.Net.connect0(Native Method) ~[na:1.7.0_67]
> >
> > at sun.nio.ch.Net.connect(Net.java:465) ~[na:1.7.0_67]
> >
> > at sun.nio.ch.Net.connect(Net.java:457) ~[na:1.7.0_67]
> >
> > at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:670)
> > ~[na:1.7.0_67]
> >
> > at kafka.network.BlockingChannel.connect(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer.connect(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer.reconnect(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer.liftedTree1$1(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at
> >
> kafka.consumer.SimpleConsumer.kafka$consumer$SimpleConsumer$$sendRequest(Unknown
> > Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at
> >
> kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply$mcV$sp(Unknown
> > Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at
> >
> kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(Unknown
> > Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at
> >
> kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(Unknown
> > Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.metrics.KafkaTimer.time(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply$mcV$sp(Unknown
> > Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.metrics.KafkaTimer.time(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.consumer.SimpleConsumer.fetch(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at kafka.javaapi.consumer.SimpleConsumer.fetch(Unknown Source)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at
> >
> org.apache.twill.internal.kafka.client.SimpleKafkaConsumer$ConsumerThread.fetchMessages(SimpleKafkaConsumer.java:419)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > at
> >
> org.apache.twill.internal.kafka.client.SimpleKafkaConsumer$ConsumerThread.run(SimpleKafkaConsumer.java:355)
> >
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
> >
> > 23:11:53.719 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)]
> DEBUG
> > org.apache.zookeeper.ClientCnxn - Reading reply
> > sessionid:0x14eb5f8db18012f, packet::
> >
> clientPath:/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/ids/1
> >
> serverPath:/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/ids/1
> > finished:false header:: 36,3  replyHeader:: 36,139540,-101  request::
> >
> '/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/ids/1,T
> >  response::
> >
> > 23:11:53.720 [Kafka-Consumer-log-0] DEBUG
> > o.a.t.i.k.client.SimpleKafkaConsumer - No leader for topic partition
> > TopicPartition{topic=log, partition=0}.
> >
> > 23:11:53.870 [IPC Parameter Sending Thread #0] DEBUG
> > org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032 from root sending #50
> >
> > 23:11:53.872 [IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
> > org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032 from root got value #50
> >
> > 23:11:53.872
> > [HelloWorldRunnable-application_1440313579459_0019-yarn-poller] DEBUG
> > o.a.hadoop.ipc.ProtobufRpcEngine - Call: getApplicationReport took 2ms
> >
> > 23:11:53.872
> > [HelloWorldRunnable-application_1440313579459_0019-yarn-poller] DEBUG
> > o.a.twill.yarn.YarnTwillController - Stop polling status from Yarn for
> > HelloWorldRunnable application_1440313579459_0019.
> >
> > 23:11:53.873
> > [HelloWorldRunnable-application_1440313579459_0019-yarn-poller] INFO
> >  o.a.twill.yarn.YarnTwillController - Yarn application HelloWorldRunnable
> > application_1440313579459_0019 completed. Shutting down controller.
> >
> > 23:11:53.879 [IPC Parameter Sending Thread #0] DEBUG
> > org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032 from root sending #51
> >
> > 23:11:53.880 [IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
> > org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032 from root got value #51
> >
> > 23:11:53.880 [ STOPPING] DEBUG o.a.hadoop.ipc.ProtobufRpcEngine - Call:
> > getApplicationReport took 1ms
> >
> > 23:11:53.881 [ STOPPING] DEBUG o.a.twill.yarn.YarnTwillController - Yarn
> > application HelloWorldRunnable application_1440313579459_0019 completed
> > with status SUCCEEDED
> >
> > 23:11:53.881 [ STOPPING] INFO  o.a.t.i.k.client.SimpleKafkaConsumer -
> > Requesting stop of all consumer threads.
> >
> > 23:11:53.881 [ STOPPING] INFO  o.a.t.i.k.client.SimpleKafkaConsumer -
> > Terminate requested Kafka-Consumer-log-0
> >
> > 23:11:53.882 [ STOPPING] INFO  o.a.t.i.k.client.SimpleKafkaConsumer -
> Wait
> > for all consumer threads to stop.
> >
> > 23:11:53.882 [ STOPPING] INFO  o.a.t.i.k.client.SimpleKafkaConsumer - All
> > consumer threads stopped.
> >
> > 23:11:53.886 [ZKKafkaClientService STOPPING] INFO
> >  o.a.t.i.k.c.ZKKafkaClientService - Stopping KafkaClientService
> >
> > 23:11:53.886 [ZKKafkaClientService STOPPING] INFO
> >  o.a.t.i.k.client.SimpleKafkaConsumer - Stopping Kafka consumer
> >
> > 23:11:53.886 [ZKKafkaClientService STOPPING] INFO
> >  o.a.t.i.k.client.SimpleKafkaConsumer - Kafka Consumer stopped
> >
> > 23:11:53.888 [ZKKafkaClientService STOPPING] INFO
> >  o.a.t.i.k.c.ZKKafkaClientService - KafkaClientService stopped
> >
> > 23:11:53.960 [Thread-2] DEBUG org.apache.hadoop.ipc.Client - stopping
> > client from cache: org.apache.hadoop.ipc.Client@231556b
> >
> > 23:11:53.975 [zk-client-EventThread] DEBUG
> org.apache.zookeeper.ZooKeeper -
> > Closing session: 0x14eb5f8db18012f
> >
> > 23:11:53.975 [zk-client-EventThread] DEBUG
> org.apache.zookeeper.ClientCnxn
> > - Closing client for session: 0x14eb5f8db18012f
> >
> > 23:11:53.977 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)]
> DEBUG
> > org.apache.zookeeper.ClientCnxn - Reading reply
> > sessionid:0x14eb5f8db18012f, packet:: clientPath:null serverPath:null
> > finished:false header:: 37,-11  replyHeader:: 37,139541,0  request:: null
> > response:: null
> >
> > 23:11:53.977 [zk-client-EventThread] DEBUG
> org.apache.zookeeper.ClientCnxn
> > - Disconnecting client for session: 0x14eb5f8db18012f
> >
> > 23:11:53.977 [zk-client-EventThread] INFO
> org.apache.zookeeper.ZooKeeper -
> > Session: 0x14eb5f8db18012f closed
> >
> > 23:11:53.977 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)]
> DEBUG
> > org.apache.zookeeper.ClientCnxn - An exception was thrown while closing
> > send thread for session 0x14eb5f8db18012f : Unable to read additional
> data
> > from server sessionid 0x14eb5f8db18012f, likely server has closed socket
> >
> > 23:11:53.977 [ STARTING-EventThread] INFO
> org.apache.zookeeper.ClientCnxn
> > - EventThread shut down
> >
> > 23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
> > o.a.hadoop.service.AbstractService - Service:
> > org.apache.hadoop.yarn.client.api.impl.YarnClientImpl entered state
> STOPPED
> >
> > 23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
> > org.apache.hadoop.ipc.Client - stopping client from cache:
> > org.apache.hadoop.ipc.Client@231556b
> >
> > 23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
> > org.apache.hadoop.ipc.Client - removing client from cache:
> > org.apache.hadoop.ipc.Client@231556b
> >
> > 23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
> > org.apache.hadoop.ipc.Client - stopping actual client because no more
> > references remain: org.apache.hadoop.ipc.Client@231556b
> >
> > 23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
> > org.apache.hadoop.ipc.Client - Stopping client
> >
> > 23:11:53.979 [IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
> > org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032 from root: closed
> >
> > 23:11:53.979 [IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
> > org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> > twill-demo-1.mycluster.com/172.26.22.109:8032 from root: stopped,
> remaining
> > connections 0
>

Re: Kafka errors with hello world example

Posted by Henry Saputra <he...@gmail.com>.
Hi Madhu,

This is probably come from embed Kafka running in Twill application.

Will take a look more to see if I could reproduce.

- Henry

On Sun, Aug 23, 2015 at 11:23 PM, Madhu G <ma...@gmail.com> wrote:
> I am running the hello world example and running into this error
>
>  /usr/java/jdk1.7.0_67-cloudera/bin/java -cp $CP
> org.apache.twill.example.yarn.HelloWorld twill-demo-1.mycluster.com:2181
>
>
>
> The YARN app runs fine but here is the error
>
>
> 23:11:53.715 [Kafka-Consumer-log-0] INFO
>  o.a.t.i.k.client.SimpleKafkaConsumer - Exception when fetching message on
> TopicPartition{topic=log, partition=0}.
>
> java.net.ConnectException: Connection refused
>
> at sun.nio.ch.Net.connect0(Native Method) ~[na:1.7.0_67]
>
> at sun.nio.ch.Net.connect(Net.java:465) ~[na:1.7.0_67]
>
> at sun.nio.ch.Net.connect(Net.java:457) ~[na:1.7.0_67]
>
> at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:670)
> ~[na:1.7.0_67]
>
> at kafka.network.BlockingChannel.connect(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer.connect(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer.reconnect(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer.liftedTree1$1(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at
> kafka.consumer.SimpleConsumer.kafka$consumer$SimpleConsumer$$sendRequest(Unknown
> Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at
> kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply$mcV$sp(Unknown
> Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at
> kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(Unknown
> Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at
> kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(Unknown
> Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.metrics.KafkaTimer.time(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply$mcV$sp(Unknown
> Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.metrics.KafkaTimer.time(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer.fetch(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.javaapi.consumer.SimpleConsumer.fetch(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at
> org.apache.twill.internal.kafka.client.SimpleKafkaConsumer$ConsumerThread.fetchMessages(SimpleKafkaConsumer.java:419)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at
> org.apache.twill.internal.kafka.client.SimpleKafkaConsumer$ConsumerThread.run(SimpleKafkaConsumer.java:355)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
>
> ----------------------
>
> To give more context, here is the meaningful part of the logs
>
>
> 2015-08-24T06:11:50,807Z INFO  o.a.t.i.a.ApplicationMasterService [
> twill-demo-2.mycluster.com] [ApplicationMasterService]
> ApplicationMasterService:handleCompleted(ApplicationMasterService.java:449)
> - Container container_1440313579459_0019_01_000002 completed with COMPLETE:.
>
> 2015-08-24T06:11:50,811Z INFO  o.a.t.i.a.RunningContainers [
> twill-demo-2.mycluster.com] [ApplicationMasterService]
> RunningContainers:handleCompleted(RunningContainers.java:393) - Container
> container_1440313579459_0019_01_000002 exited normally with state COMPLETE
>
> 2015-08-24T06:11:50,824Z INFO  o.a.t.i.a.ApplicationMasterService [
> twill-demo-2.mycluster.com] [ApplicationMasterService]
> ApplicationMasterService:doRun(ApplicationMasterService.java:362) - All
> containers completed. Shutting down application master.
>
> 2015-08-24T06:11:50,826Z INFO  o.a.t.i.a.ApplicationMasterService [
> twill-demo-2.mycluster.com] [ApplicationMasterService]
> ApplicationMasterService:doStop(ApplicationMasterService.java:238) - Stop
> application master with spec:
> {"name":"HelloWorldRunnable","runnables":{"HelloWorldRunnable":{"name":"HelloWorldRunnable","runnable":{"classname":"org.apache.twill.example.yarn.HelloWorld$HelloWorldRunnable","name":"HelloWorldRunnable","arguments":{}},"resources":{"cores":1,"memorySize":512,"instances":1,"uplink":-1,"downlink":-1},"files":[]}},"orders":[{"names":["HelloWorldRunnable"],"type":"STARTED"}],"placementPolicies":[],"handler":{"classname":"org.apache.twill.internal.LogOnlyEventHandler","configs":{}}}
>
> 2015-08-24T06:11:50,829Z INFO  o.a.t.i.a.RunningContainers [
> twill-demo-2.mycluster.com] [ApplicationMasterService]
> RunningContainers:stopAll(RunningContainers.java:332) - Stopping all
> instances of HelloWorldRunnable
>
> 2015-08-24T06:11:50,829Z INFO  o.a.t.i.a.RunningContainers [
> twill-demo-2.mycluster.com] [ApplicationMasterService]
> RunningContainers:stopAll(RunningContainers.java:342) - Terminated all
> instances of HelloWorldRunnable
>
> 2015-08-24T06:11:50,848Z INFO  o.a.t.i.a.ApplicationMasterService [
> twill-demo-2.mycluster.com] [ApplicationMasterService]
> ApplicationMasterService:cleanupDir(ApplicationMasterService.java:326) -
> Application directory deleted: hdfs://
> twill-demo-1.mycluster.com:8020/user/root/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871
>
> 2015-08-24T06:11:50,848Z INFO  o.a.t.i.AbstractTwillService [
> twill-demo-2.mycluster.com] [ApplicationMasterService]
> AbstractTwillService:removeLiveNode(AbstractTwillService.java:209) - Remove
> live node
> twill-demo-1.mycluster.com:2181/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
>
> 2015-08-24T06:11:50,851Z INFO  o.a.t.i.AbstractTwillService [
> twill-demo-2.mycluster.com] [ApplicationMasterService]
> AbstractTwillService:shutDown(AbstractTwillService.java:190) - Service
> ApplicationMasterService with runId 526a193b-e9e0-40ce-99f9-a79b174d2871
> shutdown completed
>
> 2015-08-24T06:11:50,852Z INFO  o.a.t.i.ServiceMain [
> twill-demo-2.mycluster.com] [main] ServiceMain:doMain(ServiceMain.java:100)
> - Service ApplicationMasterService [TERMINATED] completed.
>
> 23:11:51.859 [IPC Parameter Sending Thread #0] DEBUG
> org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032 from root sending #48
>
> 23:11:51.861 [IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
> org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032 from root got value #48
>
> 23:11:51.861
> [HelloWorldRunnable-application_1440313579459_0019-yarn-poller] DEBUG
> o.a.hadoop.ipc.ProtobufRpcEngine - Call: getApplicationReport took 2ms
>
> 23:11:51.863 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
> org.apache.zookeeper.ClientCnxn - Reading reply
> sessionid:0x14eb5f8db18012f, packet::
> clientPath:/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
> serverPath:/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
> finished:false header:: 34,3  replyHeader:: 34,139514,-101  request::
> '/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871,F
>  response::
>
> 23:11:52.864 [IPC Parameter Sending Thread #0] DEBUG
> org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032 from root sending #49
>
> 23:11:52.865 [IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
> org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032 from root got value #49
>
> 23:11:52.866
> [HelloWorldRunnable-application_1440313579459_0019-yarn-poller] DEBUG
> o.a.hadoop.ipc.ProtobufRpcEngine - Call: getApplicationReport took 3ms
>
> 23:11:52.866 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
> org.apache.zookeeper.ClientCnxn - Got notification
> sessionid:0x14eb5f8db18012f
>
> 23:11:52.866 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
> org.apache.zookeeper.ClientCnxn - Got WatchedEvent state:SyncConnected
> type:NodeDeleted
> path:/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/ids/1
> for sessionid 0x14eb5f8db18012f
>
> 23:11:52.868 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
> org.apache.zookeeper.ClientCnxn - Reading reply
> sessionid:0x14eb5f8db18012f, packet::
> clientPath:/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
> serverPath:/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871
> finished:false header:: 35,3  replyHeader:: 35,139515,-101  request::
> '/HelloWorldRunnable/instances/526a193b-e9e0-40ce-99f9-a79b174d2871,F
>  response::
>
> 23:11:53.180 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
> org.apache.zookeeper.ClientCnxn - Got notification
> sessionid:0x14eb5f8db18012f
>
> 23:11:53.180 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
> org.apache.zookeeper.ClientCnxn - Got WatchedEvent state:SyncConnected
> type:NodeDeleted
> path:/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/topics/log/partitions/0/state
> for sessionid 0x14eb5f8db18012f
>
> 15/08/23 23:11:53 INFO consumer.SimpleConsumer: Reconnect due to socket
> error: Connection reset by peer
>
> 23:11:53.715 [Kafka-Consumer-log-0] INFO
>  o.a.t.i.k.client.SimpleKafkaConsumer - Exception when fetching message on
> TopicPartition{topic=log, partition=0}.
>
> java.net.ConnectException: Connection refused
>
> at sun.nio.ch.Net.connect0(Native Method) ~[na:1.7.0_67]
>
> at sun.nio.ch.Net.connect(Net.java:465) ~[na:1.7.0_67]
>
> at sun.nio.ch.Net.connect(Net.java:457) ~[na:1.7.0_67]
>
> at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:670)
> ~[na:1.7.0_67]
>
> at kafka.network.BlockingChannel.connect(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer.connect(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer.reconnect(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer.liftedTree1$1(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at
> kafka.consumer.SimpleConsumer.kafka$consumer$SimpleConsumer$$sendRequest(Unknown
> Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at
> kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply$mcV$sp(Unknown
> Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at
> kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(Unknown
> Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at
> kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(Unknown
> Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.metrics.KafkaTimer.time(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply$mcV$sp(Unknown
> Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.metrics.KafkaTimer.time(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.consumer.SimpleConsumer.fetch(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at kafka.javaapi.consumer.SimpleConsumer.fetch(Unknown Source)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at
> org.apache.twill.internal.kafka.client.SimpleKafkaConsumer$ConsumerThread.fetchMessages(SimpleKafkaConsumer.java:419)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> at
> org.apache.twill.internal.kafka.client.SimpleKafkaConsumer$ConsumerThread.run(SimpleKafkaConsumer.java:355)
> ~[twill-examples-yarn-0.7.0-incubating-SNAPSHOT.jar:0.7.0-incubating-SNAPSHOT]
>
> 23:11:53.719 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
> org.apache.zookeeper.ClientCnxn - Reading reply
> sessionid:0x14eb5f8db18012f, packet::
> clientPath:/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/ids/1
> serverPath:/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/ids/1
> finished:false header:: 36,3  replyHeader:: 36,139540,-101  request::
> '/HelloWorldRunnable/526a193b-e9e0-40ce-99f9-a79b174d2871/kafka/brokers/ids/1,T
>  response::
>
> 23:11:53.720 [Kafka-Consumer-log-0] DEBUG
> o.a.t.i.k.client.SimpleKafkaConsumer - No leader for topic partition
> TopicPartition{topic=log, partition=0}.
>
> 23:11:53.870 [IPC Parameter Sending Thread #0] DEBUG
> org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032 from root sending #50
>
> 23:11:53.872 [IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
> org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032 from root got value #50
>
> 23:11:53.872
> [HelloWorldRunnable-application_1440313579459_0019-yarn-poller] DEBUG
> o.a.hadoop.ipc.ProtobufRpcEngine - Call: getApplicationReport took 2ms
>
> 23:11:53.872
> [HelloWorldRunnable-application_1440313579459_0019-yarn-poller] DEBUG
> o.a.twill.yarn.YarnTwillController - Stop polling status from Yarn for
> HelloWorldRunnable application_1440313579459_0019.
>
> 23:11:53.873
> [HelloWorldRunnable-application_1440313579459_0019-yarn-poller] INFO
>  o.a.twill.yarn.YarnTwillController - Yarn application HelloWorldRunnable
> application_1440313579459_0019 completed. Shutting down controller.
>
> 23:11:53.879 [IPC Parameter Sending Thread #0] DEBUG
> org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032 from root sending #51
>
> 23:11:53.880 [IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
> org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032 from root got value #51
>
> 23:11:53.880 [ STOPPING] DEBUG o.a.hadoop.ipc.ProtobufRpcEngine - Call:
> getApplicationReport took 1ms
>
> 23:11:53.881 [ STOPPING] DEBUG o.a.twill.yarn.YarnTwillController - Yarn
> application HelloWorldRunnable application_1440313579459_0019 completed
> with status SUCCEEDED
>
> 23:11:53.881 [ STOPPING] INFO  o.a.t.i.k.client.SimpleKafkaConsumer -
> Requesting stop of all consumer threads.
>
> 23:11:53.881 [ STOPPING] INFO  o.a.t.i.k.client.SimpleKafkaConsumer -
> Terminate requested Kafka-Consumer-log-0
>
> 23:11:53.882 [ STOPPING] INFO  o.a.t.i.k.client.SimpleKafkaConsumer - Wait
> for all consumer threads to stop.
>
> 23:11:53.882 [ STOPPING] INFO  o.a.t.i.k.client.SimpleKafkaConsumer - All
> consumer threads stopped.
>
> 23:11:53.886 [ZKKafkaClientService STOPPING] INFO
>  o.a.t.i.k.c.ZKKafkaClientService - Stopping KafkaClientService
>
> 23:11:53.886 [ZKKafkaClientService STOPPING] INFO
>  o.a.t.i.k.client.SimpleKafkaConsumer - Stopping Kafka consumer
>
> 23:11:53.886 [ZKKafkaClientService STOPPING] INFO
>  o.a.t.i.k.client.SimpleKafkaConsumer - Kafka Consumer stopped
>
> 23:11:53.888 [ZKKafkaClientService STOPPING] INFO
>  o.a.t.i.k.c.ZKKafkaClientService - KafkaClientService stopped
>
> 23:11:53.960 [Thread-2] DEBUG org.apache.hadoop.ipc.Client - stopping
> client from cache: org.apache.hadoop.ipc.Client@231556b
>
> 23:11:53.975 [zk-client-EventThread] DEBUG org.apache.zookeeper.ZooKeeper -
> Closing session: 0x14eb5f8db18012f
>
> 23:11:53.975 [zk-client-EventThread] DEBUG org.apache.zookeeper.ClientCnxn
> - Closing client for session: 0x14eb5f8db18012f
>
> 23:11:53.977 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
> org.apache.zookeeper.ClientCnxn - Reading reply
> sessionid:0x14eb5f8db18012f, packet:: clientPath:null serverPath:null
> finished:false header:: 37,-11  replyHeader:: 37,139541,0  request:: null
> response:: null
>
> 23:11:53.977 [zk-client-EventThread] DEBUG org.apache.zookeeper.ClientCnxn
> - Disconnecting client for session: 0x14eb5f8db18012f
>
> 23:11:53.977 [zk-client-EventThread] INFO  org.apache.zookeeper.ZooKeeper -
> Session: 0x14eb5f8db18012f closed
>
> 23:11:53.977 [ STARTING-SendThread(twill-demo-1.mycluster.com:2181)] DEBUG
> org.apache.zookeeper.ClientCnxn - An exception was thrown while closing
> send thread for session 0x14eb5f8db18012f : Unable to read additional data
> from server sessionid 0x14eb5f8db18012f, likely server has closed socket
>
> 23:11:53.977 [ STARTING-EventThread] INFO  org.apache.zookeeper.ClientCnxn
> - EventThread shut down
>
> 23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
> o.a.hadoop.service.AbstractService - Service:
> org.apache.hadoop.yarn.client.api.impl.YarnClientImpl entered state STOPPED
>
> 23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
> org.apache.hadoop.ipc.Client - stopping client from cache:
> org.apache.hadoop.ipc.Client@231556b
>
> 23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
> org.apache.hadoop.ipc.Client - removing client from cache:
> org.apache.hadoop.ipc.Client@231556b
>
> 23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
> org.apache.hadoop.ipc.Client - stopping actual client because no more
> references remain: org.apache.hadoop.ipc.Client@231556b
>
> 23:11:53.978 [Hadoop21YarnAppClient STOPPING] DEBUG
> org.apache.hadoop.ipc.Client - Stopping client
>
> 23:11:53.979 [IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
> org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032 from root: closed
>
> 23:11:53.979 [IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032from root] DEBUG
> org.apache.hadoop.ipc.Client - IPC Client (2014438912) connection to
> twill-demo-1.mycluster.com/172.26.22.109:8032 from root: stopped, remaining
> connections 0