aboutsummaryrefslogtreecommitdiffstats
path: root/tests/stream
diff options
context:
space:
mode:
Diffstat (limited to 'tests/stream')
-rw-r--r--tests/stream/stream_test.c41
-rw-r--r--tests/stream/stream_test.err38
-rw-r--r--tests/stream/stream_test.ok78
3 files changed, 90 insertions, 67 deletions
diff --git a/tests/stream/stream_test.c b/tests/stream/stream_test.c
index 439ea1a..b4846bc 100644
--- a/tests/stream/stream_test.c
+++ b/tests/stream/stream_test.c
@@ -19,9 +19,12 @@
#include <osmocom/core/msgb.h>
#include <osmocom/core/logging.h>
#include <osmocom/core/application.h>
+#include <osmocom/core/timer.h>
#include <osmocom/netif/stream.h>
+#define RECONNECT_TIMEOUT_SECS 9
+
#define DSTREAMTEST 0
struct log_info_cat osmo_stream_test_cat[] = {
[DSTREAMTEST] = {
@@ -54,8 +57,12 @@ static struct msgb *make_msgb(const char *m)
#define ASTR(rec) ((rec) ? "autoreconnecting" : "non-reconnecting")
/* client defs */
-#define LOGCLI(cli, fmt, args...) \
- printf("[%s] Client's %s(): " fmt, osmo_stream_cli_get_data(cli) ? "OK" : "NA", __func__, ##args)
+#define LOGCLI(cli, fmt, args...) do { \
+ struct timeval tv; \
+ osmo_gettimeofday(&tv, NULL); \
+ printf("{%lu.%06lu} [%s] Client's %s(): " fmt, tv.tv_sec, tv.tv_usec, \
+ osmo_stream_cli_get_data(cli) ? "OK" : "NA", __func__, ##args); \
+ } while (0)
#define CLI_SND(cli, m) do { \
struct msgb *msg = make_msgb(m); \
@@ -100,6 +107,7 @@ static int read_cb_cli(struct osmo_stream_cli *cli)
/* N. B: normally receiving 0 bytes means that we should close the connection and re-establish it
but to test autoreconnection logic we ignore it in here to let the test run till completion */
LOGCLI(cli, "0-byte read, auto-reconnect will be triggered if enabled\n");
+ osmo_gettimeofday_override_add(RECONNECT_TIMEOUT_SECS, 0);
}
if (!cli_data) {
@@ -116,7 +124,7 @@ static int read_cb_cli(struct osmo_stream_cli *cli)
static struct osmo_stream_cli *init_client_reconnection(struct osmo_stream_cli *cli, bool autoreconnect)
{
/* setting negative timeout ensures that we disable reconnection logic */
- osmo_stream_cli_set_reconnect_timeout(cli, autoreconnect ? 9 : -1);
+ osmo_stream_cli_set_reconnect_timeout(cli, autoreconnect ? RECONNECT_TIMEOUT_SECS : -1);
if (osmo_stream_cli_open(cli) < 0) {
LOGCLI(cli, "unable to open client\n");
@@ -224,9 +232,14 @@ static struct osmo_stream_cli *make_client(void *ctx, const char *host, unsigned
#define LOGLNK(lnk, fmt, args...) \
printf("[%s] Server's %s(): " fmt, osmo_stream_srv_link_get_data(lnk) ? "OK" : "NA", __func__, ##args)
-#define LOGSRV(srv, fmt, args...) \
- printf("[%s|%s] Server's %s(): " fmt, osmo_stream_srv_get_data(srv) ? "OK" : "NA", \
- osmo_stream_srv_link_get_data(osmo_stream_srv_get_master(srv)) ? "OK" : "NA", __func__, ##args)
+#define LOGSRV(srv, fmt, args...) do { \
+ struct timeval tv; \
+ osmo_gettimeofday(&tv, NULL); \
+ printf("{%lu.%06lu} [%s|%s] Server's %s(): " fmt, tv.tv_sec, tv.tv_usec, \
+ osmo_stream_srv_get_data(srv) ? "OK" : "NA", \
+ osmo_stream_srv_link_get_data(osmo_stream_srv_get_master(srv)) ? "OK" : "NA", \
+ __func__, ##args); \
+ } while (0)
#define SRV_SND(srv, m) do { \
struct msgb *msg = make_msgb(m); \
@@ -318,6 +331,7 @@ static int accept_cb_srv(struct osmo_stream_srv_link *lnk, int fd)
static void test_recon(void *ctx, const char *host, unsigned port, unsigned steps, struct osmo_stream_srv_link *lnk,
bool autoreconnect)
{
+ struct timeval tv;
struct osmo_stream_cli *cli = make_client(ctx, host, port, autoreconnect);
if (!cli)
return;
@@ -329,20 +343,24 @@ static void test_recon(void *ctx, const char *host, unsigned port, unsigned step
osmo_stream_srv_link_set_data(lnk, ctx);
while(steps--) {
+ osmo_gettimeofday_override_add(0, 1); /* small increment to easily spot iterations */
osmo_select_main(0);
- fprintf(stderr, "\n%s test step %u [client %s, server %s], FD reg %u\n", ASTR(autoreconnect), steps,
+ osmo_gettimeofday(&tv, NULL);
+ fprintf(stderr, "\n{%lu.%06lu} %s test step %u [client %s, server %s], FD reg %u\n",
+ tv.tv_sec, tv.tv_usec, ASTR(autoreconnect), steps,
osmo_stream_cli_get_data(cli) ? "OK" : "NA",
osmo_stream_srv_link_get_data(lnk) ? "OK" : "NA",
osmo_fd_is_registered(osmo_stream_cli_get_ofd(cli)));
if (test_stop_requested(lnk)) {
- printf("Server requested test termination\n");
+ printf("{%lu.%06lu} Server requested test termination\n",
+ tv.tv_sec, tv.tv_usec);
steps = 0;
}
}
osmo_stream_cli_destroy(cli);
- printf("%s test complete.\n\n", ASTR(autoreconnect));
+ printf("{%lu.%06lu} %s test complete.\n\n", tv.tv_sec, tv.tv_usec, ASTR(autoreconnect));
}
@@ -352,6 +370,11 @@ int main(void)
char *host = "127.0.0.11";
unsigned port = 1111;
void *tall_test = talloc_named_const(NULL, 1, "osmo_stream_test");
+
+ osmo_gettimeofday_override = true;
+ osmo_gettimeofday_override_time.tv_sec = 2;
+ osmo_gettimeofday_override_time.tv_usec = 0;
+
msgb_talloc_ctx_init(tall_test, 0);
osmo_init_logging2(tall_test, &osmo_stream_test_log_info);
log_set_log_level(osmo_stderr_target, LOGL_INFO);
diff --git a/tests/stream/stream_test.err b/tests/stream/stream_test.err
index 07cc7b0..04bfcfe 100644
--- a/tests/stream/stream_test.err
+++ b/tests/stream/stream_test.err
@@ -1,43 +1,43 @@
-autoreconnecting test step 11 [client NA, server OK], FD reg 1
+{2.000001} autoreconnecting test step 11 [client NA, server OK], FD reg 1
-autoreconnecting test step 10 [client NA, server OK], FD reg 1
+{2.000002} autoreconnecting test step 10 [client NA, server OK], FD reg 1
-autoreconnecting test step 9 [client NA, server OK], FD reg 1
+{2.000003} autoreconnecting test step 9 [client NA, server OK], FD reg 1
-autoreconnecting test step 8 [client NA, server OK], FD reg 1
+{2.000004} autoreconnecting test step 8 [client NA, server OK], FD reg 1
-autoreconnecting test step 7 [client OK, server OK], FD reg 1
+{2.000005} autoreconnecting test step 7 [client OK, server OK], FD reg 1
-autoreconnecting test step 6 [client OK, server OK], FD reg 1
+{2.000006} autoreconnecting test step 6 [client OK, server OK], FD reg 1
-autoreconnecting test step 5 [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
[ NONE] osmo_stream_cli_reconnect(): retrying in 9 seconds...
-autoreconnecting test step 4 [client OK, server OK], FD reg 0
+{11.000008} autoreconnecting test step 4 [client OK, server OK], FD reg 0
-autoreconnecting test step 3 [client OK, server OK], FD reg 1
+{11.000009} autoreconnecting test step 3 [client OK, server OK], FD reg 1
-autoreconnecting test step 2 [client OK, server OK], FD reg 0
+{11.000010} autoreconnecting test step 2 [client OK, server OK], FD reg 0
connection closed with srv
-autoreconnecting test step 1 [client OK, server NA], FD reg 0
+{11.000011} autoreconnecting test step 1 [client OK, server NA], FD reg 0
-non-reconnecting test step 7 [client NA, server OK], FD reg 1
+{11.000012} non-reconnecting test step 7 [client NA, server OK], FD reg 1
-non-reconnecting test step 6 [client NA, server OK], FD reg 1
+{11.000013} non-reconnecting test step 6 [client NA, server OK], FD reg 1
-non-reconnecting test step 5 [client NA, server OK], FD reg 1
+{11.000014} non-reconnecting test step 5 [client NA, server OK], FD reg 1
-non-reconnecting test step 4 [client NA, server OK], FD reg 1
+{11.000015} non-reconnecting test step 4 [client NA, server OK], FD reg 1
-non-reconnecting test step 3 [client OK, server OK], FD reg 1
+{11.000016} non-reconnecting test step 3 [client OK, server OK], FD reg 1
-non-reconnecting test step 2 [client OK, server OK], FD reg 1
+{11.000017} non-reconnecting test step 2 [client OK, server OK], FD reg 1
-non-reconnecting test step 1 [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
[ NONE] osmo_stream_cli_reconnect(): not reconnecting, disabled.
-non-reconnecting test step 0 [client OK, server OK], FD reg 0
+{20.000019} non-reconnecting test step 0 [client OK, server OK], FD reg 0
diff --git a/tests/stream/stream_test.ok b/tests/stream/stream_test.ok
index 7b6fb95..2106295 100644
--- a/tests/stream/stream_test.ok
+++ b/tests/stream/stream_test.ok
@@ -3,49 +3,49 @@ Prepare autoreconnecting stream client...
=======================================
Client/Server entering autoreconnecting event loop...
=======================================
-[NA] Client's connect_cb_cli(): callback triggered <initial>
-[NA] Client's connect_cb_cli(): sent 29 bytes message: 48 69 21 20 66 72 6f 6d 20 63 6f 6e 6e 65 63 74 20 63 61 6c 6c 62 61 63 6b 20 3a 2d 50
-[NA|OK] Server's read_cb_srv(): callback triggered
-[NA|OK] Server's read_cb_srv(): received 29(29) bytes: 48 69 21 20 66 72 6f 6d 20 63 6f 6e 6e 65 63 74 20 63 61 6c 6c 62 61 63 6b 20 3a 2d 50
-[NA|OK] Server's read_cb_srv(): sent 11 bytes message: 72 65 61 64 5f 63 62 5f 73 72 76
-[OK|OK] Server's read_cb_srv(): keep initial client connection
-[NA] Client's read_cb_cli(): callback triggered
-[NA] Client's read_cb_cli(): received 11(11) bytes: 72 65 61 64 5f 63 62 5f 73 72 76
-[NA] Client's read_cb_cli(): initial read, contacting server
-[OK] Client's read_cb_cli(): sent 29 bytes message: 44 6f 68 2c 20 72 65 73 70 6f 6e 64 69 6e 67 20 74 6f 20 73 65 72 76 65 72 20 3a 2d 44
-[OK|OK] Server's read_cb_srv(): callback triggered
-[OK|OK] Server's read_cb_srv(): received 29(29) bytes: 44 6f 68 2c 20 72 65 73 70 6f 6e 64 69 6e 67 20 74 6f 20 73 65 72 76 65 72 20 3a 2d 44
-[OK|OK] Server's read_cb_srv(): sent 11 bytes message: 72 65 61 64 5f 63 62 5f 73 72 76
-[OK|OK] Server's read_cb_srv(): force client disconnect on subsequent call
-[OK] Client's read_cb_cli(): callback triggered
-[OK] Client's read_cb_cli(): 0-byte read, auto-reconnect will be triggered if enabled
-[OK] Client's connect_cb_cli(): callback triggered <reconnected>
-[OK] Client's connect_cb_cli(): closing connection
-[NA|OK] Server's read_cb_srv(): callback triggered
-[NA|OK] Server's read_cb_srv(): client have already closed connection
-Server requested test termination
-autoreconnecting test complete.
+{2.000001} [NA] Client's connect_cb_cli(): callback triggered <initial>
+{2.000001} [NA] Client's connect_cb_cli(): sent 29 bytes message: 48 69 21 20 66 72 6f 6d 20 63 6f 6e 6e 65 63 74 20 63 61 6c 6c 62 61 63 6b 20 3a 2d 50
+{2.000003} [NA|OK] Server's read_cb_srv(): callback triggered
+{2.000003} [NA|OK] Server's read_cb_srv(): received 29(29) bytes: 48 69 21 20 66 72 6f 6d 20 63 6f 6e 6e 65 63 74 20 63 61 6c 6c 62 61 63 6b 20 3a 2d 50
+{2.000003} [NA|OK] Server's read_cb_srv(): sent 11 bytes message: 72 65 61 64 5f 63 62 5f 73 72 76
+{2.000003} [OK|OK] Server's read_cb_srv(): keep initial client connection
+{2.000005} [NA] Client's read_cb_cli(): callback triggered
+{2.000005} [NA] Client's read_cb_cli(): received 11(11) bytes: 72 65 61 64 5f 63 62 5f 73 72 76
+{2.000005} [NA] Client's read_cb_cli(): initial read, contacting server
+{2.000005} [OK] Client's read_cb_cli(): sent 29 bytes message: 44 6f 68 2c 20 72 65 73 70 6f 6e 64 69 6e 67 20 74 6f 20 73 65 72 76 65 72 20 3a 2d 44
+{2.000007} [OK|OK] Server's read_cb_srv(): callback triggered
+{2.000007} [OK|OK] Server's read_cb_srv(): received 29(29) bytes: 44 6f 68 2c 20 72 65 73 70 6f 6e 64 69 6e 67 20 74 6f 20 73 65 72 76 65 72 20 3a 2d 44
+{2.000007} [OK|OK] Server's read_cb_srv(): sent 11 bytes message: 72 65 61 64 5f 63 62 5f 73 72 76
+{2.000007} [OK|OK] Server's read_cb_srv(): force client disconnect on subsequent call
+{2.000008} [OK] Client's read_cb_cli(): callback triggered
+{2.000008} [OK] Client's read_cb_cli(): 0-byte read, auto-reconnect will be triggered if enabled
+{11.000010} [OK] Client's connect_cb_cli(): callback triggered <reconnected>
+{11.000010} [OK] Client's connect_cb_cli(): closing connection
+{11.000011} [NA|OK] Server's read_cb_srv(): callback triggered
+{11.000011} [NA|OK] Server's read_cb_srv(): client have already closed connection
+{11.000011} Server requested test termination
+{11.000011} autoreconnecting test complete.
Prepare non-reconnecting stream client...
=======================================
Client/Server entering non-reconnecting event loop...
=======================================
-[NA] Client's connect_cb_cli(): callback triggered <initial>
-[NA] Client's connect_cb_cli(): sent 29 bytes message: 48 69 21 20 66 72 6f 6d 20 63 6f 6e 6e 65 63 74 20 63 61 6c 6c 62 61 63 6b 20 3a 2d 50
-[NA|OK] Server's read_cb_srv(): callback triggered
-[NA|OK] Server's read_cb_srv(): received 29(29) bytes: 48 69 21 20 66 72 6f 6d 20 63 6f 6e 6e 65 63 74 20 63 61 6c 6c 62 61 63 6b 20 3a 2d 50
-[NA|OK] Server's read_cb_srv(): sent 11 bytes message: 72 65 61 64 5f 63 62 5f 73 72 76
-[OK|OK] Server's read_cb_srv(): keep initial client connection
-[NA] Client's read_cb_cli(): callback triggered
-[NA] Client's read_cb_cli(): received 11(11) bytes: 72 65 61 64 5f 63 62 5f 73 72 76
-[NA] Client's read_cb_cli(): initial read, contacting server
-[OK] Client's read_cb_cli(): sent 29 bytes message: 44 6f 68 2c 20 72 65 73 70 6f 6e 64 69 6e 67 20 74 6f 20 73 65 72 76 65 72 20 3a 2d 44
-[OK|OK] Server's read_cb_srv(): callback triggered
-[OK|OK] Server's read_cb_srv(): received 29(29) bytes: 44 6f 68 2c 20 72 65 73 70 6f 6e 64 69 6e 67 20 74 6f 20 73 65 72 76 65 72 20 3a 2d 44
-[OK|OK] Server's read_cb_srv(): sent 11 bytes message: 72 65 61 64 5f 63 62 5f 73 72 76
-[OK|OK] Server's read_cb_srv(): force client disconnect on subsequent call
-[OK] Client's read_cb_cli(): callback triggered
-[OK] Client's read_cb_cli(): 0-byte read, auto-reconnect will be triggered if enabled
-non-reconnecting test complete.
+{11.000012} [NA] Client's connect_cb_cli(): callback triggered <initial>
+{11.000012} [NA] Client's connect_cb_cli(): sent 29 bytes message: 48 69 21 20 66 72 6f 6d 20 63 6f 6e 6e 65 63 74 20 63 61 6c 6c 62 61 63 6b 20 3a 2d 50
+{11.000014} [NA|OK] Server's read_cb_srv(): callback triggered
+{11.000014} [NA|OK] Server's read_cb_srv(): received 29(29) bytes: 48 69 21 20 66 72 6f 6d 20 63 6f 6e 6e 65 63 74 20 63 61 6c 6c 62 61 63 6b 20 3a 2d 50
+{11.000014} [NA|OK] Server's read_cb_srv(): sent 11 bytes message: 72 65 61 64 5f 63 62 5f 73 72 76
+{11.000014} [OK|OK] Server's read_cb_srv(): keep initial client connection
+{11.000016} [NA] Client's read_cb_cli(): callback triggered
+{11.000016} [NA] Client's read_cb_cli(): received 11(11) bytes: 72 65 61 64 5f 63 62 5f 73 72 76
+{11.000016} [NA] Client's read_cb_cli(): initial read, contacting server
+{11.000016} [OK] Client's read_cb_cli(): sent 29 bytes message: 44 6f 68 2c 20 72 65 73 70 6f 6e 64 69 6e 67 20 74 6f 20 73 65 72 76 65 72 20 3a 2d 44
+{11.000018} [OK|OK] Server's read_cb_srv(): callback triggered
+{11.000018} [OK|OK] Server's read_cb_srv(): received 29(29) bytes: 44 6f 68 2c 20 72 65 73 70 6f 6e 64 69 6e 67 20 74 6f 20 73 65 72 76 65 72 20 3a 2d 44
+{11.000018} [OK|OK] Server's read_cb_srv(): sent 11 bytes message: 72 65 61 64 5f 63 62 5f 73 72 76
+{11.000018} [OK|OK] Server's read_cb_srv(): force client disconnect on subsequent call
+{11.000019} [OK] Client's read_cb_cli(): callback triggered
+{11.000019} [OK] Client's read_cb_cli(): 0-byte read, auto-reconnect will be triggered if enabled
+{20.000019} non-reconnecting test complete.
Stream tests completed