You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@kafka.apache.org by Jason Weiss <Ja...@rapid7.com> on 2013/05/21 16:35:36 UTC
Closing socket connections during extended message delivery
I've made some good progress on tuning Kafka for our needs, reaching about 40,000 events per second in our environment. One thing that I noticed in all of the Kafka server logs is an inordinate amount (I think?) of Closing socket connection INFO statements.
I realize they are INFO, so I assume they are expected. Can someone point me to a resource or provide a couple sentence overview on the socket strategy here? I'm curious why 6 producer clients, each using 2 threads, are opening and closing sockets so much. That's an expensive operation, and surely it affects performance since these connections are closing anywhere from 2 seconds to 30 seconds (seemingly randomly).
Thanks!
Jason
[2013-05-21 14:31:07,726] INFO Closing socket connection to /10.10.1.133. (kafka.network.Processor)
[2013-05-21 14:31:08,583] INFO Closing socket connection to /10.10.1.132. (kafka.network.Processor)
[2013-05-21 14:31:08,930] INFO Closing socket connection to /10.10.1.130. (kafka.network.Processor)
[2013-05-21 14:31:09,599] INFO Closing socket connection to /10.10.1.133. (kafka.network.Processor)
[2013-05-21 14:31:10,310] INFO Closing socket connection to /10.10.1.67. (kafka.network.Processor)
[2013-05-21 14:31:10,436] INFO Closing socket connection to /10.10.1.131. (kafka.network.Processor)
[2013-05-21 14:31:11,165] INFO Closing socket connection to /10.10.1.134. (kafka.network.Processor)
[2013-05-21 14:31:13,260] INFO Closing socket connection to /10.10.1.67. (kafka.network.Processor)
[2013-05-21 14:31:13,591] INFO Closing socket connection to /10.10.1.134. (kafka.network.Processor)
[2013-05-21 14:31:20,988] INFO Closing socket connection to /10.10.1.130. (kafka.network.Processor)
[2013-05-21 14:31:22,361] INFO Closing socket connection to /10.10.1.132. (kafka.network.Processor)
[2013-05-21 14:31:22,459] INFO Closing socket connection to /10.10.1.133. (kafka.network.Processor)
[2013-05-21 14:31:23,915] INFO Closing socket connection to /10.10.1.131. (kafka.network.Processor)
[2013-05-21 14:31:24,068] INFO Closing socket connection to /10.10.1.132. (kafka.network.Processor)
[2013-05-21 14:31:24,947] INFO Closing socket connection to /10.10.1.130. (kafka.network.Processor)
[2013-05-21 14:31:26,168] INFO Closing socket connection to /10.10.1.131. (kafka.network.Processor)
[2013-05-21 14:31:26,534] INFO Closing socket connection to /10.10.1.133. (kafka.network.Processor)
[2013-05-21 14:31:26,536] INFO Closing socket connection to /10.10.1.67. (kafka.network.Processor)
[2013-05-21 14:31:28,251] INFO Closing socket connection to /10.10.1.134. (kafka.network.Processor)
[2013-05-21 14:31:30,734] INFO Closing socket connection to /10.10.1.67. (kafka.network.Processor)
[2013-05-21 14:31:31,322] INFO Closing socket connection to /10.10.1.134. (kafka.network.Processor)
[2013-05-21 14:31:40,833] INFO Closing socket connection to /10.10.1.130. (kafka.network.Processor)
[2013-05-21 14:31:41,107] INFO Closing socket connection to /10.10.1.133. (kafka.network.Processor)
[2013-05-21 14:31:43,123] INFO Closing socket connection to /10.10.1.132. (kafka.network.Processor)
[2013-05-21 14:31:43,169] INFO Closing socket connection to /10.10.1.131. (kafka.network.Processor)
[2013-05-21 14:31:43,221] INFO Closing socket connection to /10.10.1.132. (kafka.network.Processor)
[2013-05-21 14:31:45,833] INFO Closing socket connection to /10.10.1.130. (kafka.network.Processor)
[2013-05-21 14:31:47,143] INFO Closing socket connection to /10.10.1.133. (kafka.network.Processor)
[2013-05-21 14:31:48,199] INFO Closing socket connection to /10.10.1.131. (kafka.network.Processor)
This electronic message contains information which may be confidential or privileged. The information is intended for the use of the individual or entity named above. If you are not the intended recipient, be aware that any disclosure, copying, distribution or use of the contents of this information is prohibited. If you have received this electronic transmission in error, please notify us by e-mail at (postmaster@rapid7.com) immediately.
Re: Closing socket connections during extended message delivery
Posted by Neha Narkhede <ne...@gmail.com>.
Yes. This was added to get around the VIP hard killing connections that are
idle. If your producer doesn't use a VIP you can set this high enough so it
rarely reconnects.
Thanks,
Neha
On May 21, 2013 8:13 AM, "Jason Weiss" <Ja...@rapid7.com> wrote:
> Ahh - I see, thank you.
>
> Would you describe this as a "tunable" parameter to achieve higher
> performance? For example, is it in a producer's interest to bump this
> figure up to say 250,000 from 30,000?
>
> Thanks again for the prompt response!
>
> Jason
>
>
> On 5/21/13 11:07 AM, "Jun Rao" <ju...@gmail.com> wrote:
>
> >In 0.7, each producer reconnects to the broker periodically. Take a look
> >at
> >reconnect.interval in http://kafka.apache.org/07/configuration.html
> >
> >Thanks,
> >
> >Jun
> >
> >
> >On Tue, May 21, 2013 at 7:35 AM, Jason Weiss <Ja...@rapid7.com>
> >wrote:
> >
> >> I've made some good progress on tuning Kafka for our needs, reaching
> >>about
> >> 40,000 events per second in our environment. One thing that I noticed in
> >> all of the Kafka server logs is an inordinate amount (I think?) of
> >>Closing
> >> socket connection INFO statements.
> >>
> >> I realize they are INFO, so I assume they are expected. Can someone
> >>point
> >> me to a resource or provide a couple sentence overview on the socket
> >> strategy here? I'm curious why 6 producer clients, each using 2 threads,
> >> are opening and closing sockets so much. That's an expensive operation,
> >>and
> >> surely it affects performance since these connections are closing
> >>anywhere
> >> from 2 seconds to 30 seconds (seemingly randomly).
> >>
> >> Thanks!
> >>
> >> Jason
> >>
> >>
> >>
> >> [2013-05-21 14:31:07,726] INFO Closing socket connection to
> >>/10.10.1.133.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:08,583] INFO Closing socket connection to
> >>/10.10.1.132.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:08,930] INFO Closing socket connection to
> >>/10.10.1.130.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:09,599] INFO Closing socket connection to
> >>/10.10.1.133.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:10,310] INFO Closing socket connection to /10.10.1.67
> .
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:10,436] INFO Closing socket connection to
> >>/10.10.1.131.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:11,165] INFO Closing socket connection to
> >>/10.10.1.134.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:13,260] INFO Closing socket connection to /10.10.1.67
> .
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:13,591] INFO Closing socket connection to
> >>/10.10.1.134.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:20,988] INFO Closing socket connection to
> >>/10.10.1.130.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:22,361] INFO Closing socket connection to
> >>/10.10.1.132.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:22,459] INFO Closing socket connection to
> >>/10.10.1.133.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:23,915] INFO Closing socket connection to
> >>/10.10.1.131.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:24,068] INFO Closing socket connection to
> >>/10.10.1.132.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:24,947] INFO Closing socket connection to
> >>/10.10.1.130.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:26,168] INFO Closing socket connection to
> >>/10.10.1.131.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:26,534] INFO Closing socket connection to
> >>/10.10.1.133.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:26,536] INFO Closing socket connection to /10.10.1.67
> .
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:28,251] INFO Closing socket connection to
> >>/10.10.1.134.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:30,734] INFO Closing socket connection to /10.10.1.67
> .
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:31,322] INFO Closing socket connection to
> >>/10.10.1.134.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:40,833] INFO Closing socket connection to
> >>/10.10.1.130.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:41,107] INFO Closing socket connection to
> >>/10.10.1.133.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:43,123] INFO Closing socket connection to
> >>/10.10.1.132.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:43,169] INFO Closing socket connection to
> >>/10.10.1.131.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:43,221] INFO Closing socket connection to
> >>/10.10.1.132.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:45,833] INFO Closing socket connection to
> >>/10.10.1.130.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:47,143] INFO Closing socket connection to
> >>/10.10.1.133.
> >> (kafka.network.Processor)
> >> [2013-05-21 14:31:48,199] INFO Closing socket connection to
> >>/10.10.1.131.
> >> (kafka.network.Processor)
> >>
> >> This electronic message contains information which may be confidential
> >>or
> >> privileged. The information is intended for the use of the individual or
> >> entity named above. If you are not the intended recipient, be aware that
> >> any disclosure, copying, distribution or use of the contents of this
> >> information is prohibited. If you have received this electronic
> >> transmission in error, please notify us by e-mail at (
> >> postmaster@rapid7.com) immediately.
> >>
>
> This electronic message contains information which may be confidential or
> privileged. The information is intended for the use of the individual or
> entity named above. If you are not the intended recipient, be aware that
> any disclosure, copying, distribution or use of the contents of this
> information is prohibited. If you have received this electronic
> transmission in error, please notify us by e-mail at (
> postmaster@rapid7.com) immediately.
>
>
Re: Closing socket connections during extended message delivery
Posted by Jason Weiss <Ja...@rapid7.com>.
Ahh - I see, thank you.
Would you describe this as a "tunable" parameter to achieve higher
performance? For example, is it in a producer's interest to bump this
figure up to say 250,000 from 30,000?
Thanks again for the prompt response!
Jason
On 5/21/13 11:07 AM, "Jun Rao" <ju...@gmail.com> wrote:
>In 0.7, each producer reconnects to the broker periodically. Take a look
>at
>reconnect.interval in http://kafka.apache.org/07/configuration.html
>
>Thanks,
>
>Jun
>
>
>On Tue, May 21, 2013 at 7:35 AM, Jason Weiss <Ja...@rapid7.com>
>wrote:
>
>> I've made some good progress on tuning Kafka for our needs, reaching
>>about
>> 40,000 events per second in our environment. One thing that I noticed in
>> all of the Kafka server logs is an inordinate amount (I think?) of
>>Closing
>> socket connection INFO statements.
>>
>> I realize they are INFO, so I assume they are expected. Can someone
>>point
>> me to a resource or provide a couple sentence overview on the socket
>> strategy here? I'm curious why 6 producer clients, each using 2 threads,
>> are opening and closing sockets so much. That's an expensive operation,
>>and
>> surely it affects performance since these connections are closing
>>anywhere
>> from 2 seconds to 30 seconds (seemingly randomly).
>>
>> Thanks!
>>
>> Jason
>>
>>
>>
>> [2013-05-21 14:31:07,726] INFO Closing socket connection to
>>/10.10.1.133.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:08,583] INFO Closing socket connection to
>>/10.10.1.132.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:08,930] INFO Closing socket connection to
>>/10.10.1.130.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:09,599] INFO Closing socket connection to
>>/10.10.1.133.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:10,310] INFO Closing socket connection to /10.10.1.67.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:10,436] INFO Closing socket connection to
>>/10.10.1.131.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:11,165] INFO Closing socket connection to
>>/10.10.1.134.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:13,260] INFO Closing socket connection to /10.10.1.67.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:13,591] INFO Closing socket connection to
>>/10.10.1.134.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:20,988] INFO Closing socket connection to
>>/10.10.1.130.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:22,361] INFO Closing socket connection to
>>/10.10.1.132.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:22,459] INFO Closing socket connection to
>>/10.10.1.133.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:23,915] INFO Closing socket connection to
>>/10.10.1.131.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:24,068] INFO Closing socket connection to
>>/10.10.1.132.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:24,947] INFO Closing socket connection to
>>/10.10.1.130.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:26,168] INFO Closing socket connection to
>>/10.10.1.131.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:26,534] INFO Closing socket connection to
>>/10.10.1.133.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:26,536] INFO Closing socket connection to /10.10.1.67.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:28,251] INFO Closing socket connection to
>>/10.10.1.134.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:30,734] INFO Closing socket connection to /10.10.1.67.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:31,322] INFO Closing socket connection to
>>/10.10.1.134.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:40,833] INFO Closing socket connection to
>>/10.10.1.130.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:41,107] INFO Closing socket connection to
>>/10.10.1.133.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:43,123] INFO Closing socket connection to
>>/10.10.1.132.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:43,169] INFO Closing socket connection to
>>/10.10.1.131.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:43,221] INFO Closing socket connection to
>>/10.10.1.132.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:45,833] INFO Closing socket connection to
>>/10.10.1.130.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:47,143] INFO Closing socket connection to
>>/10.10.1.133.
>> (kafka.network.Processor)
>> [2013-05-21 14:31:48,199] INFO Closing socket connection to
>>/10.10.1.131.
>> (kafka.network.Processor)
>>
>> This electronic message contains information which may be confidential
>>or
>> privileged. The information is intended for the use of the individual or
>> entity named above. If you are not the intended recipient, be aware that
>> any disclosure, copying, distribution or use of the contents of this
>> information is prohibited. If you have received this electronic
>> transmission in error, please notify us by e-mail at (
>> postmaster@rapid7.com) immediately.
>>
This electronic message contains information which may be confidential or privileged. The information is intended for the use of the individual or entity named above. If you are not the intended recipient, be aware that any disclosure, copying, distribution or use of the contents of this information is prohibited. If you have received this electronic transmission in error, please notify us by e-mail at (postmaster@rapid7.com) immediately.
Re: Closing socket connections during extended message delivery
Posted by Jun Rao <ju...@gmail.com>.
In 0.7, each producer reconnects to the broker periodically. Take a look at
reconnect.interval in http://kafka.apache.org/07/configuration.html
Thanks,
Jun
On Tue, May 21, 2013 at 7:35 AM, Jason Weiss <Ja...@rapid7.com> wrote:
> I've made some good progress on tuning Kafka for our needs, reaching about
> 40,000 events per second in our environment. One thing that I noticed in
> all of the Kafka server logs is an inordinate amount (I think?) of Closing
> socket connection INFO statements.
>
> I realize they are INFO, so I assume they are expected. Can someone point
> me to a resource or provide a couple sentence overview on the socket
> strategy here? I'm curious why 6 producer clients, each using 2 threads,
> are opening and closing sockets so much. That's an expensive operation, and
> surely it affects performance since these connections are closing anywhere
> from 2 seconds to 30 seconds (seemingly randomly).
>
> Thanks!
>
> Jason
>
>
>
> [2013-05-21 14:31:07,726] INFO Closing socket connection to /10.10.1.133.
> (kafka.network.Processor)
> [2013-05-21 14:31:08,583] INFO Closing socket connection to /10.10.1.132.
> (kafka.network.Processor)
> [2013-05-21 14:31:08,930] INFO Closing socket connection to /10.10.1.130.
> (kafka.network.Processor)
> [2013-05-21 14:31:09,599] INFO Closing socket connection to /10.10.1.133.
> (kafka.network.Processor)
> [2013-05-21 14:31:10,310] INFO Closing socket connection to /10.10.1.67.
> (kafka.network.Processor)
> [2013-05-21 14:31:10,436] INFO Closing socket connection to /10.10.1.131.
> (kafka.network.Processor)
> [2013-05-21 14:31:11,165] INFO Closing socket connection to /10.10.1.134.
> (kafka.network.Processor)
> [2013-05-21 14:31:13,260] INFO Closing socket connection to /10.10.1.67.
> (kafka.network.Processor)
> [2013-05-21 14:31:13,591] INFO Closing socket connection to /10.10.1.134.
> (kafka.network.Processor)
> [2013-05-21 14:31:20,988] INFO Closing socket connection to /10.10.1.130.
> (kafka.network.Processor)
> [2013-05-21 14:31:22,361] INFO Closing socket connection to /10.10.1.132.
> (kafka.network.Processor)
> [2013-05-21 14:31:22,459] INFO Closing socket connection to /10.10.1.133.
> (kafka.network.Processor)
> [2013-05-21 14:31:23,915] INFO Closing socket connection to /10.10.1.131.
> (kafka.network.Processor)
> [2013-05-21 14:31:24,068] INFO Closing socket connection to /10.10.1.132.
> (kafka.network.Processor)
> [2013-05-21 14:31:24,947] INFO Closing socket connection to /10.10.1.130.
> (kafka.network.Processor)
> [2013-05-21 14:31:26,168] INFO Closing socket connection to /10.10.1.131.
> (kafka.network.Processor)
> [2013-05-21 14:31:26,534] INFO Closing socket connection to /10.10.1.133.
> (kafka.network.Processor)
> [2013-05-21 14:31:26,536] INFO Closing socket connection to /10.10.1.67.
> (kafka.network.Processor)
> [2013-05-21 14:31:28,251] INFO Closing socket connection to /10.10.1.134.
> (kafka.network.Processor)
> [2013-05-21 14:31:30,734] INFO Closing socket connection to /10.10.1.67.
> (kafka.network.Processor)
> [2013-05-21 14:31:31,322] INFO Closing socket connection to /10.10.1.134.
> (kafka.network.Processor)
> [2013-05-21 14:31:40,833] INFO Closing socket connection to /10.10.1.130.
> (kafka.network.Processor)
> [2013-05-21 14:31:41,107] INFO Closing socket connection to /10.10.1.133.
> (kafka.network.Processor)
> [2013-05-21 14:31:43,123] INFO Closing socket connection to /10.10.1.132.
> (kafka.network.Processor)
> [2013-05-21 14:31:43,169] INFO Closing socket connection to /10.10.1.131.
> (kafka.network.Processor)
> [2013-05-21 14:31:43,221] INFO Closing socket connection to /10.10.1.132.
> (kafka.network.Processor)
> [2013-05-21 14:31:45,833] INFO Closing socket connection to /10.10.1.130.
> (kafka.network.Processor)
> [2013-05-21 14:31:47,143] INFO Closing socket connection to /10.10.1.133.
> (kafka.network.Processor)
> [2013-05-21 14:31:48,199] INFO Closing socket connection to /10.10.1.131.
> (kafka.network.Processor)
>
> This electronic message contains information which may be confidential or
> privileged. The information is intended for the use of the individual or
> entity named above. If you are not the intended recipient, be aware that
> any disclosure, copying, distribution or use of the contents of this
> information is prohibited. If you have received this electronic
> transmission in error, please notify us by e-mail at (
> postmaster@rapid7.com) immediately.
>