Home | About | Sematext search-lucene.com search-hadoop.com
NEW: Monitor These Apps!
elasticsearch, apache solr, apache hbase, hadoop, redis, casssandra, amazon cloudwatch, mysql, memcached, apache kafka, apache zookeeper, apache storm, ubuntu, centOS, red hat, debian, puppet labs, java, senseiDB
 Search Hadoop and all its subprojects:

Switch to Plain View
Kafka >> mail # user >> log file flushing, flushall on clean shutdown...


+
Jason Rosenberg 2013-03-28, 07:39
+
SuoNayi 2013-03-28, 08:47
+
Neha Narkhede 2013-03-28, 13:45
+
Jason Rosenberg 2013-03-28, 15:12
+
Jun Rao 2013-03-28, 15:31
Copy link to this message
-
Re: log file flushing, flushall on clean shutdown...
Ok, sorry,

I see now that in fact, it does close all logs during LogManager.close(),
which deeper in the code flushes logSegments.  So it doesn't do so as
explicitly as in LogManager.flushAllLogs during the normally scheduled
flush interval.

The confusing thing, is that I clearly see my message being sent from the
producer, e.g.:

2013-03-28 10:40:39,090 TRACE [ProducerSendThread-1585330284]
network.BoundedByteBufferSend - 499 bytes written.

Here's the shutdown sequence on the server, which appears to complete
before the last message was sent above:

2013-03-28 10:40:38,660  INFO [Thread-27] server.KafkaServer - Shutting
down Kafka server
2013-03-28 10:40:38,661  INFO [Thread-27] utils.KafkaScheduler - shutdown
scheduler kafka-logcleaner-
2013-03-28 10:40:38,670  INFO [Thread-27] utils.KafkaScheduler - shutdown
scheduler kafka-logflusher-
2013-03-28 10:40:38,673 DEBUG [Thread-27] message.FileMessageSet - flush
time 2
2013-03-28 10:40:38,673 DEBUG [Thread-27] message.FileMessageSet - flush
high water mark:227489
2013-03-28 10:40:38,674 DEBUG [Thread-27] message.FileMessageSet - flush
time 0
2013-03-28 10:40:38,674 DEBUG [Thread-27] message.FileMessageSet - flush
high water mark:37271451
...
...
2013-03-28 10:40:38,683  INFO [Thread-27] server.KafkaServer - Kafka server
shut down completed

So, I am guessing now that the 499 bytes written message was going to a
buffered socket channel, that received the bytes, but didn't actually send
them out at the os level.  No exception is thrown, so I am wondering
whether this socket is ever flushed, or if it just quietly fails to send
its data.  Thoughts?  Even if I switched to use a broker list (instead of
zk for broker discovery), it seems that if no exception is thrown on the
send to a closed broker, there's no way to manage retries, etc.
Looking deeper, it looks like after I call send on my async producer, there
are log messages coming from zk indicating the broker list has changed, but
it's too late for the async producer to reroute the message:

2013-03-28 10:40:38,440 DEBUG [...] producer.Producer - Sending message to
broker ....
2013-03-28 10:40:38,440 DEBUG [...] producer.ProducerPool - Fetching async
producer for broker id: ...
2013-03-28 10:40:38,440 DEBUG [...] producer.ProducerPool - Sending message
<broker shuts down>
2013-03-28 10:40:38,694 DEBUG [ZkClient-EventThread-35-localhost:26101]
producer.ZKBrokerPartitionInfo$BrokerTopicsListener -
[BrokerTopicsListener] List of brokers changed at /brokers/topics/...
...
...
2013-03-28 10:40:39,089 DEBUG [ProducerSendThread-1585330284]
async.ProducerSendThread - 1001 ms elapsed. Queue time reached. Sending..
2013-03-28 10:40:39,089 DEBUG [ProducerSendThread-1585330284]
async.ProducerSendThread - Handling 1 events
2013-03-28 10:40:39,089 TRACE [ProducerSendThread-1585330284]
async.DefaultEventHandler - Handling event for Topic: ...
2013-03-28 10:40:39,090 TRACE [ProducerSendThread-1585330284]
async.DefaultEventHandler - Sending 1 messages with no compression to topic
...
<send still goes to previously shut down broker>
2013-03-28 10:40:39,090 TRACE [ProducerSendThread-1585330284]
network.BoundedByteBufferSend - 499 bytes written.

I saw issue: https://issues.apache.org/jira/browse/KAFKA-253

It seems that this could be relevant.  I'm not sure was that fix ever
applied to 0.7.x?

Will these issues go away with 0.8?

Jason
On Thu, Mar 28, 2013 at 8:31 AM, Jun Rao <[EMAIL PROTECTED]> wrote:
> Jason,
>
> Our shutdown sequence in 0.7 is the following in KafkaServer.shutdown():
>
> 1. close socket channel
> 2. close log manager
> 2.1 for each log
> 2.2   flush last segment and close file channel
>
> So, it does what you are suggesting. All unflushed data are supposed to be
> written to disk on a clean shutdown.
>
> Thanks,
>
> Jun
>
>
> On Thu, Mar 28, 2013 at 8:10 AM, Jason Rosenberg <[EMAIL PROTECTED]> wrote:
>
>> Hi Neha,
>>
>> I enabled TRACE logging on the producer, and verified that it
>> successfully wrote out the bytes to the server (but this was after the
time ago.
<javascript:;>>
a
0.8.

 
+
Neha Narkhede 2013-03-28, 21:19
+
Jason Rosenberg 2013-03-29, 02:09
NEW: Monitor These Apps!
elasticsearch, apache solr, apache hbase, hadoop, redis, casssandra, amazon cloudwatch, mysql, memcached, apache kafka, apache zookeeper, apache storm, ubuntu, centOS, red hat, debian, puppet labs, java, senseiDB