mgr: improved module loading for error reporting etc #19235

jcsp · 2017-11-29T12:56:20Z

Fixes the case where commands are unfound immediately after loading module (http://tracker.ceph.com/issues/21683)
Adds helpful message when someones tries to use a command from a module that is not enabled.
Adds health checks for modules in a failed state (e.g. exceptions from serve), follows on from http://tracker.ceph.com/issues/21999
Adds can_run method to module interface to enable reporting missing dependencies (http://tracker.ceph.com/issues/21502), and expose health check if any can_run=false modules are enabled.

There is scope for some follow on work after this:

prompting user during "ceph mgr module enable" if they're enabling a can_run=false module
automatically restarting mgr (perhaps with backoff, perhaps only once) when a module fails, rather than requiring admin intervention

Happy to have feedback about some of the naming etc, I've gone back and forth about about whether the can_run bit should be called something with "dependency" in the name to make it more obvious.

tchaikov · 2017-12-01T12:06:57Z

i am still reviewing it.

tchaikov · 2017-12-04T07:34:25Z

src/messages/MMgrBeacon.h

@@ -119,18 +92,11 @@ class MMgrBeacon : public PaxosServiceMessage {
    return command_descs;
  }

-  std::set<std::string> get_available_modules() const
+  const std::vector<MgrMap::ModuleInfo> &get_available_modules() const 


nit, trailing space.

tchaikov · 2017-12-04T07:59:47Z

src/mon/MgrMap.h

+      DECODE_FINISH(p);
+    }
+
+    bool have_module(const std::string &module_name) const


nit, could use std::find() instead.

have to use a find_if because we're comparing the name member rather than the whole object, but yes.

tchaikov · 2017-12-04T08:02:20Z

src/mon/MgrMap.h

+    for (const auto &i : available_modules) {
+      old_available_modules.insert(i.name);
+    }
+


old_available_modules is not encoded.

oops, fixed.

tchaikov · 2017-12-04T08:18:16Z

src/messages/MMgrBeacon.h

-      ::decode(available_modules, p);
+      std::set<std::string> module_name_list;
+      ::decode(module_name_list, p);
+      // Only need to unpack this field if we won't have the full


we still need to read and ignore it as long as header.version >= 3. because the peer does send it to us even if header.version >= 7, as long as the compact_version < 7.

I think that's what the code is doing? The ::decode is happening under the >=3 condition, and the usage of the value is happening under the <7 condition.

sorry, i must have been reading another commit i made up in my mind. =(

tchaikov · 2017-12-04T08:26:31Z

src/mgr/ActivePyModule.h

  {}

  int load(ActivePyModules *py_modules);
  void notify(const std::string &notify_type, const std::string &notify_id);
  void notify_clog(const LogEntry &le);

+  /*


why not remove this method if it's not used anymore?

tchaikov · 2017-12-04T08:41:47Z

src/mgr/DaemonServer.cc

+            "command '" << prefix << "'): use `ceph mgr module enable "
+            << handler_name << "` to enable it";
+      dout(4) << ss.str() << dendl;
+      // FIXME: ENODEV is weird but it's not like there's an errno for


is EOPNOTSUPP a better alternative? TBH, i don't know what errno we can use here =)

I like EOPNOTSUPP, let's use that.

tchaikov · 2017-12-04T08:53:23Z

src/mgr/DaemonServer.cc

+    bool allow_failed_run = (self_test_prefix == prefix);
+
+    // Validate that the module is healthy
+    if (


nit, this is difficult to read, how about

if (module->is_loaded()) { // bypass the test for already loaded module } else if (module->get_can_run() && !module->is_failed()) { // healthy module } else if (self_test_prefix == prefix) { // run self-test method on unhealthy module } else { // ...reply with errno return; }

That block doesn't quite capture the case where we fail a command for !is_loaded(), but I agree that it was hard to read so I've refactored it slightly differently, and taken the opportunity to differentiate between the load error and the runtime error in the messages.

tchaikov · 2017-12-04T08:55:34Z

src/mgr/PyModuleRegistry.h

-  static void list_modules(std::set<std::string> *modules);
+  void list_modules(std::set<std::string> *modules);
+
+  void get_modules(std::list<PyModuleRef> *modules_out)


why not just return the list?

although not part of this PR the same question applies to the implementation of list_modules() and get_health_checks()

I've changed this now -- the pointer argument was probably just me following what was there

tchaikov · 2017-12-04T09:04:31Z

src/mon/MgrMap.h

@@ -181,8 +269,8 @@ class MgrMap
    }
    f->close_section();
    f->open_array_section("available_modules");
-    for (auto& j : available_modules) {
-      f->dump_string("module", j);
+    for (const auto& j : available_modules) {


since this method is marked const, the loop variable will be const also.

tchaikov · 2017-12-04T09:07:06Z

src/mon/MgrMap.h

@@ -234,9 +322,18 @@ class MgrMap
    m.print_summary(nullptr, &ss);
    return out << ss.str();
  }
+
+  friend ostream& operator<<(ostream& out, const std::vector<ModuleInfo>& mi) {
+    for (const auto &i : mi) {


nit, could use

std::copy(begin(mi), end(mi), ceph::make_ostream_joiner(out, ' '));

to avoid the trailing space in the output.

Because it's an array of ModuleInfo (not strings), it's kind of awkward to do something like that (iirc this method is only used in debug output)

ahh, right!

wido

Looks good!

jan--f · 2017-12-04T11:02:29Z

src/mgr/DaemonServer.cc

+    std::stringstream ss;
+
+    // Validate that the module is enabled
+    PyModuleRef module = py_modules.get_module(handler_name); 


nit: trailing ws

jan--f · 2017-12-04T11:14:20Z

src/messages/MMgrBeacon.h

@@ -87,6 +92,11 @@ class MMgrBeacon : public PaxosServiceMessage {
    return command_descs;
  }

+  const std::vector<MgrMap::ModuleInfo> &get_available_modules() const 


nit: trainling ws

jan--f · 2017-12-04T11:36:44Z

src/mgr/PyModule.cc

+    }
+  }
+  return 0;
+} 


nit: trainling ws

jan--f · 2017-12-04T11:53:34Z

src/mgr/PyModuleRegistry.cc

@@ -484,3 +251,99 @@ void PyModuleRegistry::list_modules(std::set<std::string> *modules)
  _list_modules(g_conf->get_val<std::string>("mgr_module_path"), modules);
 }

+int PyModuleRegistry::handle_command(
+  std::string const &module_name,


nit: consistent position of const keyword

jan--f · 2017-12-04T12:01:16Z

src/mgr/PyModuleRegistry.cc

+
+    for (const auto &i : modules) {
+      auto module = i.second;
+      if (module->is_enabled() && (!module->get_can_run())) {


nit: superfluous parenthesis around !module->get_can_run() and again two lines below

yeah, we could remove them.

jan--f · 2017-12-04T12:05:51Z

src/mgr/PyModuleRegistry.h

-  static void list_modules(std::set<std::string> *modules);
+  void list_modules(std::set<std::string> *modules);
+
+  void get_modules(std::list<PyModuleRef> *modules_out)


although not part of this PR the same question applies to the implementation of list_modules() and get_health_checks()

tchaikov · 2017-12-15T04:13:39Z

src/messages/MMgrBeacon.h

-      ::decode(available_modules, p);
+      std::set<std::string> module_name_list;
+      ::decode(module_name_list, p);
+      // Only need to unpack this field if we won't have the full


sorry, i must have been reading another commit i made up in my mind. =(

tchaikov · 2017-12-15T04:14:42Z

src/messages/MMgrBeacon.h

+
+    // Fill out old-style list of module names (deprecated by
+    // later field of full ModuleInfos)
+    std::vector<std::string> module_names;


nit, might need to use std::set<>. yeah, i know std::vector<> encodes just the same way as std::set<>. but better off being more consistent. what do you think?

Sure - done

tchaikov · 2017-12-15T04:18:41Z

src/mgr/DaemonServer.cc

+      accept_command = false;
+      ss << "Module '" << handler_name << "' failed to load and "
+            "cannot handle commands: " << module->get_error_string();
+    }


thanks, much better!

tchaikov · 2017-12-15T04:25:21Z

src/mgr/PyModuleRegistry.cc

+
+    for (const auto &i : modules) {
+      auto module = i.second;
+      if (module->is_enabled() && (!module->get_can_run())) {


yeah, we could remove them.

tchaikov · 2017-12-15T04:27:51Z

src/mgr/PyModuleRegistry.h

+   * Get references to all modules (whether they have loaded and/or
+   * errored) or not.
+   */
+  std::list<PyModuleRef> get_modules()


nit, could mark this method const also.

tchaikov · 2017-12-15T04:43:00Z

src/mon/MgrMap.h

+    std::set<std::string> old_available_modules;
+    for (const auto &i : available_modules) {
+      old_available_modules.insert(i.name);
+      ::encode(old_available_modules, bl);


i don't think we can encode a std::set<> this way, we would have some extra incomplete available_modules encoded here before the complete version of it.

ah, oops, this should have been outside the loop. fixed.

tchaikov · 2017-12-15T06:11:21Z

src/mon/MgrMap.h

@@ -234,9 +322,18 @@ class MgrMap
    m.print_summary(nullptr, &ss);
    return out << ss.str();
  }
+
+  friend ostream& operator<<(ostream& out, const std::vector<ModuleInfo>& mi) {
+    for (const auto &i : mi) {


ahh, right!

jcsp · 2017-12-15T16:20:07Z

OK, I think that's everything: thanks for the reviews @tchaikov @jan--f , let me know if I missed anything!

jan--f

Looks great!

jcsp · 2017-12-19T12:24:22Z

retest this please (jenkins)

(the docs build check appears to be a spurious failure downloading a dependency)

tchaikov · 2018-01-08T03:53:25Z

src/mgr/PyModule.h

+
+class PyModule
+{
+  mutable Mutex lock{"PyModule::lock"};


might need use a different name for every instance of PyModule, otherwise lockdep will be annoyed. see http://pulpito.ceph.com/kchai-2018-01-07_09:47:26-rados-wip-kefu-testing-2018-01-07-1345-distro-basic-mira/2039373/

Hmm, I'm not sure if this is because of this lock: we're getting a floating point exception in lockdep_register rather than a proper lockdep error. The backtrace looks like it's happening somewhere being called back from the python code during import (possibly construction of librados/libcephfs bits?). I'm investigating.

jcsp · 2018-01-12T11:46:22Z

Update: I'm having a hard time with this lockdep issue.

It seems that the call that's crashing is a lockdep_register call while the dashboard module is in import rados -- from tracing the execution locally (where the crash isn't happening), I see the only lock initialized there is pool-alloc-lock, a Mutex at global scope in the messenger code.

The lockdep globals should be separate for the dynamic libraries (librados) vs. the ceph-mgr binary itself, but when I put in some debug prints to print the address of a global like lockdep_mutex, the address in the librados lockdep calls is the same as from the main binary lockdep calls.

The only real change I can see here is the order of events: we are loading the python modules much earlier than we otherwise did.

Usually lockdep failures are somewhat deterministic, so it's strange that this was happening in teuthology and not during startup of a mgr when I'm running it locally. I tried to reproduce it by restarting mgr daemons in a loop (using mgr fail), and the daemons do indeed crash eventually, but without a backtrace in the log file. However, the crash is right after "Loading module dashboard", so it is probable that it's the same crash.

That intermittent failure would support the hypothesis that this is some kind of timing issue that has been exacerbated by loading modules earlier than we did before. The crash when restarting daemons in a loop is also reproducible in master.

jcsp · 2018-01-15T14:39:18Z

So, judging from this run: http://pulpito.ceph.com/jspray-2018-01-15_12:01:39-rados-wip-mgr-can-run-distro-basic-smithi/

...putting in a hack to avoid librados being imported by the dashboard module at import time makes the lockdep crashes go away. At this point I'm reasonably sure that the changes in this PR itself aren't really wrong, but there's something subtle going on with lockdep vs. dynamic libs here that I'm not getting.

tchaikov · 2018-01-23T09:09:02Z

At this point I'm reasonably sure that the changes in this PR itself aren't really wrong, but there's something subtle going on with lockdep vs. dynamic libs here that I'm not getting.

agreed.

i checked the build tested by http://pulpito.ceph.com/kchai-2018-01-07_09:47:26-rados-wip-kefu-testing-2018-01-07-1345-distro-basic-mira/2039373/, it does not contain 02a720b, that's why ceph-mgr had two copies of lockdeps table and other global locks in libceph-common dynamically linked by librados and libcommon statically linked by ceph-mgr.

in short, the issue was fixed in master =)

tchaikov · 2018-01-23T09:10:29Z

retest this please

jcsp · 2018-01-23T10:45:05Z

Woohoo!

jcsp · 2018-01-23T10:50:44Z

I had retested the failures recently (after rebase on master) here: http://pulpito.ceph.com/jspray-2018-01-18_15:07:23-rados-wip-mgr-can-run-distro-basic-smithi/ and the lockdep issue was gone, although there is now an upgrade test failing with "failed to decode message of type 1796 v1: buffer::malformed_input: void MgrMap::ModuleInfo::decode(ceph::buffer::list::iterator&) decode past end of struct encoding"

...so I need to fix that.

This is to enable us to learn more about the module before it is enabled, such as whether its can_run method return true. We can also use this to enable loading a module's commands before it is enabled, to give the user a better response when they try to use a command belong to a module that is not loaded. Signed-off-by: John Spray <john.spray@redhat.com>

...and transmit the result to the monitor in our beacon. Fixes: http://tracker.ceph.com/issues/21502 Signed-off-by: John Spray <john.spray@redhat.com>

...and for all modules, not just the active ones. This enables us to give better feedback to the user when they try and use a command from a disabled module, and also fixes the race between enabling a module and trying to use its commands. Fixes: http://tracker.ceph.com/issues/21683 Signed-off-by: John Spray <john.spray@redhat.com>

Signed-off-by: John Spray <john.spray@redhat.com>

Enable people to see can_run failures and the explanatory messages (telling them about a missing dependency) before trying to enable a module. Signed-off-by: John Spray <john.spray@redhat.com>

Signed-off-by: John Spray <john.spray@redhat.com>

list_modules is really about searching for them on disk, so it's now probe_modules and private. Both methods now return values instead of populating an argument, since when called they were always writing into a newly constructed container. Signed-off-by: John Spray <john.spray@redhat.com>

Previously only a service with debug_ms>=1 would dump corrupt messages: in an upgrade test we're *alway* interested in a corrupt message. Signed-off-by: John Spray <john.spray@redhat.com>

jcsp · 2018-01-25T11:23:23Z

Chased down that final issue, now passing: http://pulpito.ceph.com/jspray-2018-01-25_08:42:56-rados-wip-mgr-can-run-distro-basic-smithi/

jcsp added bug-fix feature mgr labels Nov 29, 2017

jcsp requested review from tchaikov, wido and jan--f November 29, 2017 12:56

tchaikov requested changes Dec 4, 2017

View reviewed changes

wido approved these changes Dec 4, 2017

View reviewed changes

jan--f reviewed Dec 4, 2017

View reviewed changes

jcsp mentioned this pull request Dec 13, 2017

mgr/Zabbix: Various fixes to Zabbix module #19452

Merged

jcsp force-pushed the wip-mgr-can-run branch 3 times, most recently from d5d5530 to 2cbb4aa Compare December 14, 2017 17:32

tchaikov reviewed Dec 15, 2017

View reviewed changes

jcsp force-pushed the wip-mgr-can-run branch 2 times, most recently from ee51ca5 to 391a9cf Compare December 15, 2017 16:19

tchaikov approved these changes Dec 15, 2017

View reviewed changes

tchaikov added the needs-qa label Dec 15, 2017

jan--f approved these changes Dec 16, 2017

View reviewed changes

jcsp force-pushed the wip-mgr-can-run branch 2 times, most recently from c4b5180 to 0f41a0d Compare December 18, 2017 14:03

tchaikov added the wip-kefu-testing label Jan 7, 2018

tchaikov requested changes Jan 8, 2018

View reviewed changes

tchaikov removed wip-kefu-testing needs-qa labels Jan 8, 2018

tchaikov assigned jcsp Jan 8, 2018

jcsp force-pushed the wip-mgr-can-run branch 2 times, most recently from f259641 to 387c981 Compare January 15, 2018 09:47

jcsp force-pushed the wip-mgr-can-run branch from 387c981 to 640ab02 Compare January 15, 2018 14:41

tchaikov self-requested a review January 16, 2018 11:39

jcsp force-pushed the wip-mgr-can-run branch 2 times, most recently from 564b783 to ef875a1 Compare January 18, 2018 13:05

jcsp mentioned this pull request Jan 19, 2018

pybind/mgr/mgr_module: make rados handle available to all modules #19972

Merged

jcsp force-pushed the wip-mgr-can-run branch from ef875a1 to d5b4d82 Compare January 22, 2018 15:46

tchaikov added the needs-qa label Jan 23, 2018

tchaikov approved these changes Jan 23, 2018

View reviewed changes

jcsp force-pushed the wip-mgr-can-run branch from dd9e664 to 9994b5f Compare January 24, 2018 14:40

John Spray added 9 commits January 24, 2018 13:08

mgr: evaluate can_run method on modules

712ad57

...and transmit the result to the monitor in our beacon. Fixes: http://tracker.ceph.com/issues/21502 Signed-off-by: John Spray <john.spray@redhat.com>

qa/mgr: add test for command execution errors

f95b079

Signed-off-by: John Spray <john.spray@redhat.com>

mgr: add health checks for failed modules

d9a4718

Signed-off-by: John Spray <john.spray@redhat.com>

mon: expose can_run flag in module ls + mgr dump

6eb5c63

Enable people to see can_run failures and the explanatory messages (telling them about a missing dependency) before trying to enable a module. Signed-off-by: John Spray <john.spray@redhat.com>

doc: note new mgr module error codes

191cce7

Signed-off-by: John Spray <john.spray@redhat.com>

qa: always dump corrupt messages in rados/upgrade

b3e6b8e

Previously only a service with debug_ms>=1 would dump corrupt messages: in an upgrade test we're *alway* interested in a corrupt message. Signed-off-by: John Spray <john.spray@redhat.com>

jcsp force-pushed the wip-mgr-can-run branch from 9994b5f to b3e6b8e Compare January 24, 2018 18:08

jcsp merged commit 474828d into ceph:master Jan 25, 2018

jcsp deleted the wip-mgr-can-run branch January 25, 2018 11:23

mgr: improved module loading for error reporting etc #19235

mgr: improved module loading for error reporting etc #19235

Conversation

jcsp commented Nov 29, 2017

tchaikov commented Dec 1, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

wido left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jcsp commented Dec 15, 2017

jan--f left a comment • edited

Choose a reason for hiding this comment

jcsp commented Dec 19, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jcsp commented Jan 12, 2018

jcsp commented Jan 15, 2018 • edited

tchaikov commented Jan 23, 2018

tchaikov commented Jan 23, 2018

jcsp commented Jan 23, 2018

jcsp commented Jan 23, 2018

jcsp commented Jan 25, 2018

jan--f left a comment •

edited

jcsp commented Jan 15, 2018 •

edited