[KAFKA-2252] Socket connection closing is logged, but not corresponding opening of socket

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 0.9.0.0
• Assignee: Gwen Shapira
• Reporter: Jason Rosenberg
• Created: 04/Jun/15 20:52
• Updated: 16/Jun/15 22:38
• Resolved: 16/Jun/15 22:38

Description

(using 0.8.2.1)
We see a large number of "Closing socket connection" logging to the broker logs, e.g.:

2015-06-04 16:49:30,262  INFO [kafka-network-thread-27330-2] network.Processor - Closing socket connection to /1.2.3.4.
2015-06-04 16:49:30,262  INFO [kafka-network-thread-27330-0] network.Processor - Closing socket connection to /5.6.7.8.
2015-06-04 16:49:30,695  INFO [kafka-network-thread-27330-0] network.Processor - Closing socket connection to /9.10.11.12.
2015-06-04 16:49:31,465  INFO [kafka-network-thread-27330-1] network.Processor - Closing socket connection to /13.14.15.16.
2015-06-04 16:49:31,806  INFO [kafka-network-thread-27330-0] network.Processor - Closing socket connection to /17.18.19.20.
2015-06-04 16:49:31,842  INFO [kafka-network-thread-27330-2] network.Processor - Closing socket connection to /21.22.23.24.

However, we have no corresponding logging for when these connections are established. Consequently, it's not very useful to see a flood of closed connections, etc. I'd think we'd want to see the corresponding 'connection established' messages, also logged as INFO.

Occasionally, we see a flood of the above messages, and have no idea as to whether it indicates a problem, etc. (Sometimes it might be due to an ongoing rolling restart, or a change in the Zookeeper cluster).