stream: Add server-side (segmentation) support for IPA

With this commit, IPA segmentation can be taken care of by setting
the segmentation callback osmo_ipa_segmentation_cb().

Depends: libosmocore.git I3a639e6896cc3b3fc8e9b2e1a58254710efa0d3f

Related: OS#5753, OS#5751
Change-Id: I6c91ff385cb5f36ab6b6c96d0e44997995d0d24c

5 files changed, 363 insertions, 10 deletions

diff --git a/examples/ipa-stream-server.c b/examples/ipa-stream-server.c
index c72ed9a..1caef96 100644
--- a/examples/ipa-stream-server.c
+++ b/examples/ipa-stream-server.c
@@ -51,12 +51,6 @@ int read_cb(struct osmo_stream_srv *conn, struct msgb *msg)
 {
 	LOGP(DSTREAMTEST, LOGL_DEBUG, "received message from stream (len=%d)\n", msgb_length(msg));
 
-	if (osmo_ipa_process_msg(msg) < 0) {
-		LOGP(DSTREAMTEST, LOGL_ERROR, "Bad IPA message\n");
-		msgb_free(msg);
-		return 0;
-	}
-
 	osmo_stream_srv_send(conn, msg);
 	return 0;
 }
@@ -84,6 +78,7 @@ static int accept_cb(struct osmo_stream_srv_link *srv, int fd)
 	osmo_stream_srv_set_name(conn, "ipa_srv");
 	osmo_stream_srv_set_read_cb(conn, read_cb);
 	osmo_stream_srv_set_closed_cb(conn, close_cb);
+	osmo_stream_srv_set_segmentation_cb(conn, osmo_ipa_segmentation_cb);
 
 	return 0;
 }
diff --git a/include/osmocom/netif/stream.h b/include/osmocom/netif/stream.h
index 057815b..6240205 100644
--- a/include/osmocom/netif/stream.h
+++ b/include/osmocom/netif/stream.h
@@ -58,6 +58,9 @@ void osmo_stream_srv_destroy(struct osmo_stream_srv *conn);
 void osmo_stream_srv_set_flush_and_destroy(struct osmo_stream_srv *conn);
 void osmo_stream_srv_set_data(struct osmo_stream_srv *conn, void *data);
 
+void osmo_stream_srv_set_segmentation_cb(struct osmo_stream_srv *conn,
+					int (*segmentation_cb)(struct msgb *msg));
+
 void osmo_stream_srv_send(struct osmo_stream_srv *conn, struct msgb *msg);
 int osmo_stream_srv_recv(struct osmo_stream_srv *conn, struct msgb *msg);
 
diff --git a/src/stream_srv.c b/src/stream_srv.c
index c8d3233..f46175b 100644
--- a/src/stream_srv.c
+++ b/src/stream_srv.c
@@ -753,6 +753,23 @@ osmo_stream_srv_set_data(struct osmo_stream_srv *conn,
 	conn->data = data;
 }
 
+/*! \brief Set the segmentation callback for target osmo_stream_srv structure.
+ * The connection has to have been established prior to calling this function.
+ *  \param[in,out] conn Target Stream Server to modify
+ *  \param[in] segmentation_cb Segmentation callback to be set */
+void osmo_stream_srv_set_segmentation_cb(struct osmo_stream_srv *conn,
+					int (*segmentation_cb)(struct msgb *msg))
+{
+	/* Note that the following implies that iofd != NULL, since
+	 * osmo_stream_srv_create2() creates the iofd member, too */
+	OSMO_ASSERT(conn->mode == OSMO_STREAM_MODE_OSMO_IO);
+	/* Copy default settings */
+	struct osmo_io_ops conn_ops = srv_ioops;
+	/* Set segmentation cb for this connection */
+	conn_ops.segmentation_cb = segmentation_cb;
+	osmo_iofd_set_ioops(conn->iofd, &conn_ops);
+}
+
 /*! \brief Get application private data of the stream server
  *  \param[in] conn Stream Server
  *  \returns Application private data, as set by \ref osmo_stream_srv_set_data() */
diff --git a/tests/stream/stream_test.c b/tests/stream/stream_test.c
index 67603e9..01ebb23 100644
--- a/tests/stream/stream_test.c
+++ b/tests/stream/stream_test.c
@@ -1,6 +1,7 @@
 /*
- * (C) 2019 by sysmocom - s.f.m.c. GmbH.
- * Author: Max Suraev
+ * (C) 2023 by sysmocom - s.f.m.c. GmbH.
+ * Authors: Max Suraev
+ *	    Alexander Rehbein
  *
  * This program is free software; you can redistribute it and/or modify
  * it under the terms of the GNU General Public License as published by
@@ -8,19 +9,23 @@
  * (at your option) any later version.
  */
 
+#include <inttypes.h>
 #include <stdio.h>
 #include <stdlib.h>
 #include <string.h>
 #include <unistd.h>
 #include <errno.h>
 
+#include <osmocom/core/byteswap.h>
 #include <osmocom/core/select.h>
 #include <osmocom/core/talloc.h>
 #include <osmocom/core/msgb.h>
 #include <osmocom/core/logging.h>
 #include <osmocom/core/application.h>
 #include <osmocom/core/timer.h>
+#include <osmocom/gsm/protocol/ipaccess.h>
 
+#include <osmocom/netif/ipa.h>
 #include <osmocom/netif/stream.h>
 
 #define RECONNECT_TIMEOUT_SECS 9
@@ -366,9 +371,273 @@ static void test_recon(void *ctx, const char *host, unsigned port, unsigned step
 	printf("{%lu.%06lu} %s test complete.\n\n", tv.tv_sec, tv.tv_usec, ASTR(autoreconnect));
 }
 
+/* Segmentation test code (using IPA) */
+#define IPAC_MSG_PING_LEN 0x01
+static const uint8_t ipac_msg_ping[] = {
+	0x00, IPAC_MSG_PING_LEN,
+	IPAC_PROTO_IPACCESS,
+	IPAC_MSGT_PING
+};
+#define IPAC_MSG_PONG_LEN 0x01
+static const uint8_t ipac_msg_pong[] = {
+	0x00, IPAC_MSG_PONG_LEN,
+	IPAC_PROTO_IPACCESS,
+	IPAC_MSGT_PONG
+};
+#define IPAC_MSG_ID_REQ_LEN 0x03
+static const uint8_t ipac_msg_idreq[] = {
+	0x00, IPAC_MSG_ID_REQ_LEN,
+	IPAC_PROTO_IPACCESS,
+	IPAC_MSGT_ID_GET,
+	0x01, IPAC_IDTAG_UNITNAME
+};
+#define ipac_msg_idreq_third (sizeof(ipac_msg_idreq)/3)
+#define ipac_msg_idreq_last_third (sizeof(ipac_msg_idreq) - 2 * ipac_msg_idreq_third)
+#define IPAC_MSG_ID_RESP_LEN 0x07
+static const uint8_t ipac_msg_idresp[] = {
+	0x00, IPAC_MSG_ID_RESP_LEN,
+	IPAC_PROTO_IPACCESS,
+	IPAC_MSGT_ID_RESP,
+	0x01, IPAC_IDTAG_UNITNAME, 0xde, 0xad, 0xbe, 0xef
+};
+
+#define put_ipa_msg(unsigned_char_ptr, struct_msgb_ptr, byte_array) do {\
+	(unsigned_char_ptr) = msgb_put(struct_msgb_ptr, sizeof(byte_array));\
+	memcpy(unsigned_char_ptr, byte_array, sizeof(byte_array));\
+} while (0)
+
+/* Array indices correspond to enum values stringified on the right */
+static const char * const IPAC_MSG_TYPES[] = {
+	[0] = "IPAC_MSGT_PING",
+	[1] = "IPAC_MSGT_PONG",
+	[2] = "UNEXPECTED VALUE",
+	[3] = "UNEXPECTED VALUE",
+	[4] = "IPAC_MSGT_ID_GET",
+	[5] = "IPAC_MSGT_ID_RESP",
+};
+
+#define IPAC_MSGT_OFFSET 3
+/* Append a message to UCHAR_PTR_DST. SRC_IPAC_MSG_BUF is expected to be a
+ * buffer containing an IPA message of type IPAC_PROTO_ACCESS that is
+ * syntactically correct up to offset 3 (IPAC_MSGT_OFFSET).
+ * Uses a counter so that appended messages can be distinguished easily in the logs */
+#define CLI_APPEND_MSG(OSMO_STREAM_CLI_PTR, UCHAR_PTR_DST, STRUCT_MSGB_PTR, SRC_IPAC_MSG_BUF) do {\
+	LOGCLI(OSMO_STREAM_CLI_PTR, "[%u-cli] Appending msg of type %s into buffer\n",\
+	       ++test_segm_ipa_stream_srv_msglognum_cli, IPAC_MSG_TYPES[SRC_IPAC_MSG_BUF[IPAC_MSGT_OFFSET]]);\
+	LOGCLI(OSMO_STREAM_CLI_PTR, "\t(msg dump: %s)\n", osmo_hexdump(SRC_IPAC_MSG_BUF,\
+	       sizeof(SRC_IPAC_MSG_BUF)));\
+	put_ipa_msg(UCHAR_PTR_DST, STRUCT_MSGB_PTR, SRC_IPAC_MSG_BUF);\
+} while (0)
+
+static unsigned test_segm_ipa_stream_srv_msglognum_cli = 0;
+static int test_segm_ipa_stream_srv_cli_connect_cb(struct osmo_stream_cli *cli)
+{
+	unsigned char *data;
+	struct msgb *m = msgb_alloc_headroom(128, 0, "IPA messages");
+	if (m == NULL) {
+		fprintf(stderr, "Cannot allocate message\n");
+		return -ENOMEM;
+	}
+
+	/* Send 4 and 1/3 messages */
+	/* Append 4 */
+	CLI_APPEND_MSG(cli, data, m, ipac_msg_ping);
+	CLI_APPEND_MSG(cli, data, m, ipac_msg_pong);
+	CLI_APPEND_MSG(cli, data, m, ipac_msg_ping);
+	CLI_APPEND_MSG(cli, data, m, ipac_msg_idresp);
+	/* Append 1/3 */
+	LOGCLI(cli, "[(0%u + 1/3)-cli] Appending 1st third of msg of type %s into buffer\n",
+	       test_segm_ipa_stream_srv_msglognum_cli, IPAC_MSG_TYPES[ipac_msg_idreq[3]]);
+	LOGCLI(cli, "\t(dump: %s)\n", osmo_hexdump(ipac_msg_idreq, ipac_msg_idreq_third));
+	data = msgb_put(m, ipac_msg_idreq_third);
+	memcpy(data, ipac_msg_idreq, ipac_msg_idreq_third);
+
+	LOGCLI(cli, "Sending 4 + 1/3 messages as one:\n");
+	LOGCLI(cli, "\t(msg dump: %s)\n\n", osmo_hexdump(m->data, m->len));
+	osmo_stream_cli_send(cli, m);
+	return 0;
+}
+
+static bool test_segm_ipa_stream_srv_all_msgs_processed = false;
+
+static void send_last_third(void *osmo_stream_cli_arg)
+{
+	struct osmo_stream_cli *osc = osmo_stream_cli_arg;
+	unsigned char *data;
+	struct msgb *reply = msgb_alloc_headroom(128, 0, "IPA delayed reply");
+
+	LOGCLI(osc, "Delay for sending last third of message is over\n");
+	if (reply == NULL) {
+		fprintf(stderr, "Cannot allocate message\n");
+		return;
+	}
+	LOGCLI(osc, "[%u-cli] Appending: Last third of IPAC_MSGT_ID_GET\n",
+	       ++test_segm_ipa_stream_srv_msglognum_cli);
+	data = msgb_put(reply, ipac_msg_idreq_last_third);
+	memcpy(data, ipac_msg_idreq + 2 * ipac_msg_idreq_third,
+	       ipac_msg_idreq_last_third);
+	/* Append two entire messages */
+	CLI_APPEND_MSG(osc, data, reply, ipac_msg_pong);
+	CLI_APPEND_MSG(osc, data, reply, ipac_msg_pong);
+	LOGCLI(osc, "\tSending:"
+		    "[ Last third of IPAC_MSGT_ID_GET | IPAC_MSGT_PONG | IPAC_MSGT_PONG ]\n");
+	LOGCLI(osc, "\t(msg dump: %s)\n\n", osmo_hexdump(reply->data, reply->len));
+	osmo_stream_cli_send(osc, reply);
+}
+
+static struct osmo_timer_list fragmented_send_tl_cli;
+
+static int test_segm_ipa_stream_srv_cli_read_cb(struct osmo_stream_cli *osc, struct msgb *msg)
+{
+	unsigned char *data;
+	struct ipa_head *h = (struct ipa_head *) msg->data;
+	uint8_t ipac_msg_type = ((uint8_t *)h)[sizeof(struct ipa_head)];
+	struct msgb *reply = msgb_alloc_headroom(128, 0, "IPA reply");
+	if (reply == NULL) {
+		fprintf(stderr, "Cannot allocate message\n");
+		return -ENOMEM;
+	}
+	LOGCLI(osc, "Received message from stream (total len = %" PRIu16 ")\n", msgb_length(msg));
+	if (ipac_msg_type < 0 || 5 < ipac_msg_type) {
+		fprintf(stderr, "Received unexpected IPAC message type %"PRIu8"\n", ipac_msg_type);
+		return -ENOMSG;
+	}
+	LOGCLI(osc, "\tType: %s\n", IPAC_MSG_TYPES[ipac_msg_type]);
+	if (ipac_msg_type == IPAC_MSGT_ID_GET) {
+		LOGCLI(osc, "Got IPAC_MSGT_ID_GET from server\n");
+		LOGCLI(osc, "[(%u + 2/3) -cli] Appending: Second third of IPAC_MSGT_ID_GET\n",
+		       test_segm_ipa_stream_srv_msglognum_cli);
+		data = msgb_put(reply, ipac_msg_idreq_third);
+		memcpy(data, ipac_msg_idreq + ipac_msg_idreq_third,
+		       ipac_msg_idreq_third);
+		LOGCLI(osc, "\tSending: Second third of IPAC_MSGT_ID_GET\n");
+		LOGCLI(osc, "\t(msg dump: %s)\n", osmo_hexdump(reply->data, reply->len));
+		osmo_stream_cli_send(osc, reply);
+		osmo_timer_setup(&fragmented_send_tl_cli, send_last_third, osc);
+		osmo_timer_add(&fragmented_send_tl_cli);
+		osmo_timer_schedule(&fragmented_send_tl_cli, 0, 500000);
+	} else if (ipac_msg_type == IPAC_MSGT_ID_RESP) {
+		LOGCLI(osc, "\tresult=  %s\n",
+		       osmo_hexdump((const unsigned char *)h, sizeof(*h) + h->len));
+		LOGCLI(osc, "\texpected=%s\n",
+		       osmo_hexdump(ipac_msg_idresp, sizeof(ipac_msg_idresp)));
+	}
+	printf("\n");
+	return 0;
+}
+
+static void *test_segm_ipa_stream_srv_run_client(void)
+{
+	struct osmo_stream_cli *osc;
+	void *ctx = talloc_named_const(NULL, 0, __func__);
+
+	(void) msgb_talloc_ctx_init(ctx, 0);
+	osc = osmo_stream_cli_create(ctx);
+	if (osc == NULL) {
+		fprintf(stderr, "osmo_stream_cli_create_iofd()\n");
+		return NULL;
+	}
+	osmo_stream_cli_set_addr(osc, "127.0.0.11");
+	osmo_stream_cli_set_port(osc, 1111);
+	osmo_stream_cli_set_connect_cb(osc, test_segm_ipa_stream_srv_cli_connect_cb);
+	osmo_stream_cli_set_data(osc, ctx);
+	osmo_stream_cli_set_read_cb2(osc, test_segm_ipa_stream_srv_cli_read_cb);
+	osmo_stream_cli_set_nodelay(osc, true);
+	if (osmo_stream_cli_open(osc) < 0) {
+		fprintf(stderr, "Cannot open stream client\n");
+		return NULL;
+	}
+
+	return NULL;
+}
+
+int test_segm_ipa_stream_srv_srv_read_cb(struct osmo_stream_srv *conn, struct msgb *msg)
+{
+	static unsigned msgnum_srv = 0;
+	struct ipa_head *ih = (struct ipa_head *)msg->l1h;
+	unsigned char *data;
+	struct msgb *m;
+	uint8_t *msgt = msg->l2h; /* Octet right after IPA header */
+	LOGSRV(conn, "[%u-srv] Received IPA message from stream (payload len = %" PRIu16 ")\n",
+	       ++msgnum_srv, msgb_length(msg));
+	LOGSRV(conn, "\tmsg buff data (including stripped headers): %s\n",
+	       osmo_hexdump((unsigned char *)ih, osmo_ntohs(ih->len) + sizeof(*ih)));
+	LOGSRV(conn, "\tIPA payload: %s\n", osmo_hexdump(ih->data, osmo_ntohs(ih->len)));
+	LOGSRV(conn, "\tType: %s\n", IPAC_MSG_TYPES[*msgt]);
+	LOGSRV(conn, "\t(msg dump: %s)\n", osmo_hexdump(msg->l1h, msg->len + sizeof(struct ipa_head)));
+	if (*msgt == IPAC_MSGT_ID_RESP) { /*  */
+		LOGSRV(conn, "Send IPAC_MSGT_ID_GET to trigger client to send next third\n\n");
+		m = msgb_alloc_headroom(128, 0, "IPA messages");
+		if (m == NULL) {
+			fprintf(stderr, "Cannot allocate message\n");
+			return -ENOMEM;
+		}
+		put_ipa_msg(data, m, ipac_msg_idreq);
+		osmo_stream_srv_send(conn, m);
+	} else if (msgnum_srv == 7 && *msgt == IPAC_MSGT_PONG) {
+		test_segm_ipa_stream_srv_all_msgs_processed = true;
+	}
+	return 0;
+}
+
+static int test_segm_ipa_stream_srv_srv_close_cb(struct osmo_stream_srv *conn)
+{
+	osmo_stream_srv_set_segmentation_cb(conn, NULL);
+	return 0;
+}
+
+static int test_segm_ipa_stream_srv_srv_accept_cb(struct osmo_stream_srv_link *srv, int fd)
+{
+	void *ctx = talloc_named_const(NULL, 0, __func__);
+	struct osmo_stream_srv *oss =
+		osmo_stream_srv_create2(ctx, srv, fd, NULL);
+	if (oss == NULL) {
+		fprintf(stderr, "Error while creating connection\n");
+		return -1;
+	}
+	osmo_stream_srv_set_segmentation_cb(oss, osmo_ipa_segmentation_cb);
+	osmo_stream_srv_set_read_cb(oss, test_segm_ipa_stream_srv_srv_read_cb);
+	osmo_stream_srv_set_closed_cb(oss, test_segm_ipa_stream_srv_srv_close_cb);
+	return 0;
+}
+
+static void test_segm_ipa_stream_srv_run(void *ctx, const char *host, unsigned port,
+				  struct osmo_stream_srv_link *srv)
+{
+	const char *testname = "test_segm_ipa_stream_srv";
+	osmo_stream_srv_link_set_accept_cb(srv,
+		test_segm_ipa_stream_srv_srv_accept_cb);
+	if (osmo_stream_srv_link_open(srv) < 0) {
+		printf("Unable to open server\n");
+		exit(1);
+	}
+	test_segm_ipa_stream_srv_run_client();
+
+	printf("______________________________________Running test %s______________________________________\n", testname);
+	alarm(2);
+
+	while (!test_segm_ipa_stream_srv_all_msgs_processed) {
+		osmo_gettimeofday_override_add(0, 1); /* small increment to easily spot iterations */
+		osmo_select_main(1);
+	}
+	alarm(0);
+	printf("==================================Test %s complete========================================\n\n", testname);
+}
+
+static void sigalarm_handler(int _foo)
+{
+	printf("FAIL: test did not run successfully\n");
+	exit(EXIT_FAILURE);
+}
 
 int main(void)
 {
+
+	if (signal(SIGALRM, sigalarm_handler) == SIG_ERR) {
+		perror("signal");
+		exit(EXIT_FAILURE);
+	}
+
 	struct osmo_stream_srv_link *srv;
 	char *host = "127.0.0.11";
 	unsigned port = 1111;
@@ -406,8 +675,8 @@ int main(void)
 	test_recon(tall_test, host, port, 12, srv, true);
 	test_recon(tall_test, host, port, 8, srv, false);
 
-	osmo_stream_srv_link_destroy(srv);
-	printf("Stream tests completed\n");
+	test_segm_ipa_stream_srv_run(tall_test, host, port, srv);
 
+	printf("Stream tests completed\n");
 	return EXIT_SUCCESS;
 }
diff --git a/tests/stream/stream_test.ok b/tests/stream/stream_test.ok
index 2106295..f21b486 100644
--- a/tests/stream/stream_test.ok
+++ b/tests/stream/stream_test.ok
@@ -48,4 +48,73 @@ Client/Server entering non-reconnecting event loop...
 {11.000019} [OK] Client's read_cb_cli(): 0-byte read, auto-reconnect will be triggered if enabled
 {20.000019} non-reconnecting test complete.
 
+______________________________________Running test test_segm_ipa_stream_srv______________________________________
+{20.000020} [OK] Client's test_segm_ipa_stream_srv_cli_connect_cb(): [1-cli] Appending msg of type IPAC_MSGT_PING into buffer
+{20.000020} [OK] Client's test_segm_ipa_stream_srv_cli_connect_cb(): 	(msg dump: 00 01 fe 00 )
+{20.000020} [OK] Client's test_segm_ipa_stream_srv_cli_connect_cb(): [2-cli] Appending msg of type IPAC_MSGT_PONG into buffer
+{20.000020} [OK] Client's test_segm_ipa_stream_srv_cli_connect_cb(): 	(msg dump: 00 01 fe 01 )
+{20.000020} [OK] Client's test_segm_ipa_stream_srv_cli_connect_cb(): [3-cli] Appending msg of type IPAC_MSGT_PING into buffer
+{20.000020} [OK] Client's test_segm_ipa_stream_srv_cli_connect_cb(): 	(msg dump: 00 01 fe 00 )
+{20.000020} [OK] Client's test_segm_ipa_stream_srv_cli_connect_cb(): [4-cli] Appending msg of type IPAC_MSGT_ID_RESP into buffer
+{20.000020} [OK] Client's test_segm_ipa_stream_srv_cli_connect_cb(): 	(msg dump: 00 07 fe 05 01 01 de ad be ef )
+{20.000020} [OK] Client's test_segm_ipa_stream_srv_cli_connect_cb(): [(04 + 1/3)-cli] Appending 1st third of msg of type IPAC_MSGT_ID_GET into buffer
+{20.000020} [OK] Client's test_segm_ipa_stream_srv_cli_connect_cb(): 	(dump: 00 03 )
+{20.000020} [OK] Client's test_segm_ipa_stream_srv_cli_connect_cb(): Sending 4 + 1/3 messages as one:
+{20.000020} [OK] Client's test_segm_ipa_stream_srv_cli_connect_cb(): 	(msg dump: 00 01 fe 00 00 01 fe 01 00 01 fe 00 00 07 fe 05 01 01 de ad be ef 00 03 )
+
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): [1-srv] Received IPA message from stream (payload len = 1)
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	msg buff data (including stripped headers): 00 01 fe 00 
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	IPA payload: 00 
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	Type: IPAC_MSGT_PING
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	(msg dump: 00 01 fe 00 )
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): [2-srv] Received IPA message from stream (payload len = 1)
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	msg buff data (including stripped headers): 00 01 fe 01 
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	IPA payload: 01 
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	Type: IPAC_MSGT_PONG
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	(msg dump: 00 01 fe 01 )
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): [3-srv] Received IPA message from stream (payload len = 1)
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	msg buff data (including stripped headers): 00 01 fe 00 
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	IPA payload: 00 
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	Type: IPAC_MSGT_PING
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	(msg dump: 00 01 fe 00 )
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): [4-srv] Received IPA message from stream (payload len = 7)
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	msg buff data (including stripped headers): 00 07 fe 05 01 01 de ad be ef 
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	IPA payload: 05 01 01 de ad be ef 
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	Type: IPAC_MSGT_ID_RESP
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	(msg dump: 00 07 fe 05 01 01 de ad be ef )
+{20.000022} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): Send IPAC_MSGT_ID_GET to trigger client to send next third
+
+{20.000024} [OK] Client's test_segm_ipa_stream_srv_cli_read_cb(): Received message from stream (total len = 6)
+{20.000024} [OK] Client's test_segm_ipa_stream_srv_cli_read_cb(): 	Type: IPAC_MSGT_ID_GET
+{20.000024} [OK] Client's test_segm_ipa_stream_srv_cli_read_cb(): Got IPAC_MSGT_ID_GET from server
+{20.000024} [OK] Client's test_segm_ipa_stream_srv_cli_read_cb(): [(4 + 2/3) -cli] Appending: Second third of IPAC_MSGT_ID_GET
+{20.000024} [OK] Client's test_segm_ipa_stream_srv_cli_read_cb(): 	Sending: Second third of IPAC_MSGT_ID_GET
+{20.000024} [OK] Client's test_segm_ipa_stream_srv_cli_read_cb(): 	(msg dump: fe 04 )
+
+{20.500024} [OK] Client's send_last_third(): Delay for sending last third of message is over
+{20.500024} [OK] Client's send_last_third(): [5-cli] Appending: Last third of IPAC_MSGT_ID_GET
+{20.500024} [OK] Client's send_last_third(): [6-cli] Appending msg of type IPAC_MSGT_PONG into buffer
+{20.500024} [OK] Client's send_last_third(): 	(msg dump: 00 01 fe 01 )
+{20.500024} [OK] Client's send_last_third(): [7-cli] Appending msg of type IPAC_MSGT_PONG into buffer
+{20.500024} [OK] Client's send_last_third(): 	(msg dump: 00 01 fe 01 )
+{20.500024} [OK] Client's send_last_third(): 	Sending:[ Last third of IPAC_MSGT_ID_GET | IPAC_MSGT_PONG | IPAC_MSGT_PONG ]
+{20.500024} [OK] Client's send_last_third(): 	(msg dump: 01 01 00 01 fe 01 00 01 fe 01 )
+
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): [5-srv] Received IPA message from stream (payload len = 3)
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	msg buff data (including stripped headers): 00 03 fe 04 01 01 
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	IPA payload: 04 01 01 
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	Type: IPAC_MSGT_ID_GET
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	(msg dump: 00 03 fe 04 01 01 )
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): [6-srv] Received IPA message from stream (payload len = 1)
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	msg buff data (including stripped headers): 00 01 fe 01 
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	IPA payload: 01 
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	Type: IPAC_MSGT_PONG
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	(msg dump: 00 01 fe 01 )
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): [7-srv] Received IPA message from stream (payload len = 1)
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	msg buff data (including stripped headers): 00 01 fe 01 
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	IPA payload: 01 
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	Type: IPAC_MSGT_PONG
+{20.500026} [NA|OK] Server's test_segm_ipa_stream_srv_srv_read_cb(): 	(msg dump: 00 01 fe 01 )
+==================================Test test_segm_ipa_stream_srv complete========================================
+
 Stream tests completed