stream: Print socket info as part of the logging context

Since the local port is logged now in stream_test, it must be set to
a specific value in order to have deterministic log output being
validated.

Change-Id: I17ef699dab72c1b613708070d22e9f040b0fe069
---
M src/stream.c
M tests/stream/stream_test.c
M tests/stream/stream_test.err
3 files changed, 42 insertions(+), 10 deletions(-)

diff --git a/src/stream.c b/src/stream.c
index 0f56969..a5a5bf1 100644
--- a/src/stream.c
+++ b/src/stream.c
@@ -77,19 +77,22 @@
 #endif
 
 #define LOGSCLI(cli, level, fmt, args...) \
-	LOGP(DLINP, level, "CLICONN(%s){%s} " fmt, \
+	LOGP(DLINP, level, "CLICONN(%s,%s){%s} " fmt, \
 	     cli->name ? : "", \
+	     cli->sockname, \
 	     get_value_string(stream_cli_state_names, (cli)->state), \
 	     ## args)
 
 #define LOGSLNK(link, level, fmt, args...) \
-	LOGP(DLINP, level, "SRV(%s) " fmt, \
+	LOGP(DLINP, level, "SRV(%s,%s) " fmt, \
 	     link->name ? : "", \
+	     link->sockname, \
 	      ## args)
 
 #define LOGSSRV(srv, level, fmt, args...) \
-	LOGP(DLINP, level, "SRVCONN(%s) " fmt, \
+	LOGP(DLINP, level, "SRVCONN(%s,%s) " fmt, \
 	     srv->name ? : "", \
+	     srv->sockname, \
 	      ## args)
 
 /* is any of the bytes from offset .. u8_size in 'u8' non-zero? return offset or -1 if all zero */
@@ -271,6 +274,7 @@
 
 struct osmo_stream_cli {
 	char *name;
+	char sockname[OSMO_SOCK_NAME_MAXLEN];
 	enum osmo_stream_mode mode;
 	union {
 		struct osmo_fd			ofd;
@@ -513,6 +517,9 @@
 	if (cli->mode == OSMO_STREAM_MODE_OSMO_FD && llist_empty(&cli->tx_queue))
 		osmo_fd_write_disable(&cli->ofd);
 
+	/* Update sockname based on socket info: */
+	osmo_sock_get_name_buf(cli->sockname, sizeof(cli->sockname), osmo_stream_cli_fd(cli));
+
 	LOGSCLI(cli, LOGL_DEBUG, "connection established\n");
 	cli->state = STREAM_CLI_STATE_CONNECTED;
 	switch (cli->sk_domain) {
@@ -1145,6 +1152,7 @@
 struct osmo_stream_srv_link {
 	struct osmo_fd		ofd;
 	char			*name;
+	char			sockname[OSMO_SOCK_NAME_MAXLEN];
 	char			*addr[OSMO_STREAM_MAX_ADDRS];
 	uint8_t			addrcnt;
 	uint16_t		port;
@@ -1483,6 +1491,8 @@
 		link->ofd.fd = -1;
 		return -EIO;
 	}
+
+	OSMO_STRLCPY_ARRAY(link->sockname, osmo_stream_srv_link_get_sockname(link));
 	return 0;
 }
 
@@ -1517,6 +1527,7 @@
 struct osmo_stream_srv {
 	struct osmo_stream_srv_link	*srv;
 	char				*name;
+	char				sockname[OSMO_SOCK_NAME_MAXLEN];
 	enum osmo_stream_mode mode;
 	union {
 		struct osmo_fd			ofd;
@@ -1693,6 +1704,8 @@
 	conn->data = data;
 	INIT_LLIST_HEAD(&conn->tx_queue);
 
+	osmo_sock_get_name_buf(conn->sockname, sizeof(conn->sockname), fd);
+
 	if (osmo_fd_register(&conn->ofd) < 0) {
 		LOGSSRV(conn, LOGL_ERROR, "could not register FD\n");
 		talloc_free(conn);
@@ -1722,8 +1735,13 @@
 
 	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 (name)
+		conn->name = talloc_strdup(conn, name);
+	osmo_sock_get_name_buf(conn->sockname, sizeof(conn->sockname), fd);
+
+	conn->iofd = osmo_iofd_setup(conn, fd, conn->name ? : conn->sockname,
+				     OSMO_IO_FD_MODE_READ_WRITE, &srv_ioops, conn);
 	if (!conn->iofd) {
 		talloc_free(conn);
 		return NULL;
diff --git a/tests/stream/stream_test.c b/tests/stream/stream_test.c
index 1b82d1a..67603e9 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_local_port(cli, 8976);
 	osmo_stream_cli_set_name(cli, "cli_test");
 	osmo_stream_cli_set_addr(cli, host);
 	osmo_stream_cli_set_port(cli, port);
diff --git a/tests/stream/stream_test.err b/tests/stream/stream_test.err
index 9fba03e..2409c07 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
-CLICONN(cli_test){CONNECTED} connection closed with srv
-CLICONN(cli_test){WAIT_RECONNECT} retrying reconnect in 9 seconds...
+CLICONN(cli_test,r=127.0.0.11:1111<->l=127.0.0.1:8976){CONNECTED} connection closed with srv
+CLICONN(cli_test,r=127.0.0.11:1111<->l=127.0.0.1:8976){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
-SRVCONN(srv_test) connection closed with client
+SRVCONN(srv_test,r=127.0.0.1:8976<->l=127.0.0.11:1111) 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
-CLICONN(cli_test){CONNECTED} connection closed with srv
-CLICONN(cli_test){CLOSED} not reconnecting, disabled
+CLICONN(cli_test,r=127.0.0.11:1111<->l=127.0.0.1:8976){CONNECTED} connection closed with srv
+CLICONN(cli_test,r=127.0.0.11:1111<->l=127.0.0.1:8976){CLOSED} not reconnecting, disabled
 
 {20.000019} non-reconnecting test step 0 [client OK, server OK], FD reg 0

