pespin has uploaded this change for review. ( 
https://gerrit.osmocom.org/c/libosmo-netif/+/33336 )


Change subject: stream: Allow setting name printed during logging
......................................................................

stream: Allow setting name printed during logging

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, 89 insertions(+), 30 deletions(-)



  git pull ssh://gerrit.osmocom.org:29418/libosmo-netif refs/changes/36/33336/1

diff --git a/TODO-RELEASE b/TODO-RELEASE
index d0852fc..827b3b2 100644
--- a/TODO-RELEASE
+++ b/TODO-RELEASE
@@ -7,3 +7,4 @@
 # 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
+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 2ba4cde..0f97c28 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);
 }
@@ -404,7 +418,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;
        }

@@ -438,7 +452,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);
@@ -629,6 +643,15 @@
        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);
+}
+
 /*! \brief Set the remote address to which we connect
  *  \param[in] cli Stream Client to modify
  *  \param[in] addr Remote IP address
@@ -1116,6 +1139,7 @@

 struct osmo_stream_srv_link {
        struct osmo_fd          ofd;
+       char                    *name;
        char                    *addr[OSMO_STREAM_MAX_ADDRS];
        uint8_t                 addrcnt;
        uint16_t                port;
@@ -1148,14 +1172,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",
+               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),
@@ -1169,7 +1193,7 @@
                }
                break;
        default:
-               LOGP(DLINP, LOGL_DEBUG, "accept()ed unexpected address family 
%d\n",
+               LOGSLNK(link, LOGL_DEBUG, "accept()ed unexpected address family 
%d\n",
                     ((struct sockaddr *)&sa)->sa_family);
                goto error_close_socket;
        }
@@ -1217,6 +1241,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
@@ -1478,6 +1511,7 @@

 struct osmo_stream_srv {
        struct osmo_stream_srv_link     *srv;
+       char                            *name;
        enum osmo_stream_mode mode;
        union {
                struct osmo_fd                  ofd;
@@ -1494,10 +1528,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;
        }
@@ -1514,10 +1548,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)
@@ -1532,10 +1566,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;
        }

@@ -1560,7 +1594,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:
@@ -1591,7 +1625,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);
@@ -1599,7 +1633,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);

@@ -1615,7 +1649,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))
@@ -1655,7 +1689,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;
        }
@@ -1683,6 +1717,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);
@@ -1691,7 +1726,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;
        }
@@ -1699,6 +1734,15 @@
        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);
+}
+
 /*! \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
@@ -1797,7 +1841,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;
        }
@@ -1926,16 +1970,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: 1
Gerrit-Owner: pespin <[email protected]>
Gerrit-MessageType: newchange

Reply via email to