This is an automated email from the ASF dual-hosted git repository.
kgiusti pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/qpid-dispatch.git
The following commit(s) were added to refs/heads/main by this push:
new 7203487 DISPATCH-2268: fix misleading log messages in the HTTP/1.x
adaptor
7203487 is described below
commit 72034876c94aee730ef5b1556f1c86c9685103f1
Author: Kenneth Giusti <kgiu...@apache.org>
AuthorDate: Fri Oct 29 15:23:22 2021 -0400
DISPATCH-2268: fix misleading log messages in the HTTP/1.x adaptor
---
src/adaptors/http1/http1_adaptor.c | 14 ++++++++------
src/adaptors/http1/http1_client.c | 22 ++++++++++++++++------
src/adaptors/http1/http1_private.h | 7 +++----
src/adaptors/http1/http1_server.c | 31 ++++++++++++++++++++-----------
4 files changed, 47 insertions(+), 27 deletions(-)
diff --git a/src/adaptors/http1/http1_adaptor.c
b/src/adaptors/http1/http1_adaptor.c
index 3828e89..86f782a 100644
--- a/src/adaptors/http1/http1_adaptor.c
+++ b/src/adaptors/http1/http1_adaptor.c
@@ -603,15 +603,17 @@ static void _core_conn_close(void *context,
qdr_connection_t *conn, qdr_error_t
qdr_http1_connection_t *hconn = (qdr_http1_connection_t*)
qdr_connection_get_context(conn);
if (hconn) {
assert(hconn->qdr_conn == conn);
- qd_log(qdr_http1_adaptor->log, QD_LOG_TRACE,
- "[C%"PRIu64"] HTTP/1.x closing connection", hconn->conn_id);
+ char *desc = error ? qdr_error_description(error) : 0;
+
+ qd_log(qdr_http1_adaptor->log, QD_LOG_INFO,
+ "[C%"PRIu64"] HTTP/1.x %s", hconn->conn_id,
+ desc ? desc : "connection closed by management");
- char *qdr_error = error ? qdr_error_description(error) : 0;
if (hconn->type == HTTP1_CONN_SERVER)
- qdr_http1_server_core_conn_close(qdr_http1_adaptor, hconn,
qdr_error);
+ qdr_http1_server_core_conn_close(qdr_http1_adaptor, hconn);
else
- qdr_http1_client_core_conn_close(qdr_http1_adaptor, hconn,
qdr_error);
- free(qdr_error);
+ qdr_http1_client_core_conn_close(qdr_http1_adaptor, hconn);
+ free(desc);
}
}
diff --git a/src/adaptors/http1/http1_client.c
b/src/adaptors/http1/http1_client.c
index fa73560..938b63f 100644
--- a/src/adaptors/http1/http1_client.c
+++ b/src/adaptors/http1/http1_client.c
@@ -24,6 +24,7 @@
#include <proton/listener.h>
#include <proton/proactor.h>
+#include <proton/netaddr.h>
//
@@ -201,7 +202,7 @@ static void _handle_listener_events(pn_event_t *e,
qd_server_t *qd_server, void
}
case PN_LISTENER_ACCEPT: {
- qd_log(log, QD_LOG_INFO, "Accepting HTTP/1.x connection on %s",
host_port);
+ qd_log(log, QD_LOG_DEBUG, "Accepting HTTP/1.x connection on %s",
host_port);
qdr_http1_connection_t *hconn = _create_client_connection(li);
if (hconn) {
// Note: the proactor may schedule the hconn on another thread
@@ -450,6 +451,16 @@ static void _handle_connection_events(pn_event_t *e,
qd_server_t *qd_server, voi
case PN_RAW_CONNECTION_CONNECTED: {
_setup_client_connection(hconn);
+
+ const struct pn_netaddr_t *na =
pn_raw_connection_remote_addr(hconn->raw_conn);
+ if (na) {
+ char buf[128];
+ if (pn_netaddr_str(na, buf, sizeof(buf)) > 0) {
+ qd_log(log, QD_LOG_INFO,
+ "[C%"PRIu64"] HTTP/1.x client connection established
from %s",
+ hconn->conn_id, buf);
+ }
+ }
break;
}
case PN_RAW_CONNECTION_CLOSED_READ: {
@@ -463,7 +474,7 @@ static void _handle_connection_events(pn_event_t *e,
qd_server_t *qd_server, voi
break;
}
case PN_RAW_CONNECTION_DISCONNECTED: {
- qd_log(log, QD_LOG_INFO, "[C%"PRIu64"] Disconnected", hconn->conn_id);
+ qd_log(log, QD_LOG_INFO, "[C%"PRIu64"] HTTP/1.x client disconnected",
hconn->conn_id);
pn_raw_connection_set_context(hconn->raw_conn, 0);
// prevent core from waking this connection
@@ -621,7 +632,7 @@ static void _handle_connection_events(pn_event_t *e,
qd_server_t *qd_server, voi
}
if (need_close)
- qdr_http1_close_connection(hconn, "Connection: close");
+ qdr_http1_close_connection(hconn, 0);
else {
hreq = (_client_request_t*) DEQ_HEAD(hconn->requests);
if (hreq) {
@@ -1792,14 +1803,13 @@ void
qdr_http1_client_conn_cleanup(qdr_http1_connection_t *hconn)
// handle connection close request from management
//
void qdr_http1_client_core_conn_close(qdr_http1_adaptor_t *adaptor,
- qdr_http1_connection_t *hconn,
- const char *error)
+ qdr_http1_connection_t *hconn)
{
// initiate close of the raw conn. the adaptor will call
// qdr_connection_close() and clean up once the DISCONNECT
// event is processed
//
- qdr_http1_close_connection(hconn, error);
+ qdr_http1_close_connection(hconn, 0);
}
static void _deliver_request(qdr_http1_connection_t *hconn, _client_request_t
*hreq)
diff --git a/src/adaptors/http1/http1_private.h
b/src/adaptors/http1/http1_private.h
index 1d4a987..39bbd1b 100644
--- a/src/adaptors/http1/http1_private.h
+++ b/src/adaptors/http1/http1_private.h
@@ -241,8 +241,8 @@ void
qdr_http1_client_core_delivery_update(qdr_http1_adaptor_t *adaptor,
bool settled);
void qdr_http1_client_conn_cleanup(qdr_http1_connection_t *hconn);
void qdr_http1_client_core_conn_close(qdr_http1_adaptor_t *adaptor,
- qdr_http1_connection_t *hconn,
- const char *error);
+ qdr_http1_connection_t *hconn);
+
// http1_server.c protocol adaptor callbacks
//
void qdr_http1_server_core_link_flow(qdr_http1_adaptor_t *adaptor,
@@ -262,8 +262,7 @@ void
qdr_http1_server_core_delivery_update(qdr_http1_adaptor_t *adaptor,
bool settled);
void qdr_http1_server_conn_cleanup(qdr_http1_connection_t *hconn);
void qdr_http1_server_core_conn_close(qdr_http1_adaptor_t *adaptor,
- qdr_http1_connection_t *hconn,
- const char *error);
+ qdr_http1_connection_t *hconn);
// recording of stats:
void qdr_http1_record_client_request_info(qdr_http1_adaptor_t *adaptor,
qdr_http1_request_base_t *request);
diff --git a/src/adaptors/http1/http1_server.c
b/src/adaptors/http1/http1_server.c
index a2e93bd..a410a18 100644
--- a/src/adaptors/http1/http1_server.c
+++ b/src/adaptors/http1/http1_server.c
@@ -153,7 +153,7 @@ static qdr_http1_connection_t
*_create_server_connection(qd_http_connector_t *ct
ZERO(hconn);
hconn->type = HTTP1_CONN_SERVER;
hconn->admin_status = QD_CONN_ADMIN_ENABLED;
- hconn->oper_status = QD_CONN_OPER_UP;
+ hconn->oper_status = QD_CONN_OPER_DOWN; // until TCP connection ready
hconn->qd_server = qd->server;
hconn->adaptor = qdr_http1_adaptor;
hconn->handler_context.handler = &_handle_connection_events;
@@ -542,6 +542,11 @@ static void _handle_connection_events(pn_event_t *e,
qd_server_t *qd_server, voi
switch (pn_event_type(e)) {
case PN_RAW_CONNECTION_CONNECTED: {
+ if (hconn->oper_status == QD_CONN_OPER_DOWN) {
+ hconn->oper_status = QD_CONN_OPER_UP;
+ qd_log(log, QD_LOG_INFO, "[C%"PRIu64"] HTTP/1.x server %s
connection established",
+ hconn->conn_id, hconn->cfg.host_port);
+ }
hconn->server.link_timeout = 0;
_setup_server_links(hconn);
while (qdr_connection_process(hconn->qdr_conn)) {}
@@ -571,8 +576,6 @@ static void _handle_connection_events(pn_event_t *e,
qd_server_t *qd_server, voi
break;
}
case PN_RAW_CONNECTION_DISCONNECTED: {
- qd_log(log, QD_LOG_INFO, "[C%"PRIu64"] Connection closed",
hconn->conn_id);
-
pn_raw_connection_set_context(hconn->raw_conn, 0);
// Check for a request that is in-progress - it needs to be cancelled.
@@ -600,8 +603,16 @@ static void _handle_connection_events(pn_event_t *e,
qd_server_t *qd_server, voi
hconn->server.link_timeout = qd_timer_now() +
LINK_TIMEOUT_MSEC;
hconn->server.reconnect_pause = 0;
} else {
- if ((qd_timer_now() - hconn->server.link_timeout) >= 0)
+ if ((qd_timer_now() - hconn->server.link_timeout) >= 0) {
_teardown_server_links(hconn);
+ // at this point we've unbound the service address so no
+ // more messages will be sent to us. Notify meatspace:
+ if (hconn->oper_status == QD_CONN_OPER_UP) {
+ hconn->oper_status = QD_CONN_OPER_DOWN;
+ qd_log(log, QD_LOG_INFO, "[C%"PRIu64"] HTTP/1.x server
%s disconnected",
+ hconn->conn_id, hconn->cfg.host_port);
+ }
+ }
if (hconn->server.reconnect_pause < RETRY_MAX_PAUSE_MSEC)
hconn->server.reconnect_pause += RETRY_PAUSE_MSEC;
}
@@ -677,8 +688,8 @@ static void _handle_connection_events(pn_event_t *e,
qd_server_t *qd_server, voi
} else {
bool need_close = _process_request((_server_request_t*)
DEQ_HEAD(hconn->requests));
if (need_close) {
- qd_log(log, QD_LOG_DEBUG, "[C%"PRIu64"] Closing connection!",
hconn->conn_id);
- qdr_http1_close_connection(hconn, "HTTP Request requires
connection close");
+ qd_log(log, QD_LOG_DEBUG, "[C%"PRIu64"] HTTP Request requires
connection close", hconn->conn_id);
+ qdr_http1_close_connection(hconn, 0);
}
}
}
@@ -1723,13 +1734,11 @@ static void _cancel_request(_server_request_t *hreq)
// handle connection close request from management
//
void qdr_http1_server_core_conn_close(qdr_http1_adaptor_t *adaptor,
- qdr_http1_connection_t *hconn,
- const char *error)
+ qdr_http1_connection_t *hconn)
{
- qdr_connection_t *qdr_conn = hconn->qdr_conn;
-
// prevent activation by core thread
sys_mutex_lock(qdr_http1_adaptor->lock);
+ qdr_connection_t *qdr_conn = hconn->qdr_conn;
qdr_connection_set_context(hconn->qdr_conn, 0);
hconn->qdr_conn = 0;
sys_mutex_unlock(qdr_http1_adaptor->lock);
@@ -1738,7 +1747,7 @@ void qdr_http1_server_core_conn_close(qdr_http1_adaptor_t
*adaptor,
hconn->oper_status = QD_CONN_OPER_DOWN;
_teardown_server_links(hconn);
qdr_connection_closed(qdr_conn);
- qdr_http1_close_connection(hconn, error);
+ qdr_http1_close_connection(hconn, 0);
// it is expected that this callback is the final callback before returning
// from qdr_connection_process(). Free hconn when qdr_connection_process
returns.
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscr...@qpid.apache.org
For additional commands, e-mail: commits-h...@qpid.apache.org
