test_http_media_cache: Fix failing test.

The retrieve_cache_control_directives test has been failing occasionally
in Jenkins. The apparent failure occurs when attempting to validate the
expiration of the retrieved file.

After reproducing, the problem was pretty clear. At the beginning of the
test, the current time is retrieved. The seconds value of this timestamp
is X. When the file is retrieved, res_http_media_cache calculates the
expiration and in doing so retrieves the current time. In most cases,
since the test executes quickly, it will also retrieve a timestamp with
X seconds. However, if the test starts very near to when the timestamp
seconds are set to increment, res_http_media_cache may retrieve a
timestamp with X+1 seconds instead.

The test attempted to account for this by allowing a tolerance of 1
second when validating the expiration. However, the problem was that the
comparisons being used in the validation used > and < operations. This
meant that values that fell within the tolerance (because they equaled
the upper bound of the tolerance) would fail.

The solution is to use >= and <= operators in the expiration validation.

However, I estimated that while the one second tolerance should be
fine on most machines, it would still be possible on a very slow machine
to end up falling outside the one second tolerance. So I have also
relaxed the tolerance of expiration validation to be three seconds
instead.

The final change here is to add a debug message when validating
expiration so that we can see what values are being compared.

ASTERISK-25959 #close
Reported by Joshua Colp

Change-Id: Ic1a0e10722c1c5d276d5a4d6a67136d6ec26c247

1 files changed, 19 insertions, 16 deletions

diff --git a/tests/test_http_media_cache.c b/tests/test_http_media_cache.c
index c08604f1e..4cc4e38dc 100644
--- a/tests/test_http_media_cache.c
+++ b/tests/test_http_media_cache.c
@@ -70,7 +70,10 @@ static char server_uri[512];
 	int actual_expires; \
 	ast_test_validate(test, metadata != NULL); \
 	ast_test_validate(test, sscanf(metadata->value, "%d", &actual_expires) == 1); \
-	ast_test_validate(test, (((expected) + (delta) > actual_expires) && ((expected) - (delta) < actual_expires))); \
+	ast_test_status_update(test, "Checking %d >= %d and %d <= %d\n", \
+			(int) ((expected) + (delta)), actual_expires, \
+			(int) ((expected) - (delta)), actual_expires); \
+	ast_test_validate(test, (((expected) + (delta) >= actual_expires) && ((expected) - (delta) <= actual_expires))); \
 } while (0)
 
 #define VALIDATE_STR_METADATA(test, bucket_file, key, expected) do { \
@@ -266,7 +269,7 @@ AST_TEST_DEFINE(retrieve_cache_control_directives)
 	options.cache_control.maxage = 300;
 	bucket_file = ast_bucket_file_retrieve(uri);
 	ast_test_validate(test, bucket_file != NULL);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 3);
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 1);
 	bucket_file_cleanup(bucket_file);
 
@@ -295,7 +298,7 @@ AST_TEST_DEFINE(retrieve_cache_control_directives)
 	options.cache_control.maxage = 300;
 	bucket_file = ast_bucket_file_retrieve(uri);
 	ast_test_validate(test, bucket_file != NULL);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 3);
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 1);
 
 	return AST_TEST_PASS;
@@ -332,7 +335,7 @@ AST_TEST_DEFINE(retrieve_cache_control_age)
 	options.cache_control.maxage = 300;
 	bucket_file = ast_bucket_file_retrieve(uri);
 	ast_test_validate(test, bucket_file != NULL);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 3);
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 0);
 	bucket_file_cleanup(bucket_file);
 
@@ -342,7 +345,7 @@ AST_TEST_DEFINE(retrieve_cache_control_age)
 	options.cache_control.s_maxage = 300;
 	bucket_file = ast_bucket_file_retrieve(uri);
 	ast_test_validate(test, bucket_file != NULL);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 3);
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 0);
 	bucket_file_cleanup(bucket_file);
 
@@ -352,7 +355,7 @@ AST_TEST_DEFINE(retrieve_cache_control_age)
 	options.cache_control.s_maxage = 600;
 	bucket_file = ast_bucket_file_retrieve(uri);
 	ast_test_validate(test, bucket_file != NULL);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 600, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 600, 3);
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 0);
 	bucket_file_cleanup(bucket_file);
 
@@ -363,7 +366,7 @@ AST_TEST_DEFINE(retrieve_cache_control_age)
 	options.expires.tv_sec = now.tv_sec + 3000;
 	bucket_file = ast_bucket_file_retrieve(uri);
 	ast_test_validate(test, bucket_file != NULL);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 3);
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 0);
 	bucket_file_cleanup(bucket_file);
 
@@ -374,7 +377,7 @@ AST_TEST_DEFINE(retrieve_cache_control_age)
 	options.expires.tv_sec = now.tv_sec + 3000;
 	bucket_file = ast_bucket_file_retrieve(uri);
 	ast_test_validate(test, bucket_file != NULL);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 3);
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 0);
 	bucket_file_cleanup(bucket_file);
 
@@ -385,7 +388,7 @@ AST_TEST_DEFINE(retrieve_cache_control_age)
 	options.expires.tv_sec = now.tv_sec + 3000;
 	bucket_file = ast_bucket_file_retrieve(uri);
 	ast_test_validate(test, bucket_file != NULL);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 300, 3);
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 0);
 	bucket_file_cleanup(bucket_file);
 
@@ -396,7 +399,7 @@ AST_TEST_DEFINE(retrieve_cache_control_age)
 	options.expires.tv_sec = now.tv_sec + 3000;
 	bucket_file = ast_bucket_file_retrieve(uri);
 	ast_test_validate(test, bucket_file != NULL);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 600, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 600, 3);
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 0);
 
 	return AST_TEST_PASS;
@@ -436,7 +439,7 @@ AST_TEST_DEFINE(retrieve_etag_expired)
 	ast_test_validate(test, !strcmp(uri, ast_sorcery_object_get_id(bucket_file)));
 	ast_test_validate(test, !ast_strlen_zero(bucket_file->path));
 	VALIDATE_STR_METADATA(test, bucket_file, "etag", options.etag);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec - 1, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec - 1, 3);
 
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 0);
 
@@ -476,7 +479,7 @@ AST_TEST_DEFINE(retrieve_expires)
 	ast_test_validate(test, bucket_file != NULL);
 	ast_test_validate(test, !strcmp(uri, ast_sorcery_object_get_id(bucket_file)));
 	ast_test_validate(test, !ast_strlen_zero(bucket_file->path));
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 3000, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec + 3000, 3);
 
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 0);
 
@@ -486,7 +489,7 @@ AST_TEST_DEFINE(retrieve_expires)
 	options.expires.tv_sec = now.tv_sec - 1;
 	bucket_file = ast_bucket_file_retrieve(uri);
 	ast_test_validate(test, bucket_file != NULL);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec - 1, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec - 1, 3);
 
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 1);
 
@@ -526,7 +529,7 @@ AST_TEST_DEFINE(retrieve_etag)
 	ast_test_validate(test, !strcmp(uri, ast_sorcery_object_get_id(bucket_file)));
 	ast_test_validate(test, !ast_strlen_zero(bucket_file->path));
 	VALIDATE_STR_METADATA(test, bucket_file, "etag", options.etag);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec, 3);
 
 	ast_test_validate(test, ast_bucket_file_is_stale(bucket_file) == 0);
 
@@ -564,7 +567,7 @@ AST_TEST_DEFINE(retrieve_nominal)
 	ast_test_validate(test, bucket_file != NULL);
 	ast_test_validate(test, !strcmp(uri, ast_sorcery_object_get_id(bucket_file)));
 	ast_test_validate(test, !ast_strlen_zero(bucket_file->path));
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec, 3);
 
 	return AST_TEST_PASS;
 }
@@ -597,7 +600,7 @@ AST_TEST_DEFINE(create_nominal)
 	ast_test_validate(test, bucket_file != NULL);
 	ast_test_validate(test, ast_bucket_file_temporary_create(bucket_file) == 0);
 	ast_test_validate(test, ast_bucket_file_create(bucket_file) == 0);
-	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec, 1);
+	VALIDATE_EXPIRES(test, bucket_file, now.tv_sec, 3);
 
 	return AST_TEST_PASS;
 }