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.

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. */

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;
 }

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
+