pespin has submitted this change. (
https://gerrit.osmocom.org/c/libosmo-netif/+/33336 )
Change subject: stream: Allow setting name printed during logging
......................................................................
stream: Allow setting name printed during logging
Depends: libosmocore.git Change-Id If2772a3ccaa98616e0189862a49ab0243435e343
Change-Id: I539a0d29d11348efe702f971965a55cf56db5c59
---
M TODO-RELEASE
M include/osmocom/netif/stream.h
M src/stream.c
M tests/stream/stream_test.c
M tests/stream/stream_test.err
5 files changed, 97 insertions(+), 32 deletions(-)
Approvals:
laforge: Looks good to me, approved
daniel: Looks good to me, but someone else must approve
pespin: Looks good to me, but someone else must approve; Verified
diff --git a/TODO-RELEASE b/TODO-RELEASE
index d0852fc..a4b381f 100644
--- a/TODO-RELEASE
+++ b/TODO-RELEASE
@@ -7,3 +7,5 @@
# If any interfaces have been added since the last public release: c:r:a + 1.
# If any interfaces have been removed or changed since the last public
release: c:r:0.
#library what description / commit summary line
+libosmocore >1.8.0 osmo_iofd
+stream NEW API osmo_stream_srv_link_set_name(),
osmo_stream_srv_set_name(), osmo_stream_cli_set_name()
\ No newline at end of file
diff --git a/include/osmocom/netif/stream.h b/include/osmocom/netif/stream.h
index b506142..11e9070 100644
--- a/include/osmocom/netif/stream.h
+++ b/include/osmocom/netif/stream.h
@@ -24,6 +24,7 @@
struct osmo_stream_srv_link *osmo_stream_srv_link_create(void *ctx);
void osmo_stream_srv_link_destroy(struct osmo_stream_srv_link *link);
+void osmo_stream_srv_link_set_name(struct osmo_stream_srv_link *link, const
char *name);
void osmo_stream_srv_link_set_nodelay(struct osmo_stream_srv_link *link, bool
nodelay);
void osmo_stream_srv_link_set_addr(struct osmo_stream_srv_link *link, const
char *addr);
int osmo_stream_srv_link_set_addrs(struct osmo_stream_srv_link *link, const
char **addr, size_t addrcnt);
@@ -46,6 +47,7 @@
struct osmo_stream_srv *osmo_stream_srv_create(void *ctx, struct
osmo_stream_srv_link *link, int fd, int (*read_cb)(struct osmo_stream_srv
*conn), int (*closed_cb)(struct osmo_stream_srv *conn), void *data);
struct osmo_stream_srv *osmo_stream_srv_create2(void *ctx, const char *name,
struct osmo_stream_srv_link *link, int fd, void *data);
+void osmo_stream_srv_set_name(struct osmo_stream_srv *conn, const char *name);
void osmo_stream_srv_set_read_cb(struct osmo_stream_srv *conn, int
(*read_cb)(struct osmo_stream_srv *conn, struct msgb *msg));
void osmo_stream_srv_set_closed_cb(struct osmo_stream_srv *conn, int
(*closed_cb)(struct osmo_stream_srv *conn));
void *osmo_stream_srv_get_data(struct osmo_stream_srv *conn);
@@ -64,6 +66,7 @@
/*! \brief Osmocom Stream Client: Single client connection */
struct osmo_stream_cli;
+void osmo_stream_cli_set_name(struct osmo_stream_cli *cli, const char *name);
void osmo_stream_cli_set_nodelay(struct osmo_stream_cli *cli, bool nodelay);
void osmo_stream_cli_set_addr(struct osmo_stream_cli *cli, const char *addr);
int osmo_stream_cli_set_addrs(struct osmo_stream_cli *cli, const char **addr,
size_t addrcnt);
diff --git a/src/stream.c b/src/stream.c
index c710e1b..0f56969 100644
--- a/src/stream.c
+++ b/src/stream.c
@@ -53,8 +53,6 @@
#include <osmocom/netif/sctp.h>
-#define LOGSCLI(cli, level, fmt, args...) \
- LOGP(DLINP, level, "[%s] %s(): " fmt,
get_value_string(stream_cli_state_names, (cli)->state), __func__, ## args)
/*! \addtogroup stream Osmocom Stream Socket
* @{
@@ -78,6 +76,22 @@
#define MSG_NOSIGNAL 0
#endif
+#define LOGSCLI(cli, level, fmt, args...) \
+ LOGP(DLINP, level, "CLICONN(%s){%s} " fmt, \
+ cli->name ? : "", \
+ get_value_string(stream_cli_state_names, (cli)->state), \
+ ## args)
+
+#define LOGSLNK(link, level, fmt, args...) \
+ LOGP(DLINP, level, "SRV(%s) " fmt, \
+ link->name ? : "", \
+ ## args)
+
+#define LOGSSRV(srv, level, fmt, args...) \
+ LOGP(DLINP, level, "SRVCONN(%s) " fmt, \
+ srv->name ? : "", \
+ ## args)
+
/* is any of the bytes from offset .. u8_size in 'u8' non-zero? return offset
or -1 if all zero */
static int byte_nonzero(const uint8_t *u8, unsigned int offset, unsigned int
u8_size)
{
@@ -300,7 +314,7 @@
}
cli->state = STREAM_CLI_STATE_WAIT_RECONNECT;
- LOGSCLI(cli, LOGL_INFO, "retrying in %d seconds...\n",
+ LOGSCLI(cli, LOGL_INFO, "retrying reconnect in %d seconds...\n",
cli->reconnect_timeout);
osmo_timer_schedule(&cli->timer, cli->reconnect_timeout, 0);
}
@@ -406,7 +420,7 @@
llist_del(&msg->list);
if (!osmo_stream_cli_is_connected(cli)) {
- LOGSCLI(cli, LOGL_ERROR, "not connected, dropping data!\n");
+ LOGSCLI(cli, LOGL_ERROR, "send: not connected, dropping
data!\n");
return 0;
}
@@ -440,7 +454,7 @@
}
if (ret >= 0 && ret < msgb_length(msg)) {
- LOGP(DLINP, LOGL_ERROR, "short send: %d < exp %u\n", ret,
msgb_length(msg));
+ LOGSCLI(cli, LOGL_ERROR, "short send: %d < exp %u\n", ret,
msgb_length(msg));
/* Update msgb and re-add it at the start of the queue: */
msgb_pull(msg, ret);
llist_add(&msg->list, &cli->tx_queue);
@@ -632,6 +646,17 @@
return cli;
}
+/*! \brief Set a name on the cli object (used during logging)
+ * \param[in] cli stream_cli whose name is to be set
+ * \param[in] name the name to be set on cli
+ */
+void osmo_stream_cli_set_name(struct osmo_stream_cli *cli, const char *name)
+{
+ osmo_talloc_replace_string(cli, &cli->name, name);
+ if (cli->mode == OSMO_STREAM_MODE_OSMO_IO && cli->iofd)
+ osmo_iofd_set_name(cli->iofd, name);
+}
+
/*! \brief Set the remote address to which we connect
* \param[in] cli Stream Client to modify
* \param[in] addr Remote IP address
@@ -1119,6 +1144,7 @@
struct osmo_stream_srv_link {
struct osmo_fd ofd;
+ char *name;
char *addr[OSMO_STREAM_MAX_ADDRS];
uint8_t addrcnt;
uint16_t port;
@@ -1151,14 +1177,14 @@
is_ipv6 = false;
switch (((struct sockaddr *)&sa)->sa_family) {
case AF_UNIX:
- LOGP(DLINP, LOGL_DEBUG, "accept()ed new link on fd %d\n",
- sock_fd);
+ LOGSLNK(link, LOGL_DEBUG, "accept()ed new link on fd %d\n",
+ sock_fd);
break;
case AF_INET6:
is_ipv6 = true;
/* fall through */
case AF_INET:
- LOGP(DLINP, LOGL_DEBUG, "accept()ed new link from %s to port
%u\n",
+ LOGSLNK(link, LOGL_DEBUG, "accept()ed new link from %s to port
%u\n",
inet_ntop(is_ipv6 ? AF_INET6 : AF_INET,
is_ipv6 ? (void *)&(((struct sockaddr_in6
*)&sa)->sin6_addr) :
(void *)&(((struct sockaddr_in
*)&sa)->sin_addr),
@@ -1172,8 +1198,8 @@
}
break;
default:
- LOGP(DLINP, LOGL_DEBUG, "accept()ed unexpected address family
%d\n",
- ((struct sockaddr *)&sa)->sa_family);
+ LOGSLNK(link, LOGL_DEBUG, "accept()ed unexpected address family
%d\n",
+ ((struct sockaddr *)&sa)->sa_family);
goto error_close_socket;
}
@@ -1220,6 +1246,15 @@
return link;
}
+/*! \brief Set a name on the srv_link object (used during logging)
+ * \param[in] link server link whose name is to be set
+ * \param[in] name the name to be set on link
+ */
+void osmo_stream_srv_link_set_name(struct osmo_stream_srv_link *link, const
char *name)
+{
+ osmo_talloc_replace_string(link, &link->name, name);
+}
+
/*! \brief Set the NODELAY socket option to avoid Nagle-like behavior
* Setting this to nodelay=true will automatically set the NODELAY
* socket option on any socket established via this server link, before
@@ -1481,6 +1516,7 @@
struct osmo_stream_srv {
struct osmo_stream_srv_link *srv;
+ char *name;
enum osmo_stream_mode mode;
union {
struct osmo_fd ofd;
@@ -1497,10 +1533,10 @@
static void stream_srv_iofd_read_cb(struct osmo_io_fd *iofd, int res, struct
msgb *msg)
{
struct osmo_stream_srv *conn = osmo_iofd_get_data(iofd);
- LOGP(DLINP, LOGL_DEBUG, "message received (res=%d)\n", res);
+ LOGSSRV(conn, LOGL_DEBUG, "message received (res=%d)\n", res);
if (conn->flags & OSMO_STREAM_SRV_F_FLUSH_DESTROY) {
- LOGP(DLINP, LOGL_INFO, "Connection is being flushed and closed;
ignoring received message\n");
+ LOGSSRV(conn, LOGL_INFO, "Connection is being flushed and
closed; ignoring received message\n");
msgb_free(msg);
return;
}
@@ -1517,10 +1553,10 @@
static void stream_srv_iofd_write_cb(struct osmo_io_fd *iofd, int res, struct
msgb *msg)
{
struct osmo_stream_srv *conn = osmo_iofd_get_data(iofd);
- LOGP(DLINP, LOGL_DEBUG, "connected write\n");
+ LOGSSRV(conn, LOGL_DEBUG, "connected write\n");
if (res == -1)
- LOGP(DLINP, LOGL_ERROR, "error to send: %s\n", strerror(errno));
+ LOGSSRV(conn, LOGL_ERROR, "error to send: %s\n",
strerror(errno));
if (osmo_iofd_txqueue_len(iofd) == 0)
if (conn->flags & OSMO_STREAM_SRV_F_FLUSH_DESTROY)
@@ -1535,10 +1571,10 @@
{
int rc = 0;
- LOGP(DLINP, LOGL_DEBUG, "message received\n");
+ LOGSSRV(conn, LOGL_DEBUG, "message received\n");
if (conn->flags & OSMO_STREAM_SRV_F_FLUSH_DESTROY) {
- LOGP(DLINP, LOGL_INFO, "Connection is being flushed and closed;
ignoring received message\n");
+ LOGSSRV(conn, LOGL_INFO, "Connection is being flushed and
closed; ignoring received message\n");
return 0;
}
@@ -1563,7 +1599,7 @@
msg = llist_first_entry(&conn->tx_queue, struct msgb, list);
llist_del(&msg->list);
- LOGP(DLINP, LOGL_DEBUG, "sending %u bytes of data\n", msg->len);
+ LOGSSRV(conn, LOGL_DEBUG, "sending %u bytes of data\n", msg->len);
switch (conn->srv->sk_domain) {
case AF_UNIX:
@@ -1594,7 +1630,7 @@
}
if (ret >= 0 && ret < msgb_length(msg)) {
- LOGP(DLINP, LOGL_ERROR, "short send: %d < exp %u\n", ret,
msgb_length(msg));
+ LOGSSRV(conn, LOGL_ERROR, "short send: %d < exp %u\n", ret,
msgb_length(msg));
/* Update msgb and re-add it at the start of the queue: */
msgb_pull(msg, ret);
llist_add(&msg->list, &conn->tx_queue);
@@ -1602,7 +1638,7 @@
}
if (ret == -1) /* send(): On error -1 is returned, and errno is set
appropriately */
- LOGP(DLINP, LOGL_ERROR, "error to send: %s\n", strerror(errno));
+ LOGSSRV(conn, LOGL_ERROR, "error to send: %s\n",
strerror(errno));
msgb_free(msg);
@@ -1618,7 +1654,7 @@
struct osmo_stream_srv *conn = ofd->data;
int rc = 0;
- LOGP(DLINP, LOGL_DEBUG, "connected read/write (what=0x%x)\n", what);
+ LOGSSRV(conn, LOGL_DEBUG, "connected read/write (what=0x%x)\n", what);
if (what & OSMO_FD_READ)
rc = osmo_stream_srv_read(conn);
if (rc != -EBADF && (what & OSMO_FD_WRITE))
@@ -1658,7 +1694,7 @@
INIT_LLIST_HEAD(&conn->tx_queue);
if (osmo_fd_register(&conn->ofd) < 0) {
- LOGP(DLINP, LOGL_ERROR, "could not register FD\n");
+ LOGSSRV(conn, LOGL_ERROR, "could not register FD\n");
talloc_free(conn);
return NULL;
}
@@ -1686,6 +1722,7 @@
conn->mode = OSMO_STREAM_MODE_OSMO_IO;
conn->srv = link;
+ conn->name = talloc_strdup(conn, name);
conn->iofd = osmo_iofd_setup(conn, fd, name,
OSMO_IO_FD_MODE_READ_WRITE, &srv_ioops, conn);
if (!conn->iofd) {
talloc_free(conn);
@@ -1694,7 +1731,7 @@
conn->data = data;
if (osmo_iofd_register(conn->iofd, fd) < 0) {
- LOGP(DLINP, LOGL_ERROR, "could not register FD %d\n", fd);
+ LOGSSRV(conn, LOGL_ERROR, "could not register FD %d\n", fd);
talloc_free(conn);
return NULL;
}
@@ -1702,6 +1739,17 @@
return conn;
}
+/*! \brief Set a name on the srv object (used during logging)
+ * \param[in] conn server whose name is to be set
+ * \param[in] name the name to be set on conn
+ */
+void osmo_stream_srv_set_name(struct osmo_stream_srv *conn, const char *name)
+{
+ osmo_talloc_replace_string(conn, &conn->name, name);
+ if (conn->mode == OSMO_STREAM_MODE_OSMO_IO && conn->iofd)
+ osmo_iofd_set_name(conn->iofd, name);
+}
+
/*! \brief Set the call-back function when data was read from the stream
server socket
* Only for osmo_stream_srv created with osmo_stream_srv_create2()
* \param[in] conn Stream Server to modify
@@ -1800,7 +1848,7 @@
OSMO_ASSERT(conn);
OSMO_ASSERT(msg);
if (conn->flags & OSMO_STREAM_SRV_F_FLUSH_DESTROY) {
- LOGP(DLINP, LOGL_DEBUG, "Connection is being flushed and
closed; ignoring new outgoing message\n");
+ LOGSSRV(conn, LOGL_DEBUG, "Connection is being flushed and
closed; ignoring new outgoing message\n");
msgb_free(msg);
return;
}
@@ -1929,16 +1977,15 @@
if (ret < 0) {
if (errno == EPIPE || errno == ECONNRESET) {
- LOGP(DLINP, LOGL_ERROR,
- "lost connection with client\n");
+ LOGSSRV(conn, LOGL_ERROR, "lost connection with
client\n");
}
return ret;
} else if (ret == 0) {
- LOGP(DLINP, LOGL_ERROR, "connection closed with client\n");
+ LOGSSRV(conn, LOGL_ERROR, "connection closed with client\n");
return ret;
}
msgb_put(msg, ret);
- LOGP(DLINP, LOGL_DEBUG, "received %d bytes from client\n", ret);
+ LOGSSRV(conn, LOGL_DEBUG, "received %d bytes from client\n", ret);
return ret;
}
diff --git a/tests/stream/stream_test.c b/tests/stream/stream_test.c
index 36a222e..1b82d1a 100644
--- a/tests/stream/stream_test.c
+++ b/tests/stream/stream_test.c
@@ -214,6 +214,7 @@
printf("Prepare %s stream client...\n", ASTR(autoreconnect));
+ osmo_stream_cli_set_name(cli, "cli_test");
osmo_stream_cli_set_addr(cli, host);
osmo_stream_cli_set_port(cli, port);
osmo_stream_cli_set_connect_cb(cli, connect_cb_cli);
@@ -323,6 +324,7 @@
LOGLNK(lnk, "error while creating connection\n");
return -EINVAL;
}
+ osmo_stream_srv_set_name(srv, "srv_test");
return 0;
}
@@ -390,6 +392,7 @@
return EXIT_FAILURE;
}
+ osmo_stream_srv_link_set_name(srv, "srv_link_test");
osmo_stream_srv_link_set_addr(srv, host);
osmo_stream_srv_link_set_port(srv, port);
osmo_stream_srv_link_set_accept_cb(srv, accept_cb_srv);
diff --git a/tests/stream/stream_test.err b/tests/stream/stream_test.err
index ca98c82..9fba03e 100644
--- a/tests/stream/stream_test.err
+++ b/tests/stream/stream_test.err
@@ -12,15 +12,15 @@
{2.000006} autoreconnecting test step 6 [client OK, server OK], FD reg 1
{2.000007} autoreconnecting test step 5 [client OK, server OK], FD reg 1
-[CONNECTED] osmo_stream_cli_recv(): connection closed with srv
-[WAIT_RECONNECT] osmo_stream_cli_reconnect(): retrying in 9 seconds...
+CLICONN(cli_test){CONNECTED} connection closed with srv
+CLICONN(cli_test){WAIT_RECONNECT} retrying reconnect in 9 seconds...
{11.000008} autoreconnecting test step 4 [client OK, server OK], FD reg 0
{11.000009} autoreconnecting test step 3 [client OK, server OK], FD reg 1
{11.000010} autoreconnecting test step 2 [client OK, server OK], FD reg 0
-connection closed with client
+SRVCONN(srv_test) connection closed with client
{11.000011} autoreconnecting test step 1 [client OK, server NA], FD reg 0
@@ -37,7 +37,7 @@
{11.000017} non-reconnecting test step 2 [client OK, server OK], FD reg 1
{11.000018} non-reconnecting test step 1 [client OK, server OK], FD reg 1
-[CONNECTED] osmo_stream_cli_recv(): connection closed with srv
-[CLOSED] osmo_stream_cli_reconnect(): not reconnecting, disabled
+CLICONN(cli_test){CONNECTED} connection closed with srv
+CLICONN(cli_test){CLOSED} not reconnecting, disabled
{20.000019} non-reconnecting test step 0 [client OK, server OK], FD reg 0
--
To view, visit https://gerrit.osmocom.org/c/libosmo-netif/+/33336
To unsubscribe, or for help writing mail filters, visit
https://gerrit.osmocom.org/settings
Gerrit-Project: libosmo-netif
Gerrit-Branch: master
Gerrit-Change-Id: I539a0d29d11348efe702f971965a55cf56db5c59
Gerrit-Change-Number: 33336
Gerrit-PatchSet: 5
Gerrit-Owner: pespin <[email protected]>
Gerrit-Reviewer: Jenkins Builder
Gerrit-Reviewer: daniel <[email protected]>
Gerrit-Reviewer: laforge <[email protected]>
Gerrit-Reviewer: pespin <[email protected]>
Gerrit-MessageType: merged
