[PATCH 00/19] multipath-tools: improve logging at -v3

[PATCH 00/19] multipath-tools: improve logging at -v3

[Martin Wilck]

Hi Christophe,

most of the patches in this series reduce log levels of frequently
printed messages at verbosity level 3. My goal was to limit the
output of multipathd to one line per path per checker invocation,
which is sufficient to track multipathd's view of path health in
the logs.

The standard setting of -v2 is not enough for post-mortem analysis of many
failures. With this series, running multipathd with verbosity 3 becomes a
realistic option even in production environments. So far the amount of output
from multipathd with -v3 pretty much made this impossible, at least over
longer time periods, and also made reading these logs very cumbersome due to
the amount of redundant partly superfluos verbosity. I've taken care not
to loose important information in the logs.

Apart from that, the series fixes errors in the unit tests introduced by my
last "checker overhaul" patch series (proving that I forgot to run the
tests before submitting :-( ), and fixes a problem that I found while testing
handling of a bad configuration (paths with size mismatch).

Regards,
Martin

Martin Wilck (19):
  tests/hwtable: set multipath_dir in local configuration
  tests/hwtable: adjust to new checker API
  multipath-tools: decrease verbosity of state messages
  libmultipath: decrease verbosity of pathinfo messages
  libmultipath: decrease verbosity of TUR checker messages
  libmultipath: avoid frequent messages from filter_property()
  libmultipath: decrease log level of "disassembled" messages
  libmultipath: decrease log level of word splitting
  libmultipath: increase log level of map removal
  multipathd: decrease log level of checker timing
  libmultipath: decrease log level of "prioritizer refcount" message
  libmpathpersist/update_map_pr: decrease log level for nop
  libmultipath: simplify devt2devname()
  libmultipath: decrease log level for failed VPD c9
  libmultipath: adopt_paths: check for size match
  libmultipath: coalesce_paths: fix size mismatch handling
  tests: add unit tests for bitmask functions
  multipathd: uev_remove_path: remove redundant orphan_paths call
  libmultipath: improve logging from orphan_paths

 libmpathpersist/mpath_persist.c |  3 +-
 libmultipath/blacklist.c        | 54 +++++++++---------
 libmultipath/blacklist.h        |  2 +-
 libmultipath/checkers/tur.c     |  6 +-
 libmultipath/configure.c        | 39 +++++++++----
 libmultipath/discovery.c        | 20 ++++---
 libmultipath/dmparser.c         |  6 +-
 libmultipath/prio.c             |  2 +-
 libmultipath/structs_vec.c      | 18 ++++--
 libmultipath/structs_vec.h      |  3 +-
 libmultipath/util.c             |  7 ++-
 libmultipath/util.h             | 16 ++++++
 multipathd/main.c               | 24 ++++----
 tests/Makefile                  |  7 ++-
 tests/blacklist.c               |  7 ++-
 tests/hwtable.c                 | 89 ++++++++++++++++--------------
 tests/util.c                    | 98 +++++++++++++++++++++++++++++++++
 17 files changed, 278 insertions(+), 123 deletions(-)

-- 
2.19.1

[PATCH 01/19] tests/hwtable: set multipath_dir in local configuration

[Martin Wilck]

If internal libmultipath APIs change (such as, recently, the
checker API), test programs will fail because they'll link
with the standard system prioritizer / checker / foreign APIs.

Make sure we always link with our own shared libraries.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 tests/Makefile  | 7 ++++++-
 tests/hwtable.c | 5 +++++
 2 files changed, 11 insertions(+), 1 deletion(-)

diff --git a/tests/Makefile b/tests/Makefile
index b37b5027..ef900866 100644
--- a/tests/Makefile
+++ b/tests/Makefile
@@ -26,7 +26,11 @@ hwtable-test_LIBDEPS := -ludev -lpthread -ldl
 blacklist-test_OBJDEPS := ../libmultipath/blacklist.o
 blacklist-test_LIBDEPS := -ludev
 
-%.out:	%-test
+lib/libchecktur.so:
+	mkdir lib
+	ln -t lib ../libmultipath/{checkers,prioritizers,foreign}/*.so
+
+%.out:	%-test lib/libchecktur.so
 	@echo == running $< ==
 	@LD_LIBRARY_PATH=$(multipathdir):$(mpathcmddir) ./$< >$@
 
@@ -34,6 +38,7 @@ OBJS = $(TESTS:%=%.o) test-lib.o
 
 clean: dep_clean
 	$(RM) $(TESTS:%=%-test) $(TESTS:%=%.out) $(OBJS)
+	$(RM) -rf lib
 
 .SECONDARY: $(OBJS)
 
diff --git a/tests/hwtable.c b/tests/hwtable.c
index 9146ecc3..1cd788ac 100644
--- a/tests/hwtable.c
+++ b/tests/hwtable.c
@@ -250,14 +250,19 @@ static void write_defaults(const struct hwt_state *hwt)
 	static struct key_value defaults[] = {
 		{ "config_dir", NULL },
 		{ "bindings_file", NULL },
+		{ "multipath_dir", NULL },
 		{ "detect_prio", "no" },
 		{ "detect_checker", "no" },
 	};
 	char buf[sizeof(tmplate) + sizeof(bindings_name)];
+	char dirbuf[PATH_MAX];
 
 	snprintf(buf, sizeof(buf), "%s/%s", hwt->tmpname, bindings_name);
 	defaults[0].value = hwt->dirname;
 	defaults[1].value = buf;
+	assert_ptr_not_equal(getcwd(dirbuf, sizeof(dirbuf)), NULL);
+	strncat(dirbuf, "/lib", sizeof(dirbuf));
+	defaults[2].value = dirbuf;
 	write_section(hwt->config_file, "defaults",
 		      ARRAY_SIZE(defaults), defaults);
 }
-- 
2.19.1

[PATCH 02/19] tests/hwtable: adjust to new checker API

[Martin Wilck]

checker.name doesn't exist any more.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 tests/hwtable.c | 84 ++++++++++++++++++++++++-------------------------
 1 file changed, 42 insertions(+), 42 deletions(-)

diff --git a/tests/hwtable.c b/tests/hwtable.c
index 1cd788ac..789481ff 100644
--- a/tests/hwtable.c
+++ b/tests/hwtable.c
@@ -570,7 +570,7 @@ static void test_internal_nvme(const struct hwt_state *hwt)
 	pp = mock_path("NVME", "NoName");
 	mp = mock_multipath(pp);
 	assert_ptr_not_equal(mp, NULL);
-	TEST_PROP(pp->checker.name, NONE);
+	TEST_PROP(checker_name(&pp->checker), NONE);
 	TEST_PROP(pp->uid_attribute, "ID_WWN");
 	assert_int_equal(mp->pgpolicy, DEFAULT_PGPOLICY);
 	assert_int_equal(mp->no_path_retry, DEFAULT_NO_PATH_RETRY);
@@ -583,7 +583,7 @@ static void test_internal_nvme(const struct hwt_state *hwt)
 			    default_wwid_1);
 	mp = mock_multipath(pp);
 	assert_ptr_not_equal(mp, NULL);
-	TEST_PROP(pp->checker.name, NONE);
+	TEST_PROP(checker_name(&pp->checker), NONE);
 	TEST_PROP(pp->uid_attribute, "ID_WWN");
 	assert_int_equal(mp->pgpolicy, MULTIBUS);
 	assert_int_equal(mp->no_path_retry, NO_PATH_RETRY_QUEUE);
@@ -755,31 +755,31 @@ static void test_regex_string_hwe(const struct hwt_state *hwt)
 	pp = mock_path(vnd_foo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), prio_emc.value);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* boo:baz matches kv1 */
 	pp = mock_path(vnd_boo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), prio_emc.value);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* .oo:ba. matches kv1 */
 	pp = mock_path(vnd__oo.value, prd_ba_.value);
 	TEST_PROP(prio_name(&pp->prio), prio_emc.value);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* .foo:(bar|baz|ba\.) doesn't match */
 	pp = mock_path(vnd__oo.value, prd_ba_s.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 
 	/* foo:bar matches kv2 and kv1 */
 	pp = mock_path_flags(vnd_foo.value, prd_bar.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 }
 
 static int setup_regex_string_hwe(void **state)
@@ -812,32 +812,32 @@ static void test_regex_string_hwe_dir(const struct hwt_state *hwt)
 	pp = mock_path(vnd_foo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), prio_emc.value);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* boo:baz matches kv1 */
 	pp = mock_path(vnd_boo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), prio_emc.value);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* .oo:ba. matches kv1 */
 	pp = mock_path(vnd__oo.value, prd_ba_.value);
 	TEST_PROP(prio_name(&pp->prio), prio_emc.value);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* .oo:(bar|baz|ba\.)$ doesn't match */
 	pp = mock_path(vnd__oo.value, prd_ba_s.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 
 	/* foo:bar matches kv2 */
 	pp = mock_path_flags(vnd_foo.value, prd_bar.value, USE_GETUID);
 	/* Later match takes prio */
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 }
 
 static int setup_regex_string_hwe_dir(void **state)
@@ -868,28 +868,28 @@ static void test_regex_2_strings_hwe_dir(const struct hwt_state *hwt)
 	TEST_PROP(prio_name(&pp->prio), prio_emc.value);
 	TEST_PROP(pp->getuid, NULL);
 	TEST_PROP(pp->uid_attribute, DEFAULT_UID_ATTRIBUTE);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* boo:baz doesn't match */
 	pp = mock_path(vnd_boo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
 	TEST_PROP(pp->uid_attribute, DEFAULT_UID_ATTRIBUTE);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 
 	/* foo:bar matches kv2 and kv1 */
 	pp = mock_path(vnd_foo.value, prd_bar.value);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, NULL);
 	TEST_PROP(pp->uid_attribute, uid_baz.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* foo:barz matches kv3 and kv2 and kv1 */
 	pp = mock_path_flags(vnd_foo.value, prd_barz.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_rdac.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
 	TEST_PROP(pp->uid_attribute, NULL);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 }
 
 static int setup_regex_2_strings_hwe_dir(void **state)
@@ -926,31 +926,31 @@ static void test_string_regex_hwe_dir(const struct hwt_state *hwt)
 	pp = mock_path_flags(vnd_foo.value, prd_bar.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_emc.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* foo:baz matches kv1 */
 	pp = mock_path(vnd_foo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), prio_emc.value);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* boo:baz matches kv1 */
 	pp = mock_path(vnd_boo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), prio_emc.value);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* .oo:ba. matches kv1 */
 	pp = mock_path(vnd__oo.value, prd_ba_.value);
 	TEST_PROP(prio_name(&pp->prio), prio_emc.value);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* .oo:(bar|baz|ba\.)$ doesn't match */
 	pp = mock_path(vnd__oo.value, prd_ba_s.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 }
 
 static int setup_string_regex_hwe_dir(void **state)
@@ -980,13 +980,13 @@ static void test_2_ident_strings_hwe(const struct hwt_state *hwt)
 	pp = mock_path(vnd_foo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 
 	/* foo:bar matches both */
 	pp = mock_path_flags(vnd_foo.value, prd_bar.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 }
 
 static int setup_2_ident_strings_hwe(void **state)
@@ -1015,13 +1015,13 @@ static void test_2_ident_strings_both_dir(const struct hwt_state *hwt)
 	pp = mock_path(vnd_foo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 
 	/* foo:bar matches both */
 	pp = mock_path_flags(vnd_foo.value, prd_bar.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 }
 
 static int setup_2_ident_strings_both_dir(void **state)
@@ -1055,13 +1055,13 @@ static void test_2_ident_strings_both_dir_w_prev(const struct hwt_state *hwt)
 	pp = mock_path(vnd_foo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 
 	/* foo:bar matches both */
 	pp = mock_path_flags(vnd_foo.value, prd_bar.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 }
 
 static int setup_2_ident_strings_both_dir_w_prev(void **state)
@@ -1100,13 +1100,13 @@ static void test_2_ident_strings_hwe_dir(const struct hwt_state *hwt)
 	pp = mock_path(vnd_foo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 
 	/* foo:bar matches both */
 	pp = mock_path_flags(vnd_foo.value, prd_bar.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 }
 
 static int setup_2_ident_strings_hwe_dir(void **state)
@@ -1134,13 +1134,13 @@ static void test_3_ident_strings_hwe_dir(const struct hwt_state *hwt)
 	pp = mock_path(vnd_foo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 
 	/* foo:bar matches both */
 	pp = mock_path_flags(vnd_foo.value, prd_bar.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 }
 
 static int setup_3_ident_strings_hwe_dir(void **state)
@@ -1178,13 +1178,13 @@ static void test_2_ident_self_matching_re_hwe_dir(const struct hwt_state *hwt)
 	pp = mock_path(vnd_foo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 
 	/* foo:bar matches both */
 	pp = mock_path_flags(vnd_foo.value, prd_bar.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 }
 
 static int setup_2_ident_self_matching_re_hwe_dir(void **state)
@@ -1213,13 +1213,13 @@ static void test_2_ident_self_matching_re_hwe(const struct hwt_state *hwt)
 	pp = mock_path(vnd_foo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 
 	/* foo:bar matches */
 	pp = mock_path_flags(vnd_foo.value, prd_bar.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 }
 
 static int setup_2_ident_self_matching_re_hwe(void **state)
@@ -1250,13 +1250,13 @@ test_2_ident_not_self_matching_re_hwe_dir(const struct hwt_state *hwt)
 	pp = mock_path(vnd_foo.value, prd_baz.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 
 	/* foo:bar matches both */
 	pp = mock_path_flags(vnd_foo.value, prd_bar.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 }
 
 static int setup_2_ident_not_self_matching_re_hwe_dir(void **state)
@@ -1287,19 +1287,19 @@ static void test_2_matching_res_hwe_dir(const struct hwt_state *hwt)
 	pp = mock_path(vnd_foo.value, prd_bar.value);
 	TEST_PROP(prio_name(&pp->prio), prio_emc.value);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* foo:bay matches k1 and k2 */
 	pp = mock_path_flags(vnd_foo.value, "bay", USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 
 	/* foo:baz matches k2 only. */
 	pp = mock_path_flags(vnd_foo.value, prd_baz.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 }
 
 static int setup_2_matching_res_hwe_dir(void **state)
@@ -1328,12 +1328,12 @@ static void test_2_nonmatching_res_hwe_dir(const struct hwt_state *hwt)
 	pp = mock_path(vnd_foo.value, prd_bar.value);
 	TEST_PROP(prio_name(&pp->prio), DEFAULT_PRIO);
 	TEST_PROP(pp->getuid, NULL);
-	TEST_PROP(pp->checker.name, DEFAULT_CHECKER);
+	TEST_PROP(checker_name(&pp->checker), DEFAULT_CHECKER);
 
 	pp = mock_path_flags(vnd_foo.value, prd_baz.value, USE_GETUID);
 	TEST_PROP(prio_name(&pp->prio), prio_hds.value);
 	TEST_PROP(pp->getuid, gui_foo.value);
-	TEST_PROP(pp->checker.name, chk_hp.value);
+	TEST_PROP(checker_name(&pp->checker), chk_hp.value);
 }
 
 static int setup_2_nonmatching_res_hwe_dir(void **state)
-- 
2.19.1

[PATCH 03/19] multipath-tools: decrease verbosity of state messages

[Martin Wilck]

With verbosity level 3, thousands of "path state = running" messages
are logged, which are pretty much irrelevant, as the checker state
takes precedence. Also the "get_state" message is totally useless.

With this patch, the path state is reported exactly once per path
and check.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/discovery.c |  4 +---
 multipathd/main.c        | 18 ++++++++++--------
 2 files changed, 11 insertions(+), 11 deletions(-)

diff --git a/libmultipath/discovery.c b/libmultipath/discovery.c
index 63558ad8..f9a59011 100644
--- a/libmultipath/discovery.c
+++ b/libmultipath/discovery.c
@@ -1433,7 +1433,7 @@ path_offline (struct path * pp)
 	}
 
 
-	condlog(3, "%s: path state = %s", pp->dev, buff);
+	condlog(4, "%s: path state = %s", pp->dev, buff);
 
 	if (pp->bus == SYSFS_BUS_SCSI) {
 		if (!strncmp(buff, "offline", 7)) {
@@ -1552,8 +1552,6 @@ get_state (struct path * pp, struct config *conf, int daemon, int oldstate)
 	struct checker * c = &pp->checker;
 	int state;
 
-	condlog(3, "%s: get_state", pp->dev);
-
 	if (!checker_selected(c)) {
 		if (daemon) {
 			if (pathinfo(pp, conf, DI_SYSFS) != PATHINFO_OK) {
diff --git a/multipathd/main.c b/multipathd/main.c
index cc555bb7..88ae4903 100644
--- a/multipathd/main.c
+++ b/multipathd/main.c
@@ -1909,6 +1909,16 @@ check_path (struct vectors * vecs, struct path * pp, int ticks)
 	pp->tick = checkint;
 
 	newstate = path_offline(pp);
+	if (newstate == PATH_UP) {
+		conf = get_multipath_config();
+		pthread_cleanup_push(put_multipath_config, conf);
+		newstate = get_state(pp, conf, 1, newstate);
+		pthread_cleanup_pop(1);
+	} else {
+		checker_clear_message(&pp->checker);
+		condlog(3, "%s: state %s, checker not called",
+			pp->dev, checker_state_name(newstate));
+	}
 	/*
 	 * Wait for uevent for removed paths;
 	 * some LLDDs like zfcp keep paths unavailable
@@ -1917,14 +1927,6 @@ check_path (struct vectors * vecs, struct path * pp, int ticks)
 	if (newstate == PATH_REMOVED)
 		newstate = PATH_DOWN;
 
-	if (newstate == PATH_UP) {
-		conf = get_multipath_config();
-		pthread_cleanup_push(put_multipath_config, conf);
-		newstate = get_state(pp, conf, 1, newstate);
-		pthread_cleanup_pop(1);
-	} else
-		checker_clear_message(&pp->checker);
-
 	if (pp->wwid_changed) {
 		condlog(2, "%s: path wwid has changed. Refusing to use",
 			pp->dev);
-- 
2.19.1

[PATCH 04/19] libmultipath: decrease verbosity of pathinfo messages

[Martin Wilck]

Reduce the verbosity of pointless messages from pathinfo(), in
particular those that are printed on every checker invocation.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/discovery.c | 10 ++++++----
 1 file changed, 6 insertions(+), 4 deletions(-)

diff --git a/libmultipath/discovery.c b/libmultipath/discovery.c
index f9a59011..3ad33492 100644
--- a/libmultipath/discovery.c
+++ b/libmultipath/discovery.c
@@ -1382,7 +1382,7 @@ common_sysfs_pathinfo (struct path * pp)
 	devt = udev_device_get_devnum(pp->udev);
 	snprintf(pp->dev_t, BLK_DEV_SIZE, "%d:%d", major(devt), minor(devt));
 
-	condlog(3, "%s: dev_t = %s", pp->dev, pp->dev_t);
+	condlog(4, "%s: dev_t = %s", pp->dev, pp->dev_t);
 
 	if (sysfs_get_size(pp, &pp->size))
 		return PATHINFO_FAILED;
@@ -1599,6 +1599,7 @@ get_prio (struct path * pp)
 	struct prio * p;
 	struct config *conf;
 	int checker_timeout;
+	int old_prio;
 
 	if (!pp)
 		return 0;
@@ -1619,13 +1620,14 @@ get_prio (struct path * pp)
 	conf = get_multipath_config();
 	checker_timeout = conf->checker_timeout;
 	put_multipath_config(conf);
+	old_prio = pp->priority;
 	pp->priority = prio_getprio(p, pp, checker_timeout);
 	if (pp->priority < 0) {
 		condlog(3, "%s: %s prio error", pp->dev, prio_name(p));
 		pp->priority = PRIO_UNDEF;
 		return 1;
 	}
-	condlog(3, "%s: %s prio = %u",
+	condlog((old_prio == pp->priority ? 4 : 3), "%s: %s prio = %u",
 		pp->dev, prio_name(p), pp->priority);
 	return 0;
 }
@@ -1863,7 +1865,7 @@ int pathinfo(struct path *pp, struct config *conf, int mask)
 			udev_device_get_sysattr_value(pp->udev, "hidden");
 
 		if (hidden && !strcmp(hidden, "1")) {
-			condlog(3, "%s: hidden", pp->dev);
+			condlog(4, "%s: hidden", pp->dev);
 			return PATHINFO_SKIPPED;
 		}
 		if (is_claimed_by_foreign(pp->udev) ||
@@ -1876,7 +1878,7 @@ int pathinfo(struct path *pp, struct config *conf, int mask)
 			   pp->dev) > 0)
 		return PATHINFO_SKIPPED;
 
-	condlog(3, "%s: mask = 0x%x", pp->dev, mask);
+	condlog(4, "%s: mask = 0x%x", pp->dev, mask);
 
 	/*
 	 * Sanity check: we need the device number to
-- 
2.19.1

[PATCH 05/19] libmultipath: decrease verbosity of TUR checker messages

[Martin Wilck]

The thread startup/stop messages aren't very interesting.
Decrease their verbosity level to v4.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/checkers/tur.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/libmultipath/checkers/tur.c b/libmultipath/checkers/tur.c
index 63b19624..6b08dbbb 100644
--- a/libmultipath/checkers/tur.c
+++ b/libmultipath/checkers/tur.c
@@ -261,7 +261,7 @@ static void *tur_thread(void *ctx)
 	tur_thread_cleanup_push(ct);
 	rcu_register_thread();
 
-	condlog(3, "%d:%d : tur checker starting up", major(ct->devt),
+	condlog(4, "%d:%d : tur checker starting up", major(ct->devt),
 		minor(ct->devt));
 
 	tur_deep_sleep(ct);
@@ -275,7 +275,7 @@ static void *tur_thread(void *ctx)
 	pthread_cond_signal(&ct->active);
 	pthread_mutex_unlock(&ct->lock);
 
-	condlog(3, "%d:%d : tur checker finished, state %s", major(ct->devt),
+	condlog(4, "%d:%d : tur checker finished, state %s", major(ct->devt),
 		minor(ct->devt), checker_state_name(state));
 
 	running = uatomic_xchg(&ct->running, 0);
@@ -415,7 +415,7 @@ int libcheck_check(struct checker * c)
 		}
 		pthread_mutex_unlock(&ct->lock);
 		if (tur_status == PATH_PENDING) {
-			condlog(3, "%d:%d : tur checker still running",
+			condlog(4, "%d:%d : tur checker still running",
 				major(ct->devt), minor(ct->devt));
 		} else {
 			int running = uatomic_xchg(&ct->running, 0);
-- 
2.19.1

[PATCH 06/19] libmultipath: avoid frequent messages from filter_property()

[Martin Wilck]

Unlike the other filter functions, filter_property() is called
on every pathinfo() call, and prints a message with -v3 every
time. Avoid that by using a lower log priority for the call
from pathinfo().

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/blacklist.c | 54 ++++++++++++++++++++--------------------
 libmultipath/blacklist.h |  2 +-
 libmultipath/configure.c |  6 ++---
 libmultipath/discovery.c |  2 +-
 tests/blacklist.c        |  7 +++---
 5 files changed, 36 insertions(+), 35 deletions(-)

diff --git a/libmultipath/blacklist.c b/libmultipath/blacklist.c
index 318ec03f..709895e2 100644
--- a/libmultipath/blacklist.c
+++ b/libmultipath/blacklist.c
@@ -232,24 +232,24 @@ setup_default_blist (struct config * conf)
 	return 0;
 }
 
-#define LOG_BLIST(M,S)							\
+#define LOG_BLIST(M, S, lvl)						\
 	if (vendor && product)						\
-		condlog(3, "%s: (%s:%s) %s %s",				\
+		condlog(lvl, "%s: (%s:%s) %s %s",			\
 			dev, vendor, product, (M), (S));		\
 	else if (wwid && !dev)						\
-		condlog(3, "%s: %s %s", wwid, (M), (S));		\
+		condlog(lvl, "%s: %s %s", wwid, (M), (S));		\
 	else if (wwid)							\
-		condlog(3, "%s: %s %s %s", dev, (M), wwid, (S));	\
+		condlog(lvl, "%s: %s %s %s", dev, (M), wwid, (S));	\
 	else if (env)							\
-		condlog(3, "%s: %s %s %s", dev, (M), env, (S));		\
+		condlog(lvl, "%s: %s %s %s", dev, (M), env, (S));	\
 	else if (protocol)						\
-		condlog(3, "%s: %s %s %s", dev, (M), protocol, (S));	\
+		condlog(lvl, "%s: %s %s %s", dev, (M), protocol, (S));	\
 	else								\
-		condlog(3, "%s: %s %s", dev, (M), (S))
+		condlog(lvl, "%s: %s %s", dev, (M), (S))
 
-void
+static void
 log_filter (const char *dev, char *vendor, char *product, char *wwid,
-	    const char *env, const char *protocol, int r)
+	    const char *env, const char *protocol, int r, int lvl)
 {
 	/*
 	 * Try to sort from most likely to least.
@@ -258,37 +258,37 @@ log_filter (const char *dev, char *vendor, char *product, char *wwid,
 	case MATCH_NOTHING:
 		break;
 	case MATCH_DEVICE_BLIST:
-		LOG_BLIST("vendor/product", "blacklisted");
+		LOG_BLIST("vendor/product", "blacklisted", lvl);
 		break;
 	case MATCH_WWID_BLIST:
-		LOG_BLIST("wwid", "blacklisted");
+		LOG_BLIST("wwid", "blacklisted", lvl);
 		break;
 	case MATCH_DEVNODE_BLIST:
-		LOG_BLIST("device node name", "blacklisted");
+		LOG_BLIST("device node name", "blacklisted", lvl);
 		break;
 	case MATCH_PROPERTY_BLIST:
-		LOG_BLIST("udev property", "blacklisted");
+		LOG_BLIST("udev property", "blacklisted", lvl);
 		break;
 	case MATCH_PROTOCOL_BLIST:
-		LOG_BLIST("protocol", "blacklisted");
+		LOG_BLIST("protocol", "blacklisted", lvl);
 		break;
 	case MATCH_DEVICE_BLIST_EXCEPT:
-		LOG_BLIST("vendor/product", "whitelisted");
+		LOG_BLIST("vendor/product", "whitelisted", lvl);
 		break;
 	case MATCH_WWID_BLIST_EXCEPT:
-		LOG_BLIST("wwid", "whitelisted");
+		LOG_BLIST("wwid", "whitelisted", lvl);
 		break;
 	case MATCH_DEVNODE_BLIST_EXCEPT:
-		LOG_BLIST("device node name", "whitelisted");
+		LOG_BLIST("device node name", "whitelisted", lvl);
 		break;
 	case MATCH_PROPERTY_BLIST_EXCEPT:
-		LOG_BLIST("udev property", "whitelisted");
+		LOG_BLIST("udev property", "whitelisted", lvl);
 		break;
 	case MATCH_PROPERTY_BLIST_MISSING:
-		LOG_BLIST("blacklisted,", "udev property missing");
+		LOG_BLIST("blacklisted,", "udev property missing", lvl);
 		break;
 	case MATCH_PROTOCOL_BLIST_EXCEPT:
-		LOG_BLIST("protocol", "whitelisted");
+		LOG_BLIST("protocol", "whitelisted", lvl);
 		break;
 	}
 }
@@ -306,7 +306,7 @@ filter_device (vector blist, vector elist, char * vendor, char * product,
 			r = MATCH_DEVICE_BLIST;
 	}
 
-	log_filter(dev, vendor, product, NULL, NULL, NULL, r);
+	log_filter(dev, vendor, product, NULL, NULL, NULL, r, 3);
 	return r;
 }
 
@@ -322,7 +322,7 @@ filter_devnode (vector blist, vector elist, char * dev)
 			r = MATCH_DEVNODE_BLIST;
 	}
 
-	log_filter(dev, NULL, NULL, NULL, NULL, NULL, r);
+	log_filter(dev, NULL, NULL, NULL, NULL, NULL, r, 3);
 	return r;
 }
 
@@ -338,7 +338,7 @@ filter_wwid (vector blist, vector elist, char * wwid, char * dev)
 			r = MATCH_WWID_BLIST;
 	}
 
-	log_filter(dev, NULL, NULL, wwid, NULL, NULL, r);
+	log_filter(dev, NULL, NULL, wwid, NULL, NULL, r, 3);
 	return r;
 }
 
@@ -357,7 +357,7 @@ filter_protocol(vector blist, vector elist, struct path * pp)
 			r = MATCH_PROTOCOL_BLIST;
 	}
 
-	log_filter(pp->dev, NULL, NULL, NULL, NULL, buf, r);
+	log_filter(pp->dev, NULL, NULL, NULL, NULL, buf, r, 3);
 	return r;
 }
 
@@ -366,7 +366,7 @@ filter_path (struct config * conf, struct path * pp)
 {
 	int r;
 
-	r = filter_property(conf, pp->udev);
+	r = filter_property(conf, pp->udev, 3);
 	if (r > 0)
 		return r;
 	r = filter_devnode(conf->blist_devnode, conf->elist_devnode, pp->dev);
@@ -384,7 +384,7 @@ filter_path (struct config * conf, struct path * pp)
 }
 
 int
-filter_property(struct config * conf, struct udev_device * udev)
+filter_property(struct config *conf, struct udev_device *udev, int lvl)
 {
 	const char *devname = udev_device_get_sysname(udev);
 	struct udev_list_entry *list_entry;
@@ -415,7 +415,7 @@ filter_property(struct config * conf, struct udev_device * udev)
 		}
 	}
 
-	log_filter(devname, NULL, NULL, NULL, env, NULL, r);
+	log_filter(devname, NULL, NULL, NULL, env, NULL, r, lvl);
 	return r;
 }
 
diff --git a/libmultipath/blacklist.h b/libmultipath/blacklist.h
index 18903b6b..4c8ec99e 100644
--- a/libmultipath/blacklist.h
+++ b/libmultipath/blacklist.h
@@ -37,7 +37,7 @@ int filter_devnode (vector, vector, char *);
 int filter_wwid (vector, vector, char *, char *);
 int filter_device (vector, vector, char *, char *, char *);
 int filter_path (struct config *, struct path *);
-int filter_property(struct config *, struct udev_device *);
+int filter_property(struct config *, struct udev_device *, int);
 int filter_protocol(vector, vector, struct path *);
 int store_ble (vector, char *, int);
 int set_ble_device (vector, char *, char *, int);
diff --git a/libmultipath/configure.c b/libmultipath/configure.c
index ed3e30f5..406cd4c9 100644
--- a/libmultipath/configure.c
+++ b/libmultipath/configure.c
@@ -1289,7 +1289,7 @@ int get_refwwid(enum mpath_cmds cmd, char *dev, enum devtypes dev_type,
 		conf = get_multipath_config();
 		pthread_cleanup_push(put_multipath_config, conf);
 		if (pp->udev && pp->uid_attribute &&
-		    filter_property(conf, pp->udev) > 0)
+		    filter_property(conf, pp->udev, 3) > 0)
 			invalid = 1;
 		pthread_cleanup_pop(1);
 		if (invalid)
@@ -1329,7 +1329,7 @@ int get_refwwid(enum mpath_cmds cmd, char *dev, enum devtypes dev_type,
 		conf = get_multipath_config();
 		pthread_cleanup_push(put_multipath_config, conf);
 		if (pp->udev && pp->uid_attribute &&
-		    filter_property(conf, pp->udev) > 0)
+		    filter_property(conf, pp->udev, 3) > 0)
 			invalid = 1;
 		pthread_cleanup_pop(1);
 		if (invalid)
@@ -1358,7 +1358,7 @@ int get_refwwid(enum mpath_cmds cmd, char *dev, enum devtypes dev_type,
 		conf = get_multipath_config();
 		pthread_cleanup_push(put_multipath_config, conf);
 		if (pp->udev && pp->uid_attribute &&
-		    filter_property(conf, pp->udev) > 0)
+		    filter_property(conf, pp->udev, 3) > 0)
 			invalid = 1;
 		pthread_cleanup_pop(1);
 		if (invalid)
diff --git a/libmultipath/discovery.c b/libmultipath/discovery.c
index 3ad33492..1c87277f 100644
--- a/libmultipath/discovery.c
+++ b/libmultipath/discovery.c
@@ -1869,7 +1869,7 @@ int pathinfo(struct path *pp, struct config *conf, int mask)
 			return PATHINFO_SKIPPED;
 		}
 		if (is_claimed_by_foreign(pp->udev) ||
-			 filter_property(conf, pp->udev) > 0)
+		    filter_property(conf, pp->udev, 4) > 0)
 			return PATHINFO_SKIPPED;
 	}
 
diff --git a/tests/blacklist.c b/tests/blacklist.c
index a55c1c07..54d568f5 100644
--- a/tests/blacklist.c
+++ b/tests/blacklist.c
@@ -267,7 +267,8 @@ static void test_property_blacklist(void **state)
 	static struct udev_device udev = { "sdb", { "ID_FOO", "ID_WWN", "ID_BAR", NULL } };
 	conf.blist_property = blist_property_wwn;
 	expect_condlog(3, "sdb: udev property ID_WWN blacklisted\n");
-	assert_int_equal(filter_property(&conf, &udev), MATCH_PROPERTY_BLIST);
+	assert_int_equal(filter_property(&conf, &udev, 3),
+			 MATCH_PROPERTY_BLIST);
 }
 
 /* the property check works different in that you check all the property
@@ -280,7 +281,7 @@ static void test_property_whitelist(void **state)
 	static struct udev_device udev = { "sdb", { "ID_FOO", "ID_WWN", "ID_BAR", NULL } };
 	conf.elist_property = blist_property_wwn;
 	expect_condlog(3, "sdb: udev property ID_WWN whitelisted\n");
-	assert_int_equal(filter_property(&conf, &udev),
+	assert_int_equal(filter_property(&conf, &udev, 3),
 			 MATCH_PROPERTY_BLIST_EXCEPT);
 }
 
@@ -289,7 +290,7 @@ static void test_property_missing(void **state)
 	static struct udev_device udev = { "sdb", { "ID_FOO", "ID_BAZ", "ID_BAR", NULL } };
 	conf.blist_property = blist_property_wwn;
 	expect_condlog(3, "sdb: blacklisted, udev property missing\n");
-	assert_int_equal(filter_property(&conf, &udev),
+	assert_int_equal(filter_property(&conf, &udev, 3),
 			 MATCH_PROPERTY_BLIST_MISSING);
 }
 
-- 
2.19.1

[PATCH 07/19] libmultipath: decrease log level of "disassembled" messages

[Martin Wilck]

These messages are printed from update_multipath_strings, and
thus from check_path(), which is too much for -v3.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/dmparser.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/libmultipath/dmparser.c b/libmultipath/dmparser.c
index 620f507d..ac13ec06 100644
--- a/libmultipath/dmparser.c
+++ b/libmultipath/dmparser.c
@@ -117,7 +117,7 @@ assemble_map (struct multipath * mp, char * params, int len)
 	}
 
 	FREE(f);
-	condlog(3, "%s: assembled map [%s]", mp->alias, params);
+	condlog(4, "%s: assembled map [%s]", mp->alias, params);
 	return 0;
 
 err:
@@ -145,7 +145,7 @@ int disassemble_map(vector pathvec, char *params, struct multipath *mpp,
 
 	p = params;
 
-	condlog(3, "%s: disassemble map [%s]", mpp->alias, params);
+	condlog(4, "%s: disassemble map [%s]", mpp->alias, params);
 
 	/*
 	 * features
@@ -410,7 +410,7 @@ int disassemble_status(char *params, struct multipath *mpp)
 
 	p = params;
 
-	condlog(3, "%s: disassemble status [%s]", mpp->alias, params);
+	condlog(4, "%s: disassemble status [%s]", mpp->alias, params);
 
 	/*
 	 * features
-- 
2.19.1

[PATCH 08/19] libmultipath: decrease log level of word splitting

[Martin Wilck]

This will make log level 4 actually usable.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/util.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/libmultipath/util.c b/libmultipath/util.c
index 66c47611..b5d2e706 100644
--- a/libmultipath/util.c
+++ b/libmultipath/util.c
@@ -104,7 +104,7 @@ get_word (char * sentence, char ** word)
 	}
 	strncpy(*word, sentence, len);
 	strchop(*word);
-	condlog(4, "*word = %s, len = %i", *word, len);
+	condlog(5, "*word = %s, len = %i", *word, len);
 
 	if (*p == '\0')
 		return 0;
-- 
2.19.1

Re: [PATCH 08/19] libmultipath: decrease log level of word splitting

[Benjamin Marzinski]

On Wed, Nov 21, 2018 at 11:18:28AM +0100, Martin Wilck wrote:
> This will make log level 4 actually usable.

condlog doesn't actually handle verbosity levels gerater than 4
correctly when logging to syslog (there is no loglevel 8).  I didn't
even realize that there were any condlog(5, ...) calls.  I am all for
using them to make log level 4 usable, but we should cap prio at 7 in
log_safe(), to make syslog happy (not that syslog is used much
anymore).

Otherwise, I'm fine with this

-Ben
 
> Signed-off-by: Martin Wilck <mwilck@suse.com>
> ---
>  libmultipath/util.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/libmultipath/util.c b/libmultipath/util.c
> index 66c47611..b5d2e706 100644
> --- a/libmultipath/util.c
> +++ b/libmultipath/util.c
> @@ -104,7 +104,7 @@ get_word (char * sentence, char ** word)
>  	}
>  	strncpy(*word, sentence, len);
>  	strchop(*word);
> -	condlog(4, "*word = %s, len = %i", *word, len);
> +	condlog(5, "*word = %s, len = %i", *word, len);
>  
>  	if (*p == '\0')
>  		return 0;
> -- 
> 2.19.1

Re: [PATCH 08/19] libmultipath: decrease log level of word splitting

[Benjamin Marzinski]

On Wed, Nov 21, 2018 at 11:18:28AM +0100, Martin Wilck wrote:
> This will make log level 4 actually usable.

in light of
[PATCH v2 20/24] libmultipath: avoid syslog loglevel > LOG_DEBUG

Reviewed-by: Benjamin Marzinski <bmarzins@redhat.com>

> 
> Signed-off-by: Martin Wilck <mwilck@suse.com>
> ---
>  libmultipath/util.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/libmultipath/util.c b/libmultipath/util.c
> index 66c47611..b5d2e706 100644
> --- a/libmultipath/util.c
> +++ b/libmultipath/util.c
> @@ -104,7 +104,7 @@ get_word (char * sentence, char ** word)
>  	}
>  	strncpy(*word, sentence, len);
>  	strchop(*word);
> -	condlog(4, "*word = %s, len = %i", *word, len);
> +	condlog(5, "*word = %s, len = %i", *word, len);
>  
>  	if (*p == '\0')
>  		return 0;
> -- 
> 2.19.1

[PATCH 09/19] libmultipath: increase log level of map removal

[Martin Wilck]

This is an important event which we want to see with -v3.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/structs_vec.c | 6 +++---
 multipathd/main.c          | 1 +
 2 files changed, 4 insertions(+), 3 deletions(-)

diff --git a/libmultipath/structs_vec.c b/libmultipath/structs_vec.c
index c85823a0..561ff4ac 100644
--- a/libmultipath/structs_vec.c
+++ b/libmultipath/structs_vec.c
@@ -113,8 +113,6 @@ remove_map(struct multipath * mpp, struct vectors * vecs, int purge_vec)
 {
 	int i;
 
-	condlog(4, "%s: remove multipath map", mpp->alias);
-
 	/*
 	 * clear references to this map
 	 */
@@ -134,8 +132,10 @@ void
 remove_map_by_alias(const char *alias, struct vectors * vecs, int purge_vec)
 {
 	struct multipath * mpp = find_mp_by_alias(vecs->mpvec, alias);
-	if (mpp)
+	if (mpp) {
+		condlog(2, "%s: removing map by alias", alias);
 		remove_map(mpp, vecs, purge_vec);
+	}
 }
 
 void
diff --git a/multipathd/main.c b/multipathd/main.c
index 88ae4903..b961de53 100644
--- a/multipathd/main.c
+++ b/multipathd/main.c
@@ -334,6 +334,7 @@ remove_map_and_stop_waiter(struct multipath *mpp, struct vectors *vecs)
 {
 	/* devices are automatically removed by the dmevent polling code,
 	 * so they don't need to be manually removed here */
+	condlog(3, "%s: removing map from internal tables", mpp->alias);
 	if (!poll_dmevents)
 		stop_waiter_thread(mpp, vecs);
 	remove_map(mpp, vecs, PURGE_VEC);
-- 
2.19.1

[PATCH 10/19] multipathd: decrease log level of checker timing

[Martin Wilck]

These messages, printed for every checker invocation, were helpful
in the past but they don't make much sense under normal operations.
The same information can be derived from journal time stamps on
recent Linux distributions.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 multipathd/main.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/multipathd/main.c b/multipathd/main.c
index b961de53..79c8ed1e 100644
--- a/multipathd/main.c
+++ b/multipathd/main.c
@@ -2267,7 +2267,7 @@ checkerloop (void *ap)
 			if (num_paths) {
 				unsigned int max_checkint;
 
-				condlog(3, "checked %d path%s in %lu.%06lu secs",
+				condlog(4, "checked %d path%s in %lu.%06lu secs",
 					num_paths, num_paths > 1 ? "s" : "",
 					diff_time.tv_sec,
 					diff_time.tv_nsec / 1000);
-- 
2.19.1

[PATCH 11/19] libmultipath: decrease log level of "prioritizer refcount" message

[Martin Wilck]

This was important during development of the refcounting code, but
now it isn't any more.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/prio.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/libmultipath/prio.c b/libmultipath/prio.c
index 17acfd05..0590218d 100644
--- a/libmultipath/prio.c
+++ b/libmultipath/prio.c
@@ -42,7 +42,7 @@ void free_prio (struct prio * p)
 		return;
 	p->refcount--;
 	if (p->refcount) {
-		condlog(3, "%s prioritizer refcount %d",
+		condlog(4, "%s prioritizer refcount %d",
 			p->name, p->refcount);
 		return;
 	}
-- 
2.19.1

[PATCH 12/19] libmpathpersist/update_map_pr: decrease log level for nop

[Martin Wilck]

No need to log at -v3 if nothing to do.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmpathpersist/mpath_persist.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/libmpathpersist/mpath_persist.c b/libmpathpersist/mpath_persist.c
index 2ffe56ea..0b9c7149 100644
--- a/libmpathpersist/mpath_persist.c
+++ b/libmpathpersist/mpath_persist.c
@@ -889,7 +889,8 @@ int update_map_pr(struct multipath *mpp)
 	if (!get_be64(mpp->reservation_key))
 	{
 		/* Nothing to do. Assuming pr mgmt feature is disabled*/
-		condlog(3, "%s: reservation_key not set in multipath.conf", mpp->alias);
+		condlog(4, "%s: reservation_key not set in multipath.conf",
+			mpp->alias);
 		return MPATH_PR_SUCCESS;
 	}
 
-- 
2.19.1

[PATCH 13/19] libmultipath: simplify devt2devname()

[Martin Wilck]

Since 1e79548, we don't fallback from /sys/dev/block to
/proc/partitions anyway. The strncmp() at "skip_proc"
is doomed to fail. So we might as well return immediately.

Also, decrease the log level; whether this failure is
noteworthy is rather up to the callers to decide.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/util.c | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

diff --git a/libmultipath/util.c b/libmultipath/util.c
index b5d2e706..28eb7577 100644
--- a/libmultipath/util.c
+++ b/libmultipath/util.c
@@ -191,7 +191,8 @@ int devt2devname(char *devname, int devname_len, char *devt)
 				return 0;
 			}
 		}
-		goto skip_proc;
+		condlog(4, "%s is invalid", block_path);
+		return 1;
 	}
 	memset(block_path, 0, sizeof(block_path));
 
@@ -220,7 +221,7 @@ int devt2devname(char *devname, int devname_len, char *devt)
 		}
 	}
 	fclose(fd);
-skip_proc:
+
 	if (strncmp(block_path,"/sys/block", 10)) {
 		condlog(3, "No device found for %u:%u", major, minor);
 		return 1;
-- 
2.19.1

[PATCH 14/19] libmultipath: decrease log level for failed VPD c9

[Martin Wilck]

It's normal that SCSI devices don't support this page. Only RDAC
devices need it.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/discovery.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/libmultipath/discovery.c b/libmultipath/discovery.c
index 1c87277f..7f983a63 100644
--- a/libmultipath/discovery.c
+++ b/libmultipath/discovery.c
@@ -1106,7 +1106,9 @@ get_vpd_sgio (int fd, int pg, char * str, int maxlen)
 
 	memset(buff, 0x0, 4096);
 	if (sgio_get_vpd(buff, 4096, fd, pg) < 0) {
-		condlog(3, "failed to issue vpd inquiry for pg%02x",
+		int lvl = pg == 0x80 || pg == 0x83 ? 3 : 4;
+
+		condlog(lvl, "failed to issue vpd inquiry for pg%02x",
 			pg);
 		return -errno;
 	}
-- 
2.19.1

[PATCH 15/19] libmultipath: adopt_paths: check for size match

[Martin Wilck]

In coalesce_paths() and ev_add_path(), we check for size mismatch.
We should do it here, too.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/structs_vec.c | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/libmultipath/structs_vec.c b/libmultipath/structs_vec.c
index 561ff4ac..a0b69ce5 100644
--- a/libmultipath/structs_vec.c
+++ b/libmultipath/structs_vec.c
@@ -60,6 +60,12 @@ int adopt_paths(vector pathvec, struct multipath *mpp)
 
 	vector_foreach_slot (pathvec, pp, i) {
 		if (!strncmp(mpp->wwid, pp->wwid, WWID_SIZE)) {
+			if (pp->size != 0 && mpp->size != 0 &&
+			    pp->size != mpp->size) {
+				condlog(3, "%s: size mismatch for %s, not adding path",
+					pp->dev, mpp->alias);
+				continue;
+			}
 			condlog(3, "%s: ownership set to %s",
 				pp->dev, mpp->alias);
 			pp->mpp = mpp;
-- 
2.19.1

[PATCH 16/19] libmultipath: coalesce_paths: fix size mismatch handling

[Martin Wilck]

When there are paths with the same WWID but different sizes, and
coalesce_paths() walks the pathvec, it checks paths _after_
the current one for size mismatch and sets ACT_REJECT. However,
these paths will be reached in the main loop later, and this time
the already handled paths will not be checked for size mismatch;
thus a map could be created, possibly even with mismatching
devices.

Fix that by tracking which paths were already discarded, and
skipping them in the main loop later.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/configure.c | 33 +++++++++++++++++++++++++--------
 libmultipath/util.h      | 16 ++++++++++++++++
 2 files changed, 41 insertions(+), 8 deletions(-)

diff --git a/libmultipath/configure.c b/libmultipath/configure.c
index 406cd4c9..4ed3cc23 100644
--- a/libmultipath/configure.c
+++ b/libmultipath/configure.c
@@ -1009,6 +1009,7 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
 	vector pathvec = vecs->pathvec;
 	struct config *conf;
 	int allow_queueing;
+	uint64_t *size_mismatch_seen;
 
 	/* ignore refwwid if it's empty */
 	if (refwwid && !strlen(refwwid))
@@ -1019,6 +1020,14 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
 			pp1->mpp = NULL;
 		}
 	}
+
+	if (VECTOR_SIZE(pathvec) == 0)
+		return 0;
+	size_mismatch_seen = calloc((VECTOR_SIZE(pathvec) - 1) / 64 + 1,
+				    sizeof(uint64_t));
+	if (size_mismatch_seen == NULL)
+		return 1;
+
 	vector_foreach_slot (pathvec, pp1, k) {
 		int invalid;
 		/* skip this path for some reason */
@@ -1038,8 +1047,8 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
 			continue;
 		}
 
-		/* 2. if path already coalesced */
-		if (pp1->mpp)
+		/* 2. if path already coalesced, or seen and discarded */
+		if (pp1->mpp || is_bit_set_in_array(k, size_mismatch_seen))
 			continue;
 
 		/* 3. if path has disappeared */
@@ -1088,9 +1097,10 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
 				 * ouch, avoid feeding that to the DM
 				 */
 				condlog(0, "%s: size %llu, expected %llu. "
-					"Discard", pp2->dev_t, pp2->size,
+					"Discard", pp2->dev, pp2->size,
 					mpp->size);
 				mpp->action = ACT_REJECT;
+				set_bit_in_array(i, size_mismatch_seen);
 			}
 		}
 		verify_paths(mpp, vecs);
@@ -1119,8 +1129,10 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
 					"ignoring" : "removing");
 				remove_map(mpp, vecs, 0);
 				continue;
-			} else /* if (r == DOMAP_RETRY) */
-				return r;
+			} else /* if (r == DOMAP_RETRY) */ {
+				r = 1;
+				goto out;
+			}
 		}
 		if (r == DOMAP_DRY)
 			continue;
@@ -1161,8 +1173,10 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
 
 		if (newmp) {
 			if (mpp->action != ACT_REJECT) {
-				if (!vector_alloc_slot(newmp))
-					return 1;
+				if (!vector_alloc_slot(newmp)) {
+					r = 1;
+					goto out;
+				}
 				vector_set_slot(newmp, mpp);
 			}
 			else
@@ -1193,7 +1207,10 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
 				condlog(2, "%s: remove (dead)", alias);
 		}
 	}
-	return 0;
+	r = 0;
+out:
+	free(size_mismatch_seen);
+	return r;
 }
 
 struct udev_device *get_udev_device(const char *dev, enum devtypes dev_type)
diff --git a/libmultipath/util.h b/libmultipath/util.h
index a818e29a..1f13c913 100644
--- a/libmultipath/util.h
+++ b/libmultipath/util.h
@@ -3,6 +3,7 @@
 
 #include <sys/types.h>
 #include <inttypes.h>
+#include <stdbool.h>
 
 size_t strchop(char *);
 int basenamecpy (const char *src, char *dst, size_t size);
@@ -39,4 +40,19 @@ struct scandir_result {
 };
 void free_scandir_result(struct scandir_result *);
 
+static inline bool is_bit_set_in_array(unsigned int bit, const uint64_t *arr)
+{
+	return arr[bit / 64] & (1ULL << (bit % 64)) ? 1 : 0;
+}
+
+static inline void set_bit_in_array(unsigned int bit, uint64_t *arr)
+{
+	arr[bit / 64] |= (1ULL << (bit % 64));
+}
+
+static inline void clear_bit_in_array(unsigned int bit, uint64_t *arr)
+{
+	arr[bit / 64] &= ~(1ULL << (bit % 64));
+}
+
 #endif /* _UTIL_H */
-- 
2.19.1

Re: [PATCH 16/19] libmultipath: coalesce_paths: fix size mismatch handling

[Benjamin Marzinski]

On Wed, Nov 21, 2018 at 11:18:36AM +0100, Martin Wilck wrote:
> When there are paths with the same WWID but different sizes, and
> coalesce_paths() walks the pathvec, it checks paths _after_
> the current one for size mismatch and sets ACT_REJECT. However,
> these paths will be reached in the main loop later, and this time
> the already handled paths will not be checked for size mismatch;
> thus a map could be created, possibly even with mismatching
> devices.
> 
> Fix that by tracking which paths were already discarded, and
> skipping them in the main loop later.

Previously, multipath would retry if coalesce_paths returned
DOMAP_RETRY. With this patch, DOMAP_RETRY isn't returned, so that no
longer happens. Is this intentional?

Also, I would prefer if coalesce_paths always used named constants for
the return values, instead of converting them to numbers.

-Ben
 
> Signed-off-by: Martin Wilck <mwilck@suse.com>
> ---
>  libmultipath/configure.c | 33 +++++++++++++++++++++++++--------
>  libmultipath/util.h      | 16 ++++++++++++++++
>  2 files changed, 41 insertions(+), 8 deletions(-)
> 
> diff --git a/libmultipath/configure.c b/libmultipath/configure.c
> index 406cd4c9..4ed3cc23 100644
> --- a/libmultipath/configure.c
> +++ b/libmultipath/configure.c
> @@ -1009,6 +1009,7 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
>  	vector pathvec = vecs->pathvec;
>  	struct config *conf;
>  	int allow_queueing;
> +	uint64_t *size_mismatch_seen;
>  
>  	/* ignore refwwid if it's empty */
>  	if (refwwid && !strlen(refwwid))
> @@ -1019,6 +1020,14 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
>  			pp1->mpp = NULL;
>  		}
>  	}
> +
> +	if (VECTOR_SIZE(pathvec) == 0)
> +		return 0;
> +	size_mismatch_seen = calloc((VECTOR_SIZE(pathvec) - 1) / 64 + 1,
> +				    sizeof(uint64_t));
> +	if (size_mismatch_seen == NULL)
> +		return 1;
> +
>  	vector_foreach_slot (pathvec, pp1, k) {
>  		int invalid;
>  		/* skip this path for some reason */
> @@ -1038,8 +1047,8 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
>  			continue;
>  		}
>  
> -		/* 2. if path already coalesced */
> -		if (pp1->mpp)
> +		/* 2. if path already coalesced, or seen and discarded */
> +		if (pp1->mpp || is_bit_set_in_array(k, size_mismatch_seen))
>  			continue;
>  
>  		/* 3. if path has disappeared */
> @@ -1088,9 +1097,10 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
>  				 * ouch, avoid feeding that to the DM
>  				 */
>  				condlog(0, "%s: size %llu, expected %llu. "
> -					"Discard", pp2->dev_t, pp2->size,
> +					"Discard", pp2->dev, pp2->size,
>  					mpp->size);
>  				mpp->action = ACT_REJECT;
> +				set_bit_in_array(i, size_mismatch_seen);
>  			}
>  		}
>  		verify_paths(mpp, vecs);
> @@ -1119,8 +1129,10 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
>  					"ignoring" : "removing");
>  				remove_map(mpp, vecs, 0);
>  				continue;
> -			} else /* if (r == DOMAP_RETRY) */
> -				return r;
> +			} else /* if (r == DOMAP_RETRY) */ {
> +				r = 1;
> +				goto out;
> +			}
>  		}
>  		if (r == DOMAP_DRY)
>  			continue;
> @@ -1161,8 +1173,10 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
>  
>  		if (newmp) {
>  			if (mpp->action != ACT_REJECT) {
> -				if (!vector_alloc_slot(newmp))
> -					return 1;
> +				if (!vector_alloc_slot(newmp)) {
> +					r = 1;
> +					goto out;
> +				}
>  				vector_set_slot(newmp, mpp);
>  			}
>  			else
> @@ -1193,7 +1207,10 @@ int coalesce_paths (struct vectors * vecs, vector newmp, char * refwwid,
>  				condlog(2, "%s: remove (dead)", alias);
>  		}
>  	}
> -	return 0;
> +	r = 0;
> +out:
> +	free(size_mismatch_seen);
> +	return r;
>  }
>  
>  struct udev_device *get_udev_device(const char *dev, enum devtypes dev_type)
> diff --git a/libmultipath/util.h b/libmultipath/util.h
> index a818e29a..1f13c913 100644
> --- a/libmultipath/util.h
> +++ b/libmultipath/util.h
> @@ -3,6 +3,7 @@
>  
>  #include <sys/types.h>
>  #include <inttypes.h>
> +#include <stdbool.h>
>  
>  size_t strchop(char *);
>  int basenamecpy (const char *src, char *dst, size_t size);
> @@ -39,4 +40,19 @@ struct scandir_result {
>  };
>  void free_scandir_result(struct scandir_result *);
>  
> +static inline bool is_bit_set_in_array(unsigned int bit, const uint64_t *arr)
> +{
> +	return arr[bit / 64] & (1ULL << (bit % 64)) ? 1 : 0;
> +}
> +
> +static inline void set_bit_in_array(unsigned int bit, uint64_t *arr)
> +{
> +	arr[bit / 64] |= (1ULL << (bit % 64));
> +}
> +
> +static inline void clear_bit_in_array(unsigned int bit, uint64_t *arr)
> +{
> +	arr[bit / 64] &= ~(1ULL << (bit % 64));
> +}
> +
>  #endif /* _UTIL_H */
> -- 
> 2.19.1

Re: [PATCH 16/19] libmultipath: coalesce_paths: fix size mismatch handling

[Martin Wilck]

On Thu, 2018-11-29 at 14:53 -0600,  Benjamin Marzinski  wrote:
> On Wed, Nov 21, 2018 at 11:18:36AM +0100, Martin Wilck wrote:
> > When there are paths with the same WWID but different sizes, and
> > coalesce_paths() walks the pathvec, it checks paths _after_
> > the current one for size mismatch and sets ACT_REJECT. However,
> > these paths will be reached in the main loop later, and this time
> > the already handled paths will not be checked for size mismatch;
> > thus a map could be created, possibly even with mismatching
> > devices.
> > 
> > Fix that by tracking which paths were already discarded, and
> > skipping them in the main loop later.
> 
> Previously, multipath would retry if coalesce_paths returned
> DOMAP_RETRY. With this patch, DOMAP_RETRY isn't returned, so that no
> longer happens. Is this intentional?

No, it was an oversight. Thanks for spotting it. Note: it's only
relevant for the case where lock_multipath() fails, which should hardly
ever happen any more since we are using shared locks (5ec07b3).
Whether we still need lock_multipath() is an open question. I
personally think we don't.

> 
> Also, I would prefer if coalesce_paths always used named constants
> for
> the return values, instead of converting them to numbers.

OK, I'll send an extra patch for that.

Martin

-- 
Dr. Martin Wilck <mwilck@suse.com>, Tel. +49 (0)911 74053 2107
SUSE Linux GmbH, GF: Felix Imendörffer, Jane Smithard, Graham Norton
HRB 21284 (AG Nürnberg)


--
dm-devel mailing list
dm-devel@redhat.com
https://www.redhat.com/mailman/listinfo/dm-devel

[PATCH 17/19] tests: add unit tests for bitmask functions

[Martin Wilck]

Add unit tests for the bitmask management functions the previous
patch added in util.h.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 tests/util.c | 98 ++++++++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 98 insertions(+)

diff --git a/tests/util.c b/tests/util.c
index 839effd2..e6d4b9ab 100644
--- a/tests/util.c
+++ b/tests/util.c
@@ -26,6 +26,8 @@
 
 #include "globals.c"
 
+#define BITARR_SZ 4
+
 static void test_basenamecpy_good0(void **state)
 {
 	char dst[10];
@@ -139,6 +141,100 @@ static void test_basenamecpy_bad5(void **state)
         assert_int_equal(basenamecpy("baz/qux", NULL, sizeof(dst)), 0);
 }
 
+static void test_bitmask_1(void **state)
+{
+	uint64_t arr[BITARR_SZ];
+	int i, j, k, m, b;
+
+	memset(arr, 0, sizeof(arr));
+
+	for (j = 0; j < BITARR_SZ; j++) {
+		for (i = 0; i < 64; i++) {
+			b = 64 * j + i;
+			assert(!is_bit_set_in_array(b, arr));
+			set_bit_in_array(b, arr);
+			for (k = 0; k < BITARR_SZ; k++) {
+				printf("b = %d j = %d k = %d a = %"PRIx64"\n",
+				       b, j, k, arr[k]);
+				if (k == j)
+					assert_int_equal(arr[j], 1ULL << i);
+				else
+					assert_int_equal(arr[k], 0ULL);
+			}
+			for (m = 0; m < 64; m++)
+				if (i == m)
+					assert(is_bit_set_in_array(64 * j + m,
+								   arr));
+				else
+					assert(!is_bit_set_in_array(64 * j + m,
+								    arr));
+			clear_bit_in_array(b, arr);
+			assert(!is_bit_set_in_array(b, arr));
+			for (k = 0; k < BITARR_SZ; k++)
+				assert_int_equal(arr[k], 0ULL);
+		}
+	}
+}
+
+static void test_bitmask_2(void **state)
+{
+	uint64_t arr[BITARR_SZ];
+	int i, j, k, m, b;
+
+	memset(arr, 0, sizeof(arr));
+
+	for (j = 0; j < BITARR_SZ; j++) {
+		for (i = 0; i < 64; i++) {
+			b = 64 * j + i;
+			assert(!is_bit_set_in_array(b, arr));
+			set_bit_in_array(b, arr);
+			for (m = 0; m < 64; m++)
+				if (m <= i)
+					assert(is_bit_set_in_array(64 * j + m,
+								   arr));
+				else
+					assert(!is_bit_set_in_array(64 * j + m,
+								    arr));
+			assert(is_bit_set_in_array(b, arr));
+			for (k = 0; k < BITARR_SZ; k++) {
+				if (k < j || (k == j && i == 63))
+					assert_int_equal(arr[k], ~0ULL);
+				else if (k > j)
+					assert_int_equal(arr[k], 0ULL);
+				else
+					assert_int_equal(
+						arr[k],
+						(1ULL << (i + 1)) - 1);
+			}
+		}
+	}
+	for (j = 0; j < BITARR_SZ; j++) {
+		for (i = 0; i < 64; i++) {
+			b = 64 * j + i;
+			assert(is_bit_set_in_array(b, arr));
+			clear_bit_in_array(b, arr);
+			for (m = 0; m < 64; m++)
+				if (m <= i)
+					assert(!is_bit_set_in_array(64 * j + m,
+								    arr));
+				else
+					assert(is_bit_set_in_array(64 * j + m,
+								   arr));
+			assert(!is_bit_set_in_array(b, arr));
+			for (k = 0; k < BITARR_SZ; k++) {
+				if (k < j || (k == j && i == 63))
+					assert_int_equal(arr[k], 0ULL);
+				else if (k > j)
+					assert_int_equal(arr[k], ~0ULL);
+				else
+					assert_int_equal(
+						arr[k],
+						~((1ULL << (i + 1)) - 1));
+			}
+		}
+	}
+}
+
 int test_basenamecpy(void)
 {
 	const struct CMUnitTest tests[] = {
@@ -156,6 +252,8 @@ int test_basenamecpy(void)
 		cmocka_unit_test(test_basenamecpy_bad3),
 		cmocka_unit_test(test_basenamecpy_bad4),
 		cmocka_unit_test(test_basenamecpy_bad5),
+		cmocka_unit_test(test_bitmask_1),
+		cmocka_unit_test(test_bitmask_2),
 	};
 	return cmocka_run_group_tests(tests, NULL, NULL);
 }
-- 
2.19.1

[PATCH 18/19] multipathd: uev_remove_path: remove redundant orphan_paths call

[Martin Wilck]

The remove_map_and_stop_waiter() call which follows immediately
will do the same thing.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 multipathd/main.c | 1 -
 1 file changed, 1 deletion(-)

diff --git a/multipathd/main.c b/multipathd/main.c
index 79c8ed1e..0c248046 100644
--- a/multipathd/main.c
+++ b/multipathd/main.c
@@ -787,7 +787,6 @@ uev_remove_map (struct uevent * uev, struct vectors * vecs)
 		goto out;
 	}
 
-	orphan_paths(vecs->pathvec, mpp);
 	remove_map_and_stop_waiter(mpp, vecs);
 out:
 	lock_cleanup_pop(vecs->lock);
-- 
2.19.1

[PATCH 19/19] libmultipath: improve logging from orphan_paths

[Martin Wilck]

It's a big difference if a map is flushed from DM (changing kernel
state) or just removed from internal multipathd tables. Convey
this information in log messages.

Signed-off-by: Martin Wilck <mwilck@suse.com>
---
 libmultipath/structs_vec.c | 6 +++---
 libmultipath/structs_vec.h | 3 ++-
 multipathd/main.c          | 2 +-
 3 files changed, 6 insertions(+), 5 deletions(-)

diff --git a/libmultipath/structs_vec.c b/libmultipath/structs_vec.c
index a0b69ce5..4667e34f 100644
--- a/libmultipath/structs_vec.c
+++ b/libmultipath/structs_vec.c
@@ -102,14 +102,14 @@ void orphan_path(struct path *pp, const char *reason)
 	pp->fd = -1;
 }
 
-void orphan_paths(vector pathvec, struct multipath *mpp)
+void orphan_paths(vector pathvec, struct multipath *mpp, const char *reason)
 {
 	int i;
 	struct path * pp;
 
 	vector_foreach_slot (pathvec, pp, i) {
 		if (pp->mpp == mpp) {
-			orphan_path(pp, "map flushed");
+			orphan_path(pp, reason);
 		}
 	}
 }
@@ -122,7 +122,7 @@ remove_map(struct multipath * mpp, struct vectors * vecs, int purge_vec)
 	/*
 	 * clear references to this map
 	 */
-	orphan_paths(vecs->pathvec, mpp);
+	orphan_paths(vecs->pathvec, mpp, "map removed internally");
 
 	if (purge_vec &&
 	    (i = find_slot(vecs->mpvec, (void *)mpp)) != -1)
diff --git a/libmultipath/structs_vec.h b/libmultipath/structs_vec.h
index f7777aaf..f8b9f63e 100644
--- a/libmultipath/structs_vec.h
+++ b/libmultipath/structs_vec.h
@@ -14,7 +14,8 @@ struct vectors {
 void enter_recovery_mode(struct multipath *mpp);
 
 int adopt_paths (vector pathvec, struct multipath * mpp);
-void orphan_paths (vector pathvec, struct multipath * mpp);
+void orphan_paths(vector pathvec, struct multipath *mpp,
+		  const char *reason);
 void orphan_path (struct path * pp, const char *reason);
 
 int verify_paths(struct multipath * mpp, struct vectors * vecs);
diff --git a/multipathd/main.c b/multipathd/main.c
index 0c248046..77126f9e 100644
--- a/multipathd/main.c
+++ b/multipathd/main.c
@@ -655,7 +655,7 @@ flush_map(struct multipath * mpp, struct vectors * vecs, int nopaths)
 		condlog(2, "%s: map flushed", mpp->alias);
 	}
 
-	orphan_paths(vecs->pathvec, mpp);
+	orphan_paths(vecs->pathvec, mpp, "map flushed");
 	remove_map_and_stop_waiter(mpp, vecs);
 
 	return 0;
-- 
2.19.1

Re: [PATCH 00/19] multipath-tools: improve logging at -v3

[Benjamin Marzinski]

On Wed, Nov 21, 2018 at 11:18:20AM +0100, Martin Wilck wrote:
> Hi Christophe,
> 
> most of the patches in this series reduce log levels of frequently
> printed messages at verbosity level 3. My goal was to limit the
> output of multipathd to one line per path per checker invocation,
> which is sufficient to track multipathd's view of path health in
> the logs.
> 
> The standard setting of -v2 is not enough for post-mortem analysis of many
> failures. With this series, running multipathd with verbosity 3 becomes a
> realistic option even in production environments. So far the amount of output
> from multipathd with -v3 pretty much made this impossible, at least over
> longer time periods, and also made reading these logs very cumbersome due to
> the amount of redundant partly superfluos verbosity. I've taken care not
> to loose important information in the logs.
> 
> Apart from that, the series fixes errors in the unit tests introduced by my
> last "checker overhaul" patch series (proving that I forgot to run the
> tests before submitting :-( ), and fixes a problem that I found while testing
> handling of a bad configuration (paths with size mismatch).
> 

ACK for all patches except 8 and 16.

-Ben

> Regards,
> Martin
> 
> Martin Wilck (19):
>   tests/hwtable: set multipath_dir in local configuration
>   tests/hwtable: adjust to new checker API
>   multipath-tools: decrease verbosity of state messages
>   libmultipath: decrease verbosity of pathinfo messages
>   libmultipath: decrease verbosity of TUR checker messages
>   libmultipath: avoid frequent messages from filter_property()
>   libmultipath: decrease log level of "disassembled" messages
>   libmultipath: decrease log level of word splitting
>   libmultipath: increase log level of map removal
>   multipathd: decrease log level of checker timing
>   libmultipath: decrease log level of "prioritizer refcount" message
>   libmpathpersist/update_map_pr: decrease log level for nop
>   libmultipath: simplify devt2devname()
>   libmultipath: decrease log level for failed VPD c9
>   libmultipath: adopt_paths: check for size match
>   libmultipath: coalesce_paths: fix size mismatch handling
>   tests: add unit tests for bitmask functions
>   multipathd: uev_remove_path: remove redundant orphan_paths call
>   libmultipath: improve logging from orphan_paths
> 
>  libmpathpersist/mpath_persist.c |  3 +-
>  libmultipath/blacklist.c        | 54 +++++++++---------
>  libmultipath/blacklist.h        |  2 +-
>  libmultipath/checkers/tur.c     |  6 +-
>  libmultipath/configure.c        | 39 +++++++++----
>  libmultipath/discovery.c        | 20 ++++---
>  libmultipath/dmparser.c         |  6 +-
>  libmultipath/prio.c             |  2 +-
>  libmultipath/structs_vec.c      | 18 ++++--
>  libmultipath/structs_vec.h      |  3 +-
>  libmultipath/util.c             |  7 ++-
>  libmultipath/util.h             | 16 ++++++
>  multipathd/main.c               | 24 ++++----
>  tests/Makefile                  |  7 ++-
>  tests/blacklist.c               |  7 ++-
>  tests/hwtable.c                 | 89 ++++++++++++++++--------------
>  tests/util.c                    | 98 +++++++++++++++++++++++++++++++++
>  17 files changed, 278 insertions(+), 123 deletions(-)
> 
> -- 
> 2.19.1