Closing connection messages

[Rajiv Kurian <ra...@signalfx.com>]

My broker logs are full of messages of the following type of log message:

INFO  [kafka-network-thread-9092-1        ] [kafka.network.Processor
      ]: Closing socket connection to /some_ip_that_I_know.

I see at least one every 4-5  seconds. Something I identified was that the
ip of the closed clients was always from one class of application. This
application mostly consumes kafka partitions (rarely produces) and it uses
the SimpleConsumer to consume data, make requests about partition
leadership (to keep it up to date) and to also make requests about the
latest offset in a set of partitions (for metrics).

The data consumption happens with long running consumers, but the one off
requests like partition leadership requests and offset queries happen with
short-lived consumers that are closed after a request is served. However
the volume of closing "Closing socket connection" log messages is higher
than what I think the rate of these short lived requests should be. My
guess is that something else is going on.

Is there a way for me to track what client is exactly having its connection
closed? Each of my SimpleConsumer clients uses a particular client name
when connecting to the broker. Is there a way to enable additional logging
which would give me this data along with the "Closing socket connection"
message?

Thanks,

Rajiv

Re: Closing connection messages

[Rajiv Kurian <ra...@signalfx.com>]

Thanks Todd. I figured out the problem on my client end (independent of
these messages being kind of noisy). My SimpleConsumer was querying every
broker (instead of only the brokers it needed to talk to) for offset
requests every one minute. Given I have more than 50 clients every server
received about one message per second. The verbose log actually helped me
figure out my problem. I know only ask the leader of a partition for its
offsets.

Thanks!

On Thu, Sep 17, 2015 at 3:39 PM, Todd Palino <tp...@gmail.com> wrote:

> This message is regarding a normal connection close. You see it in the logs
> for any connection - consumers, producers, replica fetchers. It can be
> particularly noisy because metadata requests often happen on their own
> connection.
>
> The log message has been moved to debug level in recent commits (it
> actually was changed a while back but snuck back in with one of the larger
> sets of changes). In general, I'd say you should just ignore it for now.
>
> -Todd
>
>
> On Wed, Sep 16, 2015 at 9:55 PM, Rajiv Kurian <ra...@signalfx.com> wrote:
>
> > My broker logs are full of messages of the following type of log message:
> >
> > INFO  [kafka-network-thread-9092-1        ] [kafka.network.Processor
> >       ]: Closing socket connection to /some_ip_that_I_know.
> >
> > I see at least one every 4-5  seconds. Something I identified was that
> the
> > ip of the closed clients was always from one class of application. This
> > application mostly consumes kafka partitions (rarely produces) and it
> uses
> > the SimpleConsumer to consume data, make requests about partition
> > leadership (to keep it up to date) and to also make requests about the
> > latest offset in a set of partitions (for metrics).
> >
> > The data consumption happens with long running consumers, but the one off
> > requests like partition leadership requests and offset queries happen
> with
> > short-lived consumers that are closed after a request is served. However
> > the volume of closing "Closing socket connection" log messages is higher
> > than what I think the rate of these short lived requests should be. My
> > guess is that something else is going on.
> >
> > Is there a way for me to track what client is exactly having its
> connection
> > closed? Each of my SimpleConsumer clients uses a particular client name
> > when connecting to the broker. Is there a way to enable additional
> logging
> > which would give me this data along with the "Closing socket connection"
> > message?
> >
> > Thanks,
> >
> > Rajiv
> >
>

Re: Closing connection messages

[Todd Palino <tp...@gmail.com>]

This message is regarding a normal connection close. You see it in the logs
for any connection - consumers, producers, replica fetchers. It can be
particularly noisy because metadata requests often happen on their own
connection.

The log message has been moved to debug level in recent commits (it
actually was changed a while back but snuck back in with one of the larger
sets of changes). In general, I'd say you should just ignore it for now.

-Todd


On Wed, Sep 16, 2015 at 9:55 PM, Rajiv Kurian <ra...@signalfx.com> wrote:

> My broker logs are full of messages of the following type of log message:
>
> INFO  [kafka-network-thread-9092-1        ] [kafka.network.Processor
>       ]: Closing socket connection to /some_ip_that_I_know.
>
> I see at least one every 4-5  seconds. Something I identified was that the
> ip of the closed clients was always from one class of application. This
> application mostly consumes kafka partitions (rarely produces) and it uses
> the SimpleConsumer to consume data, make requests about partition
> leadership (to keep it up to date) and to also make requests about the
> latest offset in a set of partitions (for metrics).
>
> The data consumption happens with long running consumers, but the one off
> requests like partition leadership requests and offset queries happen with
> short-lived consumers that are closed after a request is served. However
> the volume of closing "Closing socket connection" log messages is higher
> than what I think the rate of these short lived requests should be. My
> guess is that something else is going on.
>
> Is there a way for me to track what client is exactly having its connection
> closed? Each of my SimpleConsumer clients uses a particular client name
> when connecting to the broker. Is there a way to enable additional logging
> which would give me this data along with the "Closing socket connection"
> message?
>
> Thanks,
>
> Rajiv
>