You are viewing a plain text version of this content. The canonical link for it is here.
Posted to jira@kafka.apache.org by GitBox <gi...@apache.org> on 2021/10/28 21:49:37 UTC
[GitHub] [kafka] hachikuji opened a new pull request #11449: MINOR: Log client disconnect events at INFO level
hachikuji opened a new pull request #11449:
URL: https://github.com/apache/kafka/pull/11449
Client disconnects are crucial events for debugging. The fact that we only log them at DEBUG/TRACE means we rarely have them available outside of a testing context. This patch therefore increases verbosity to INFO level. In practice, we already have backoff configurations which should prevent these logs from getting too spammy.
### Committer Checklist (excluded from commit message)
- [ ] Verify design and implementation
- [ ] Verify test coverage and CI build status
- [ ] Verify documentation (including upgrade notes)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [kafka] hachikuji commented on a change in pull request #11449: MINOR: Log client disconnect events at INFO level
Posted by GitBox <gi...@apache.org>.
hachikuji commented on a change in pull request #11449:
URL: https://github.com/apache/kafka/pull/11449#discussion_r745061966
##########
File path: clients/src/main/java/org/apache/kafka/clients/NetworkClient.java
##########
@@ -319,23 +319,29 @@ public void disconnect(String nodeId) {
if (connectionStates.isDisconnected(nodeId))
return;
+ log.info("Client requested disconnect from node {} (invoking callbacks for in-flight requests)", nodeId);
Review comment:
I think it is useful to cover both cases (as well as any future cases). Let me consider adding a disconnect reason.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [kafka] hachikuji commented on a change in pull request #11449: MINOR: Log client disconnect events at INFO level
Posted by GitBox <gi...@apache.org>.
hachikuji commented on a change in pull request #11449:
URL: https://github.com/apache/kafka/pull/11449#discussion_r745072515
##########
File path: clients/src/main/java/org/apache/kafka/clients/NetworkClient.java
##########
@@ -319,23 +319,29 @@ public void disconnect(String nodeId) {
if (connectionStates.isDisconnected(nodeId))
return;
+ log.info("Client requested disconnect from node {} (invoking callbacks for in-flight requests)", nodeId);
Review comment:
I found it a little simpler to add a separate log message for the coordinator case. Let me know if that seems reasonable. In general, I'm not too worried about the verbosity of this message since client-initiated disconnects should be relatively rare (e.g. after session or request timeouts).
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [kafka] guozhangwang commented on a change in pull request #11449: MINOR: Log client disconnect events at INFO level
Posted by GitBox <gi...@apache.org>.
guozhangwang commented on a change in pull request #11449:
URL: https://github.com/apache/kafka/pull/11449#discussion_r740417424
##########
File path: clients/src/main/java/org/apache/kafka/clients/NetworkClient.java
##########
@@ -319,23 +319,29 @@ public void disconnect(String nodeId) {
if (connectionStates.isDisconnected(nodeId))
return;
+ log.info("Client requested disconnect from node {} (invoking callbacks for in-flight requests)", nodeId);
Review comment:
It seems we only have two types of callers for this: 1) admin-client proactively disconnecting, where the caller always log an info explaining why, 2) consumer-client async disconnect the coordinator.
If our target is primarily covering 2) here, what about: 1) make this function `disconnect(nodeId, reason)` where `reason` is a formatted string; 2) rename the `pendingDisconnects` (which is only used for coordinator disconnects) as `pendingCoordinatorDisconnects` and pass in a reason like "since the node was previously recognized as the group coordinator but now it become unknown".
##########
File path: clients/src/main/java/org/apache/kafka/clients/NetworkClient.java
##########
@@ -923,7 +930,7 @@ private void handleApiVersionsResponse(List<ClientResponse> responses,
private void handleDisconnections(List<ClientResponse> responses, long now) {
for (Map.Entry<String, ChannelState> entry : this.selector.disconnected().entrySet()) {
String node = entry.getKey();
- log.debug("Node {} disconnected.", node);
+ log.info("Node {} disconnected.", node);
Review comment:
It makes me thinking: why not consolidating `disconnect` to call `processDisconnections` but have two call paths here?
##########
File path: clients/src/main/java/org/apache/kafka/clients/NetworkClient.java
##########
@@ -355,6 +361,7 @@ private void cancelInFlightRequests(String nodeId, long now, Collection<ClientRe
*/
@Override
public void close(String nodeId) {
+ log.info("Client requested disconnect from node {} (not invoking callbacks for in-flight requests)", nodeId);
Review comment:
nit: request closing the socket from node?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [kafka] guozhangwang commented on pull request #11449: MINOR: Log client disconnect events at INFO level
Posted by GitBox <gi...@apache.org>.
guozhangwang commented on pull request #11449:
URL: https://github.com/apache/kafka/pull/11449#issuecomment-963575647
Sounds good. LGTM!
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [kafka] dajac commented on pull request #11449: MINOR: Log client disconnect events at INFO level
Posted by GitBox <gi...@apache.org>.
dajac commented on pull request #11449:
URL: https://github.com/apache/kafka/pull/11449#issuecomment-965692247
@hachikuji Is it worth cherry-picking this one into 3.1 branch as well?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [kafka] hachikuji commented on pull request #11449: MINOR: Log client disconnect events at INFO level
Posted by GitBox <gi...@apache.org>.
hachikuji commented on pull request #11449:
URL: https://github.com/apache/kafka/pull/11449#issuecomment-954935502
It's worth noting that we already have the WARN log here when a connection cannot be established: https://github.com/apache/kafka/blob/trunk/clients/src/main/java/org/apache/kafka/clients/NetworkClient.java#L766. This is probably the most likely case to be spammy. The other additions from this PR are less common situations such as request timeouts and client-side requests to disconnect.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [kafka] hachikuji commented on a change in pull request #11449: MINOR: Log client disconnect events at INFO level
Posted by GitBox <gi...@apache.org>.
hachikuji commented on a change in pull request #11449:
URL: https://github.com/apache/kafka/pull/11449#discussion_r739414003
##########
File path: clients/src/main/java/org/apache/kafka/clients/NetworkClient.java
##########
@@ -320,21 +320,17 @@ public void disconnect(String nodeId) {
return;
selector.close(nodeId);
- long now = time.milliseconds();
+ log.info("Manually disconnected from {}. Aborted in-flight requests: {}.", nodeId, inFlightRequests);
Review comment:
Ah, yeah. I thought I had fixed that, but looks like I forgot to push.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [kafka] hachikuji merged pull request #11449: MINOR: Log client disconnect events at INFO level
Posted by GitBox <gi...@apache.org>.
hachikuji merged pull request #11449:
URL: https://github.com/apache/kafka/pull/11449
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [kafka] dajac commented on a change in pull request #11449: MINOR: Log client disconnect events at INFO level
Posted by GitBox <gi...@apache.org>.
dajac commented on a change in pull request #11449:
URL: https://github.com/apache/kafka/pull/11449#discussion_r739097403
##########
File path: clients/src/main/java/org/apache/kafka/clients/NetworkClient.java
##########
@@ -320,21 +320,17 @@ public void disconnect(String nodeId) {
return;
selector.close(nodeId);
- long now = time.milliseconds();
+ log.info("Manually disconnected from {}. Aborted in-flight requests: {}.", nodeId, inFlightRequests);
Review comment:
Should we log only the in-flight requests of the node? It seems that this would log them for all nodes.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [kafka] hachikuji commented on pull request #11449: MINOR: Log client disconnect events at INFO level
Posted by GitBox <gi...@apache.org>.
hachikuji commented on pull request #11449:
URL: https://github.com/apache/kafka/pull/11449#issuecomment-954276201
The main thing I am interested in here is disconnects when there are inflight requests, so we can probably be more selective about the logging if there are any concerns.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [kafka] guozhangwang commented on a change in pull request #11449: MINOR: Log client disconnect events at INFO level
Posted by GitBox <gi...@apache.org>.
guozhangwang commented on a change in pull request #11449:
URL: https://github.com/apache/kafka/pull/11449#discussion_r740417424
##########
File path: clients/src/main/java/org/apache/kafka/clients/NetworkClient.java
##########
@@ -319,23 +319,29 @@ public void disconnect(String nodeId) {
if (connectionStates.isDisconnected(nodeId))
return;
+ log.info("Client requested disconnect from node {} (invoking callbacks for in-flight requests)", nodeId);
Review comment:
It seems we only have two types of callers for this: 1) admin-client proactively disconnecting, where the caller always log an info explaining why, 2) consumer-client async disconnect the coordinator.
If our target is primarily covering 2) here, what about: 1) make this function `disconnect(nodeId, reason)` where `reason` is a formatted string; 2) rename the `pendingDisconnects` (which is only used for coordinator disconnects) as `pendingCoordinatorDisconnects` and pass in a reason like "since the node was previously recognized as the group coordinator but now it become unknown".
##########
File path: clients/src/main/java/org/apache/kafka/clients/NetworkClient.java
##########
@@ -923,7 +930,7 @@ private void handleApiVersionsResponse(List<ClientResponse> responses,
private void handleDisconnections(List<ClientResponse> responses, long now) {
for (Map.Entry<String, ChannelState> entry : this.selector.disconnected().entrySet()) {
String node = entry.getKey();
- log.debug("Node {} disconnected.", node);
+ log.info("Node {} disconnected.", node);
Review comment:
It makes me thinking: why not consolidating `disconnect` to call `processDisconnections` but have two call paths here?
##########
File path: clients/src/main/java/org/apache/kafka/clients/NetworkClient.java
##########
@@ -355,6 +361,7 @@ private void cancelInFlightRequests(String nodeId, long now, Collection<ClientRe
*/
@Override
public void close(String nodeId) {
+ log.info("Client requested disconnect from node {} (not invoking callbacks for in-flight requests)", nodeId);
Review comment:
nit: request closing the socket from node?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [kafka] hachikuji commented on a change in pull request #11449: MINOR: Log client disconnect events at INFO level
Posted by GitBox <gi...@apache.org>.
hachikuji commented on a change in pull request #11449:
URL: https://github.com/apache/kafka/pull/11449#discussion_r745071482
##########
File path: clients/src/main/java/org/apache/kafka/clients/NetworkClient.java
##########
@@ -923,7 +930,7 @@ private void handleApiVersionsResponse(List<ClientResponse> responses,
private void handleDisconnections(List<ClientResponse> responses, long now) {
for (Map.Entry<String, ChannelState> entry : this.selector.disconnected().entrySet()) {
String node = entry.getKey();
- log.debug("Node {} disconnected.", node);
+ log.info("Node {} disconnected.", node);
Review comment:
I agree there is room for consolidation, but I was trying to avoid refactoring here. Could we consider this separately?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: jira-unsubscribe@kafka.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org