Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

net: Fix handling of upstream connection timeout events. #4040 #4107

Closed
wants to merge 1 commit into from
Closed

net: Fix handling of upstream connection timeout events. #4040 #4107

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
34 changes: 30 additions & 4 deletions src/flb_network.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -446,14 +446,14 @@ static int net_connect_async(int fd,

/* Connection is broken, not much to do here */
str = strerror_r(error, so_error_buf, sizeof(so_error_buf));
flb_error("[net] TCP connection failed: %s:%i (%s)",
u->tcp_host, u->tcp_port, str);
flb_error("[net] TCP connection #%i failed: %s:%i (%s)",
u_conn->fd, u->tcp_host, u->tcp_port, str);
return -1;
}
}
else {
flb_error("[net] TCP connection, unexpected error: %s:%i",
u->tcp_host, u->tcp_port);
flb_error("[net] TCP connection #%i, unexpected error: %s:%i",
u_conn->fd, u->tcp_host, u->tcp_port);
return -1;
}

Expand Down Expand Up @@ -1061,6 +1061,8 @@ flb_sockfd_t flb_net_tcp_connect(const char *host, unsigned long port,
char _port[6];
struct addrinfo hints;
struct addrinfo *res, *rp;
char so_error_buf[256] = {0};
char *str = NULL;

if (is_async == FLB_TRUE && !u_conn) {
flb_error("[net] invalid async mode with not set upstream connection");
Expand All @@ -1081,6 +1083,30 @@ flb_sockfd_t flb_net_tcp_connect(const char *host, unsigned long port,
if (is_async) {
ret = flb_net_getaddrinfo(host, _port, &hints, &res,
u_conn->u->net.dns_mode, connect_timeout);
/*
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Some context to explain this change better:

  1. The check for u_conn->net_error is unconditional by intention and doesn't distinguish between the DNS lookup succeeding or failing.
  2. This is my understanding of the current code base (pseudo-code)
coroutine_1_flb_net_tcp_connect:
dns_lookup_async
----yield/resume_1---
fd = create_socket
conn->fd = fd
tcp_connect_async(fd)
----yield/resume_2---
http_proxy_connect
tls_connect_async
----yield/resume_3---
check tls_connect return val and return connection

coroutine_2_flb_upstream_conn_timeouts:
shutdown(fd) // if fd is not valid, this has no effect
conn->net_error = CONNECT_TIMEOUT
prepare_destroy_conn // delete event, close socket, move connection to pending destroy queue

coroutine_3_flb_upstream_conn_pending_destroy:
for c in pending_destroy_queue:
   destroy_conn(c) //free up connection memory

coroutine_2 and coroutine_3 can execute after any of the yield/resume points in coroutine_1.
3. I saw from logs that the DNS lookup timeout handler can execute very late when the plugin is under load. I want to avoid relying on it.
4. This specific change is for the following scenario that I saw in my logs for the bug:

coroutine_1 
yield/resume_1
coroutine_2
coroutine_3
coroutine_1

Since there is no file descriptor set in the connection object yet, coroutine_1 doesn't know that the connection timeout triggered in upstream. The DNS lookup can succeed or fail. An error must be returned even if DNS succeeded. Otherwise the connection will be returned as a successful connection.

* When the output plugin is under load, DNS timers fire much later than
* they should and DNS lookups are slow as well. It is possible that
* the connection times out via the upstream handler. Since the socket
* has not yet been created, the upstream timeout handler doesn't have
* a valid fd to notify this coroutine on. A check is needed to see if
* the connection timed out even if the DNS lookup succeeded.
* FIXME: Ideally, the upstream timeout handler should be able to
* trigger an action that will cancel pending DNS queries. This could be
* implemented by storing the DNS socket in the upstream connection
* and having the upstream timeout handler call shutdown on it. It
* will need more plumbing through the code.
*/
if (u_conn->net_error > 0) {
str = strerror_r(u_conn->net_error, so_error_buf, sizeof(so_error_buf));
flb_error("[net] TCP connection #%i failed because of an "
"upstream event after resolving DNS: error=%i:(%s)",
u_conn->fd, u_conn->net_error, str);
if (ret == 0 && res != NULL) {
flb_net_free_translated_addrinfo(res);
}
return -1;
}

}
else {
ret = getaddrinfo(host, _port, &hints, &res);
Expand Down
12 changes: 9 additions & 3 deletions src/flb_upstream.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -794,11 +794,17 @@ int flb_upstream_conn_timeouts(struct mk_list *list)
* Shutdown the connection, this is the safest way to indicate
* that the socket cannot longer work and any co-routine on
* waiting for I/O will receive the notification and trigger
* the error to it caller.
* the error to it caller. This only works if the connection
* has a valid fd, which is assigned after the DNS lookup
* succeeds.
* Do not call prepare_destroy_conn here since the connection
* is still pending. It will be handled when the function for
* creating a new connection returns.
*/
shutdown(u_conn->fd, SHUT_RDWR);
if (u_conn->fd > -1) {
shutdown(u_conn->fd, SHUT_RDWR);
}
u_conn->net_error = ETIMEDOUT;
prepare_destroy_conn(u_conn);
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I discussed with @leonardo-albertovich on Slack. He thinks this change may have side effects. I'd like to understand under what scenario prepare_destroy_conn is needed here i.e. the scenario where it wouldn't be handled by the code that is trying to create the connection.

}
}

Expand Down
9 changes: 9 additions & 0 deletions src/tls/flb_tls.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -293,6 +293,8 @@ int flb_tls_session_create(struct flb_tls *tls,
int flag;
struct flb_tls_session *session;
struct flb_upstream *u = u_conn->u;
char so_error_buf[256] = {0};
char *str = NULL;

/* Create TLS session */
session = tls->api->session_create(tls, u_conn);
Expand All @@ -318,6 +320,13 @@ int flb_tls_session_create(struct flb_tls *tls,
ret = tls->api->net_handshake(tls, session);
if (ret != 0) {
if (ret != FLB_TLS_WANT_READ && ret != FLB_TLS_WANT_WRITE) {
if (u_conn->net_error > 0) {
str = strerror_r(u_conn->net_error, so_error_buf, sizeof(so_error_buf));
flb_error("[io_tls] tls handshake for connection #%i to %s:%i "
"failed because of an upstream event: error=%i:(%s)",
u_conn->fd, u->tcp_host, u->tcp_port,
u_conn->net_error, str);
}
goto error;
}

Expand Down