Change test timing and time-outs in access-control and authentication

expiry tests and add timestamps to test logging to get more stable
test results on Travis and enable analysing timeing issues.

Signed-off-by: Dennis Potman <dennis.potman@adlinktech.com>
This commit is contained in:
Dennis Potman 2020-03-30 14:23:18 +02:00 committed by eboasson
parent e3056402fc
commit 5e721c99e5
4 changed files with 140 additions and 110 deletions

View file

@ -148,7 +148,7 @@ CU_TheoryDataPoints(ddssec_access_control, config_parameters_file) = {
CU_Theory((const char * test_descr, const char * gov, const char * perm, const char * ca, bool incl_empty_els, bool exp_fail),
ddssec_access_control, config_parameters_file)
{
printf("running test config_parameters_file: %s\n", test_descr);
print_test_msg ("running test config_parameters_file: %s\n", test_descr);
access_control_init (
(const char *[]) { TEST_IDENTITY1_CERTIFICATE, TEST_IDENTITY1_CERTIFICATE },
(const char *[]) { TEST_IDENTITY1_PRIVATE_KEY, TEST_IDENTITY1_PRIVATE_KEY },
@ -170,26 +170,25 @@ CU_TheoryDataPoints(ddssec_access_control, permissions_expiry) = {
/* | */"valid -1 minute until now",
/* | | */"1s valid, create pp after 1100ms",
/* | | | */"node 2 permissions expired",
/* | | | | */"node 1 3s valid, write/read for 1s delayed 3s",
/* | | | | | */"node 2 3s valid, write/read for 1s delayed 3s"),
/* | | | | */"node 1 3s valid, write/read for 10s",
/* | | | | | */"node 2 3s valid, write/read for 10s"),
CU_DataPoints(int32_t, 0, -M(1), 0, 0, 0, 0), /* node 1 permissions not before (offset from local time) */
CU_DataPoints(int32_t, M(1), 0, S(1), D(1), S(3), D(1)), /* node 1 permissions not after (offset from local time) */
CU_DataPoints(int32_t, M(1), 0, S(1), D(1), S(4), D(1)), /* node 1 permissions not after (offset from local time) */
CU_DataPoints(int32_t, 0, -M(1), 0, -D(1), 0, 0), /* node 2 permissions not before (offset from local time) */
CU_DataPoints(int32_t, M(1), 0, S(1), 0, D(1), S(3)), /* node 2 permissions not after (offset from local time) */
CU_DataPoints(int32_t, M(1), 0, S(1), 0, D(1), S(4)), /* node 2 permissions not after (offset from local time) */
CU_DataPoints(uint32_t, 0, 0, 1100, 0, 0, 0), /* delay (ms) after generating permissions */
CU_DataPoints(bool, false, true, true, false, false, false), /* expect pp 1 create failure */
CU_DataPoints(bool, false, true, true, true, false, false), /* expect pp 2 create failure */
CU_DataPoints(uint32_t, 0, 0, 0, 0, 3000, 3000), /* delay (ms) after creating readers/writers */
CU_DataPoints(uint32_t, 1, 0, 0, 0, 1000, 1000), /* write/read data during x ms */
CU_DataPoints(uint32_t, 1, 0, 0, 0, 10000, 10000), /* write/read data during x ms */
CU_DataPoints(bool, false, false, false, false, true, true), /* expect read data failure */
};
CU_Theory(
(const char * test_descr,
int32_t perm1_not_before, int32_t perm1_not_after, int32_t perm2_not_before, int32_t perm2_not_after,
uint32_t delay_perm, bool exp_pp1_fail, bool exp_pp2_fail, uint32_t delay_wr_rd, uint32_t write_read_dur, bool exp_read_fail),
uint32_t delay_perm, bool exp_pp1_fail, bool exp_pp2_fail, uint32_t write_read_dur, bool exp_read_fail),
ddssec_access_control, permissions_expiry, .timeout=20)
{
printf("running test permissions_expiry: %s\n", test_descr);
print_test_msg ("running test permissions_expiry: %s\n", test_descr);
char topic_name[100];
create_topic_name ("ddssec_access_control_", g_topic_nr++, topic_name, sizeof (topic_name));
@ -222,7 +221,6 @@ CU_Theory(
{
dds_entity_t wr = 0, rd = 0;
rd_wr_init (g_participant[0], &g_pubsub[0], &g_topic[0], &wr, g_participant[1], &g_pubsub[1], &g_topic[1], &rd, topic_name);
dds_sleepfor (DDS_MSECS (delay_wr_rd));
write_read_for (wr, g_participant[1], rd, DDS_MSECS (write_read_dur), false, exp_read_fail);
}
@ -243,7 +241,9 @@ CU_Theory(
#undef M
#define N_NODES 4
#define N_RD 1 // N_RD > 1 not yet implemented
#define N_WR 3
#define N_NODES (N_RD + N_WR)
#define PERM_EXP_BASE 3
CU_Test(ddssec_access_control, permissions_expiry_multiple, .timeout=20)
{
@ -266,7 +266,7 @@ CU_Test(ddssec_access_control, permissions_expiry_multiple, .timeout=20)
ca_list[i] = ca;
id[i] = generate_identity (ca_list[i], TEST_IDENTITY_CA1_PRIVATE_KEY, id_name, pk[i], 0, 3600, &id_subj[i]);
exp_fail[i] = false;
dds_duration_t v = DDS_SECS(i == 0 ? 3600 : PERM_EXP_BASE + i); /* 1st node is reader and should not expire */
dds_duration_t v = DDS_SECS(i < N_RD ? 3600 : PERM_EXP_BASE + 2 * i); /* 1st node is reader and should not expire */
grants[i] = get_permissions_grant (id_name, id_subj[i], t_perm, t_perm + v, perm_topic, perm_topic, NULL);
ddsrt_free (id_name);
}
@ -283,25 +283,30 @@ CU_Test(ddssec_access_control, permissions_expiry_multiple, .timeout=20)
dds_qset_history (qos, DDS_HISTORY_KEEP_ALL, -1);
dds_qset_durability (qos, DDS_DURABILITY_TRANSIENT_LOCAL);
dds_qset_reliability (qos, DDS_RELIABILITY_RELIABLE, DDS_INFINITY);
dds_entity_t sub_tp = dds_create_topic (g_participant[0], &SecurityCoreTests_Type1_desc, topic_name, NULL, NULL);
CU_ASSERT_FATAL (sub_tp > 0);
dds_entity_t sub = dds_create_subscriber (g_participant[0], NULL, NULL);
CU_ASSERT_FATAL (sub > 0);
dds_entity_t rd = dds_create_reader (sub, sub_tp, qos, NULL);
CU_ASSERT_FATAL (rd > 0);
dds_set_status_mask (rd, DDS_DATA_AVAILABLE_STATUS);
dds_entity_t wr[N_NODES - 1];
for (int i = 1; i < N_NODES; i++)
dds_entity_t rd[N_RD];
for (int i = 0; i < N_RD; i++)
{
dds_entity_t pub = dds_create_publisher (g_participant[i], NULL, NULL);
dds_entity_t sub = dds_create_subscriber (g_participant[i], NULL, NULL);
CU_ASSERT_FATAL (sub > 0);
dds_entity_t sub_tp = dds_create_topic (g_participant[i], &SecurityCoreTests_Type1_desc, topic_name, NULL, NULL);
CU_ASSERT_FATAL (sub_tp > 0);
rd[i] = dds_create_reader (sub, sub_tp, qos, NULL);
CU_ASSERT_FATAL (rd[i] > 0);
dds_set_status_mask (rd[i], DDS_DATA_AVAILABLE_STATUS);
}
dds_entity_t wr[N_WR];
for (int i = 0; i < N_WR; i++)
{
dds_entity_t pub = dds_create_publisher (g_participant[i + N_RD], NULL, NULL);
CU_ASSERT_FATAL (pub > 0);
dds_entity_t pub_tp = dds_create_topic (g_participant[i], &SecurityCoreTests_Type1_desc, topic_name, NULL, NULL);
dds_entity_t pub_tp = dds_create_topic (g_participant[i + N_RD], &SecurityCoreTests_Type1_desc, topic_name, NULL, NULL);
CU_ASSERT_FATAL (pub_tp > 0);
wr[i - 1] = dds_create_writer (pub, pub_tp, qos, NULL);
CU_ASSERT_FATAL (wr[i - 1] > 0);
dds_set_status_mask (wr[i - 1], DDS_PUBLICATION_MATCHED_STATUS);
sync_writer_to_readers(g_participant[i], wr[i - 1], 1);
wr[i] = dds_create_writer (pub, pub_tp, qos, NULL);
CU_ASSERT_FATAL (wr[i] > 0);
dds_set_status_mask (wr[i], DDS_PUBLICATION_MATCHED_STATUS);
sync_writer_to_readers (g_participant[i + N_RD], wr[i], N_RD);
}
dds_delete_qos (qos);
@ -311,47 +316,48 @@ CU_Test(ddssec_access_control, permissions_expiry_multiple, .timeout=20)
dds_sample_info_t info[1];
dds_return_t ret;
for (int i = 1; i < N_NODES; i++)
for (int i = 0; i < N_WR; i++)
{
// sleep until 1s before next writer pp permission expires
dds_duration_t delay = DDS_SECS (PERM_EXP_BASE + i - 1) - (dds_time () - t_perm);
dds_duration_t delay = DDS_SECS (PERM_EXP_BASE + 2 * i) - (dds_time () - t_perm);
if (delay > 0)
dds_sleepfor (delay);
printf ("run %d\n", i);
print_test_msg ("run %d\n", i);
for (int w = 1; w < N_NODES; w++)
for (int w = 0; w < N_WR; w++)
{
sample.id = w;
ret = dds_write (wr[w - 1], &sample);
ret = dds_write (wr[w], &sample);
CU_ASSERT_EQUAL_FATAL (ret, DDS_RETCODE_OK);
printf ("write %d\n", w);
print_test_msg ("write %d\n", w);
}
// Expect reader to receive data from writers with non-expired permissions
int n_samples = 0, n_invalid = 0, n_wait = 0;
while (n_samples + n_invalid < N_NODES - 1 && n_wait < 5)
while (n_samples + n_invalid < N_WR && n_wait < 5)
{
ret = dds_take (rd, samples, info, 1, 1);
ret = dds_take (rd[0], samples, info, 1, 1);
CU_ASSERT_FATAL (ret >= 0);
if (ret == 0)
{
reader_wait_for_data (g_participant[0], rd, DDS_MSECS (100));
reader_wait_for_data (g_participant[0], rd[0], DDS_MSECS (200));
print_test_msg ("wait for data\n");
n_wait++;
}
else if (info[0].instance_state == DDS_IST_ALIVE)
{
printf ("recv sample %d\n", rd_sample.id);
print_test_msg ("recv sample %d\n", rd_sample.id);
n_samples++;
}
else
{
printf ("recv inv sample\n");
print_test_msg ("recv inv sample\n");
n_invalid++;
}
}
CU_ASSERT_EQUAL (n_samples, N_NODES - i);
CU_ASSERT (n_invalid < i);
CU_ASSERT_EQUAL (n_samples, N_WR - i);
CU_ASSERT (n_invalid <= i);
}
access_control_fini (N_NODES);

View file

@ -228,7 +228,7 @@ CU_Theory((const char * test_descr, const char * id2, const char *key2, const ch
{
struct Handshake *hs_list;
int nhs;
printf("running test id_ca_certs: %s\n", test_descr);
print_test_msg ("running test id_ca_certs: %s\n", test_descr);
authentication_init (ID1, ID1K, CA1, id2, key2, ca2, NULL, NULL, exp_fail_pp1, exp_fail_pp2);
// Domain 1
@ -252,7 +252,7 @@ CU_TheoryDataPoints(ddssec_authentication, trusted_ca_dir) = {
};
CU_Theory((const char * ca_dir, bool exp_fail), ddssec_authentication, trusted_ca_dir)
{
printf("Testing custom CA dir: %s\n", ca_dir);
print_test_msg ("Testing custom CA dir: %s\n", ca_dir);
authentication_init (ID1, ID1K, CA1, ID1, ID1K, CA1, ca_dir, NULL, exp_fail, exp_fail);
if (!exp_fail)
{
@ -275,17 +275,17 @@ CU_TheoryDataPoints(ddssec_authentication, expired_cert) = {
/* | | | | */"ca and id1 1min valid",
/* | | | | | */"id1 and id2 1s valid, delay 1100ms",
/* | | | | | | */"id1 valid after 1s, delay 1100ms",
/* | | | | | | | */"id1 expire during session"),
/* | | | | | | | */"id1 expires during session"),
CU_DataPoints(int32_t, 0, -M(1), 0, 0, 0, 0, 0, 0 ), /* CA1 not before */
CU_DataPoints(int32_t, D(1), 0, D(1), D(1), M(1), D(1), D(1), D(1) ), /* CA1 not after (offset from local time) */
CU_DataPoints(int32_t, 0, 0, -D(1), 0, 0, 0, S(1), 0 ), /* ID1 not before (offset from local time) */
CU_DataPoints(int32_t, D(1), D(1), 0, D(1), M(1), S(1), D(1), S(2) ), /* ID1 not after (offset from local time) */
CU_DataPoints(int32_t, D(1), D(1), 0, D(1), M(1), S(1), D(1), S(4) ), /* ID1 not after (offset from local time) */
CU_DataPoints(bool, false, true, true, false, false, true, false, false ), /* expect validate local ID1 fail */
CU_DataPoints(int32_t, 0, 0, 0, -D(1), 0, 0, 0, 0 ), /* ID2 not before (offset from local time) */
CU_DataPoints(int32_t, D(1), D(1), D(1), 0, D(1), S(1), D(1), D(1) ), /* ID2 not after (offset from local time) */
CU_DataPoints(bool, false, true, false, true, false, true, false, false ), /* expect validate local ID2 fail */
CU_DataPoints(uint32_t, 0, 0, 0, 0, 0, 1100, 1100, 0 ), /* delay (ms) after generating certificate */
CU_DataPoints(uint32_t, 1, 0, 0, 0, 1, 0, 1, 3500 ), /* write/read data during x ms */
CU_DataPoints(uint32_t, 1, 0, 0, 0, 1, 0, 1, 10000 ), /* write/read data during x ms */
CU_DataPoints(bool, false, false, false, false, false, false, false, true ), /* expect read data failure */
};
CU_Theory(
@ -295,11 +295,12 @@ CU_Theory(
uint32_t delay, uint32_t write_read_dur, bool exp_read_fail),
ddssec_authentication, expired_cert, .timeout=30)
{
printf("running test expired_cert: %s\n", test_descr);
print_test_msg ("running test expired_cert: %s\n", test_descr);
char topic_name[100];
create_topic_name("ddssec_authentication_", g_topic_nr++, topic_name, sizeof (topic_name));
print_test_msg ("generate ids (id1: %d-%d, id2: %d-%d):\n", id1_not_before, id1_not_after, id2_not_before, id2_not_after);
char *ca, *id1, *id2, *id1_subj, *id2_subj;
ca = generate_ca ("ca1", CA1K, ca_not_before, ca_not_after);
id1 = generate_identity (ca, CA1K, "id1", ID1K, id1_not_before, id1_not_after, &id1_subj);

View file

@ -61,9 +61,19 @@ static char * get_node_type_str(enum hs_node_type node_type)
return "";
}
void print_test_msg (const char *msg, ...)
{
va_list args;
dds_time_t t = dds_time ();
printf ("%d.%06d ", (int32_t) (t / DDS_NSECS_IN_SEC), (int32_t) (t % DDS_NSECS_IN_SEC) / 1000);
va_start (args, msg);
vprintf (msg, args);
va_end (args);
}
static void add_local_identity (DDS_Security_IdentityHandle handle, DDS_Security_GUID_t *guid)
{
printf("add local identity %"PRId64"\n", handle);
print_test_msg ("add local identity %"PRId64"\n", handle);
localIdentityList[numLocal].handle = handle;
memcpy (&localIdentityList[numLocal].guid, guid, sizeof(DDS_Security_GUID_t));
numLocal++;
@ -93,7 +103,7 @@ static void add_remote_identity(DDS_Security_IdentityHandle handle, DDS_Security
{
if (find_remote_identity (handle) < 0)
{
printf("add remote identity %"PRId64"\n", handle);
print_test_msg ("add remote identity %"PRId64"\n", handle);
remoteIdentityList[numRemote].handle = handle;
memcpy (&remoteIdentityList[numRemote].guid, guid, sizeof(DDS_Security_GUID_t));
numRemote++;
@ -109,7 +119,7 @@ static void clear_stores(void)
static struct Handshake *add_handshake (enum hs_node_type node_type, DDS_Security_IdentityHandle lHandle, DDS_Security_IdentityHandle rHandle)
{
printf("add handshake %"PRId64"-%"PRId64"\n", lHandle, rHandle);
print_test_msg ("add handshake %"PRId64"-%"PRId64"\n", lHandle, rHandle);
handshakeList[numHandshake].handle = -1;
handshakeList[numHandshake].node_type = node_type;
handshakeList[numHandshake].handshakeResult = DDS_SECURITY_VALIDATION_FAILED;
@ -139,7 +149,7 @@ static void handle_process_message(dds_domainid_t domain_id, DDS_Security_Identi
int idx;
if ((idx = find_handshake (msg->hsHandle)) >= 0)
{
printf("set handshake %"PRId64" final result to '%s' (errmsg: %s)\n", msg->hsHandle, get_validation_result_str(msg->result), msg->err_msg);
print_test_msg ("set handshake %"PRId64" final result to '%s' (errmsg: %s)\n", msg->hsHandle, get_validation_result_str (msg->result), msg->err_msg);
handshakeList[idx].finalResult = msg->result;
handshakeList[idx].err_msg = ddsrt_strdup (msg->err_msg);
}
@ -150,7 +160,7 @@ static void handle_process_message(dds_domainid_t domain_id, DDS_Security_Identi
static void handle_begin_handshake_request (dds_domainid_t domain_id, struct Handshake *hs, DDS_Security_IdentityHandle lid, DDS_Security_IdentityHandle rid)
{
struct message *msg;
printf("handle begin handshake request %"PRId64"<->%"PRId64"\n", lid, rid);
print_test_msg ("handle begin handshake request %"PRId64"<->%"PRId64"\n", lid, rid);
if ((msg = test_authentication_plugin_take_msg (domain_id, MESSAGE_KIND_BEGIN_HANDSHAKE_REQUEST, lid, rid, 0, HS_TIMEOUT)))
{
hs->handle = msg->hsHandle;
@ -166,7 +176,7 @@ static void handle_begin_handshake_request(dds_domainid_t domain_id, struct Hand
static void handle_begin_handshake_reply (dds_domainid_t domain_id, struct Handshake *hs, DDS_Security_IdentityHandle lid, DDS_Security_IdentityHandle rid)
{
struct message *msg;
printf("handle begin handshake reply %"PRId64"<->%"PRId64"\n", lid, rid);
print_test_msg ("handle begin handshake reply %"PRId64"<->%"PRId64"\n", lid, rid);
if ((msg = test_authentication_plugin_take_msg (domain_id, MESSAGE_KIND_BEGIN_HANDSHAKE_REPLY, lid, rid, 0, HS_TIMEOUT)))
{
hs->handle = msg->hsHandle;
@ -199,7 +209,7 @@ static void handle_validate_remote_identity(dds_domainid_t domain_id, DDS_Securi
}
else
{
printf("validate remote failed\n");
print_test_msg ("validate remote failed\n");
}
test_authentication_plugin_release_msg (msg);
}
@ -212,7 +222,7 @@ static void handle_validate_local_identity(dds_domainid_t domain_id, bool exp_lo
CU_ASSERT_FATAL ((msg->result == DDS_SECURITY_VALIDATION_OK) != exp_localid_fail);
if (exp_localid_fail && exp_localid_msg)
{
printf("validate_local_identity failed as expected (msg: %s)\n", msg->err_msg);
print_test_msg ("validate_local_identity failed as expected (msg: %s)\n", msg->err_msg);
CU_ASSERT_FATAL (msg->err_msg && strstr (msg->err_msg, exp_localid_msg) != NULL);
}
else
@ -236,9 +246,9 @@ void validate_handshake(dds_domainid_t domain_id, bool exp_localid_fail, const c
for (int n = 0; n < numHandshake; n++)
{
struct Handshake *hs = &handshakeList[n];
printf("Result: hs %"PRId64", node type %s, final result %s\n", hs->handle, get_node_type_str(hs->node_type), get_validation_result_str(hs->finalResult));
print_test_msg ("Result: hs %"PRId64", node type %s, final result %s\n", hs->handle, get_node_type_str (hs->node_type), get_validation_result_str (hs->finalResult));
if (hs->err_msg && strlen (hs->err_msg))
printf("- err_msg: %s\n", hs->err_msg);
print_test_msg ("- err_msg: %s\n", hs->err_msg);
}
if (nhs)
*nhs = numHandshake;
@ -247,7 +257,7 @@ void validate_handshake(dds_domainid_t domain_id, bool exp_localid_fail, const c
else
handshake_list_fini (handshakeList, numHandshake);
}
printf ("finished validate handshake for domain %d\n\n", domain_id);
print_test_msg ("finished validate handshake for domain %d\n\n", domain_id);
}
void validate_handshake_nofail (dds_domainid_t domain_id)
@ -359,6 +369,7 @@ void write_read_for(dds_entity_t wr, dds_entity_t pp_rd, dds_entity_t rd, dds_du
do
{
print_test_msg("write\n");
if (dds_write (wr, &sample) != DDS_RETCODE_OK)
write_fail = true;
@ -366,18 +377,29 @@ void write_read_for(dds_entity_t wr, dds_entity_t pp_rd, dds_entity_t rd, dds_du
{
if ((ret = dds_take (rd, samples, info, 1, 1)) > 0)
{
print_test_msg ("take sample\n");
if (info[0].instance_state != DDS_IST_ALIVE || !info[0].valid_data)
{
print_test_msg ("invalid sample instance_state=%d valid_data=%d\n", info[0].instance_state, info[0].valid_data);
read_fail = true;
}
else
CU_ASSERT_EQUAL_FATAL (rd_sample.value, 1);
CU_ASSERT_EQUAL_FATAL (ret, 1);
break;
}
if (ret < 0 || !reader_wait_for_data (pp_rd, rd, DDS_MSECS (100)))
if (ret < 0 || !reader_wait_for_data (pp_rd, rd, DDS_MSECS (1000)))
{
print_test_msg ("take no sample\n");
read_fail = true;
break;
}
}
dds_sleepfor (DDS_MSECS (1));
if (write_fail || read_fail)
break;
dds_sleepfor (DDS_MSECS (100));
}
while (dds_time() < tend && !write_fail && !read_fail);
CU_ASSERT_EQUAL (write_fail, exp_write_fail);
CU_ASSERT_EQUAL (read_fail, exp_read_fail);
while (dds_time() < tend);
CU_ASSERT_EQUAL_FATAL (write_fail, exp_write_fail);
CU_ASSERT_EQUAL_FATAL (read_fail, exp_read_fail);
}

View file

@ -50,6 +50,7 @@ struct Handshake
char * err_msg;
};
void print_test_msg (const char *msg, ...);
void validate_handshake(dds_domainid_t domain_id, bool exp_localid_fail, const char * exp_localid_msg, struct Handshake *hs_list[], int *nhs);
void validate_handshake_nofail (dds_domainid_t domain_id);
void handshake_list_fini(struct Handshake *hs_list, int nhs);