logging: Move the filter check up as well

There doesn't seem to be a reason not to check the filter. Update
and extend the test. Currently the filter function will be called
once for the log check and once for the output of it.

3 files changed, 24 insertions, 18 deletions

diff --git a/src/logging.c b/src/logging.c
index 7db7101e..1c9c6634 100644
--- a/src/logging.c
+++ b/src/logging.c
@@ -339,6 +339,15 @@ static inline int check_log_to_target(struct log_target *tar, int subsys, int le
 	    level < category->loglevel)
 		return 0;
 
+	/* Apply filters here... if that becomes messy we will
+	 * need to put filters in a list and each filter will
+	 * say stop, continue, output */
+	if ((tar->filter_map & LOG_FILTER_ALL) != 0)
+		return 1;
+
+	if (osmo_log_info->filter_fn)
+		return osmo_log_info->filter_fn(&log_context, tar);
+
 	/* TODO: Check the filter/selector too? */
 	return 1;
 }
@@ -358,17 +367,6 @@ void osmo_vlogp(int subsys, int level, const char *file, int line,
 		if (!check_log_to_target(tar, subsys, level))
 			continue;
 
-		/* Apply filters here... if that becomes messy we will
-		 * need to put filters in a list and each filter will
-		 * say stop, continue, output */
-		if ((tar->filter_map & LOG_FILTER_ALL) != 0)
-			output = 1;
-		else if (osmo_log_info->filter_fn)
-			output = osmo_log_info->filter_fn(&log_context,
-						       tar);
-		if (!output)
-			continue;
-
 		/* According to the manpage, vsnprintf leaves the value of ap
 		 * in undefined state. Since _output uses vsnprintf and it may
 		 * be called several times, we have to pass a copy of ap. */
diff --git a/tests/logging/logging_test.c b/tests/logging/logging_test.c
index 3c8bac4b..3d1b7d87 100644
--- a/tests/logging/logging_test.c
+++ b/tests/logging/logging_test.c
@@ -30,6 +30,7 @@ enum {
 };
 
 static int filter_called = 0;
+static int select_output = 0;
 
 static const struct log_info_cat default_categories[] = {
 	[DRLL] = {
@@ -56,7 +57,7 @@ static int test_filter(const struct log_context *ctx, struct log_target *target)
 {
 	filter_called += 1;
 	/* omit everything */
-	return 0;
+	return select_output;
 }
 
 const struct log_info log_info = {
@@ -77,6 +78,9 @@ int main(int argc, char **argv)
 
 	log_parse_category_mask(stderr_target, "DRLL:DCC");
 	log_parse_category_mask(stderr_target, "DRLL");
+
+	select_output = 0;
+
 	DEBUGP(DCC, "You should not see this\n");
 	if (log_check_level(DMM, LOGL_DEBUG) != 0)
 		fprintf(stderr, "log_check_level did not catch this case\n");
@@ -87,17 +91,20 @@ int main(int argc, char **argv)
 	DEBUGP(DCC, "You should see this\n");
 	OSMO_ASSERT(log_check_level(DCC, LOGL_DEBUG) != 0);
 	DEBUGP(DMM, "You should not see this\n");
-	if (log_check_level(DMM, LOGL_DEBUG) != 0)
-		fprintf(stderr, "log_check_level did not catch this case\n");
 
+	OSMO_ASSERT(log_check_level(DMM, LOGL_DEBUG) == 0);
 	OSMO_ASSERT(filter_called == 0);
 
 	log_set_all_filter(stderr_target, 0);
 	DEBUGP(DRLL, "You should not see this and filter is called\n");
 	OSMO_ASSERT(filter_called == 1);
-	if (log_check_level(DRLL, LOGL_DEBUG) != 0)
-		fprintf(stderr,
-			"log_check_level did not catch this case (filter)\n");
+	OSMO_ASSERT(log_check_level(DRLL, LOGL_DEBUG) == 0);
+	OSMO_ASSERT(filter_called == 2);
 
+	DEBUGP(DRLL, "You should not see this\n");
+	OSMO_ASSERT(filter_called == 3);
+	select_output = 1;
+	DEBUGP(DRLL, "You should see this\n");
+	OSMO_ASSERT(filter_called == 5); /* called twice on output */
 	return 0;
 }
diff --git a/tests/logging/logging_test.err b/tests/logging/logging_test.err
index c3b67cc2..4891491b 100644
--- a/tests/logging/logging_test.err
+++ b/tests/logging/logging_test.err
@@ -1,3 +1,4 @@
 You should see this
 You should see this
-log_check_level did not catch this case (filter)
+You should see this
+
\ No newline at end of file