New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

mgr: redirect python stdout,stderr to ceph log #14189

Merged
merged 6 commits into from Apr 21, 2017

Conversation

Projects
None yet
6 participants
@tchaikov
Contributor

tchaikov commented Mar 28, 2017

Signed-off-by: Kefu Chai kchai@redhat.com

@tserong

This comment has been minimized.

Contributor

tserong commented Mar 28, 2017

Good idea (this might also help with some CherryPy logging annoyance I've been looking at). I'll do some testing...

@tserong

This comment has been minimized.

Contributor

tserong commented Mar 28, 2017

OK, this works for me (the errors that weren't being logged that I mentioned in #14126 do get logged with this patch applied), and actually means we could drop the handle_pyerror() function and use PyErr_Print() in PyModules::init() instead. Also, the CherryPy logging now gets captured without any extra effort.

@@ -29,6 +29,34 @@
#define dout_context g_ceph_context
#define dout_subsys ceph_subsys_mgr
#undef dout_prefix
#define dout_prefix *_dout << "mgr [py] "

This comment has been minimized.

@tserong

tserong Mar 28, 2017

Contributor

I'd suggest this be "mgr[$module_name]" if possible, rather than "mgr [py]", so you know which module the log/error came from.

This comment has been minimized.

@tchaikov

tchaikov Mar 29, 2017

Contributor

@tserong i guess it's possible by parsing the backtrace but that'd terrify me.

@tchaikov tchaikov changed the title from mgr: redirect python stdout,stderr to a ceph log to mgr: redirect python stdout,stderr to ceph log Mar 28, 2017

@tchaikov

This comment has been minimized.

Contributor

tchaikov commented Mar 29, 2017

@tserong i removed the handle_pyerror() related changes from your PR and incorporated it into mine. i think that would form a more complete solution for debugging the ceph-mgr plugins.

@tserong

This comment has been minimized.

Contributor

tserong commented Mar 29, 2017

Thanks!

@tchaikov tchaikov added the bug fix label Mar 29, 2017

@tchaikov

This comment has been minimized.

Contributor

tchaikov commented Mar 29, 2017

@tserong i updated the my change so that only the customized "stderr" is used only when the ceph-mgr is daemonized. the format of the original error message looks better without the interleaved new lines.

@tchaikov

This comment has been minimized.

Contributor

tchaikov commented Mar 29, 2017

now the output with "-f" looks like

2017-03-29 15:32:09.473607 7f29a9180700 -1 mgr init Traceback (most recent call last):

  File "/var/ceph/ceph/src/pybind/mgr/rest/__init__.py", line 2, in <module>
    from module import *  # NOQA

  File "/var/ceph/ceph/src/pybind/mgr/rest/module.py", line 23, in <module>
    import cherrypy

ImportError: No module named cherrypy

2017-03-29 15:32:13.913007 7f29ac186700 -1 mgr ms_dispatch mgrdigest v1
2017-03-29 15:32:18.913380 7f29ac186700 -1 mgr ms_dispatch mgrdigest v1
2017-03-29 15:32:23.913688 7f29ac186700 -1 mgr ms_dispatch mgrdigest v1
Traceback (most recent call last):
  File "/var/ceph/ceph/src/pybind/mgr/fsstatus/module.py", line 267, in handle_command
2017-03-29 15:32:24.380101 7f29a897f700 -1 mgr handle_command Failed to invoke handle_command() on fsstatus
    return self.handle_osd_perf(cmd)
  File "/var/ceph/ceph/src/pybind/mgr/fsstatus/module.py", line 258, in handle_osd_perf
    raise Exception("omg")
Exception: omg

// i added a raise Exception("omg") in fsstatus/module.py locally for testing this change.

@tserong

This comment has been minimized.

Contributor

tserong commented Mar 31, 2017

Looks good to me. I've also submitted tchaikov#1

@tchaikov

This comment has been minimized.

Contributor

tchaikov commented Apr 2, 2017

retest this please.

@tchaikov tchaikov requested a review from liewegas Apr 11, 2017

@liewegas liewegas added the needs-qa label Apr 11, 2017

@liewegas

lgtm, altho that isn't worth much in this case :)

@jcsp

This comment has been minimized.

Contributor

jcsp commented Apr 12, 2017

(only just saw this one)

For the exception handling, I think it's cleaner to keep the explicit code that generates a string and sends it to the log, rather than relying on plumbing python's stderr into our log at level 0.

The problem with sending stderr to level 0 is that if you instantiate a python StreamHandler log handler, that goes to stderr by default. So any module that happens to spin one of those up by default (like a web server that thinks its logging to the console) will end up generating level 0 messages in the ceph log.

So I guess I would suggest keeping the explicit exception handler (sending its strings to dout(0)), and maybe have the python stderr handler send its strings to dout(4) or something like that, so that if someone wants to see their python module stderr they can, but we don't send it to our log level 0 by default.

@dmick

This comment has been minimized.

Member

dmick commented Apr 12, 2017

wish I'd realized this was going on before I modified everything to use handle_pyerror() :) But given the above comments, if the stuff in my dmick/wip-guilolz branch is useful, I'm happy to contribute it, particularly dmick@23cb9a7, dmick@217f3f2, and dmick@a3c3b4e

@yuriw yuriw removed the wip-yuri-testing label Apr 13, 2017

@tchaikov

This comment has been minimized.

Contributor

tchaikov commented Apr 17, 2017

@jcsp

  • keep handle_pyerror() for printing the exception when loading a plugin.
  • drop the 3rd commit which replaced the handle_pyerror() call with PyErr_Print().

could you take a look again?

@@ -27,7 +27,9 @@ class ServeThread;
class PyModules
{
protected:

This comment has been minimized.

@jcsp

jcsp Apr 18, 2017

Contributor

Why keep a reference to py_logger if we're not doing any teardown on it?

This comment has been minimized.

@tchaikov

tchaikov Apr 18, 2017

Contributor

right. will remove it.

@jcsp

jcsp approved these changes Apr 18, 2017

LGTM, I'm guessing that the py_logger member is not doing any harm because it's a global thing getting town down in finalize anyway. @dmick's changes should sit neatly on top of this and convert some of those PyErr_Print calls into explicit logging of exceptions, so that the stderr/stdout handling is just a fallback for any python code that wants to write there.

@liewegas

This comment has been minimized.

Member

liewegas commented Apr 20, 2017

rebase?

tserong and others added some commits Mar 24, 2017

mgr: log module name before PyErr_Print()
If an exception is raised in any of the python module functions
invoked by mgr (for example, ImportError if rest_framework isn't
available when serve() in called in the rest module), print the
module name along with the failed method name.

This commit also fixes what looks to me like a missed call to
PyGILState_Release() in the failure case in MgrPyModule::serve().

Signed-off-by: Tim Serong <tserong@suse.com>
mgr: redirect python stdout,stderr to ceph log
PyErr_Print() uses a file object "stderr" for printing messages.

Signed-off-by: Kefu Chai <kchai@redhat.com>
mgr/MgrPyModule.cc: get Python traceback in all CallMethod spots
Signed-off-by: Dan Mick <dan.mick@redhat.com>
mgr/PyModules handle_pyerror: don't add extra newlines to tb
Signed-off-by: Dan Mick <dan.mick@redhat.com>
mgr/MgrPyModule::handle_command: order stringstreams to match intent
ds is intended for command output (like stdout), to be shown/saved
when there's no error returned; ss is for error status (like stderr)
to further explain the error.  mgr Python tracebacks should go to
the latter.

Signed-off-by: Dan Mick <dan.mick@redhat.com>
mgr: move handle_pyerror() from MgrPyModules to MgrPyModule
so we can reuse it in a more sane way.

Signed-off-by: Kefu Chai <kchai@redhat.com>
@tchaikov

This comment has been minimized.

Contributor

tchaikov commented Apr 21, 2017

@liewegas rebased

@jcsp updated as you suggested.

@tchaikov

This comment has been minimized.

@liewegas liewegas merged commit 56bff03 into ceph:master Apr 21, 2017

3 checks passed

Signed-off-by all commits in this PR are signed
Details
Unmodifed Submodules submodules for project are unmodified
Details
default Build finished.
Details

@tchaikov tchaikov deleted the tchaikov:wip-mgr-py-stderr branch Apr 22, 2017

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment