lvm2-commits November 2016

lvm2-commits@lists.fedorahosted.org

7 participants
113 discussions

master - dmeventd: separate dm and dmeventd logging
by Zdenek Kabelac 03 Nov '16

03 Nov '16

Gitweb: http://git.fedorahosted.org/git/?p=lvm2.git;a=commitdiff;h=4b4d19e3aa1da061… Commit: 4b4d19e3aa1da061fed35edb979e1ca2a29fb7ed Parent: cd468b6218fc5c46e98ee0061010724c298c312c Author: Zdenek Kabelac <zkabelac(a)redhat.com> AuthorDate: Thu Nov 3 12:10:45 2016 +0100 Committer: Zdenek Kabelac <zkabelac(a)redhat.com> CommitterDate: Thu Nov 3 12:43:09 2016 +0100 dmeventd: separate dm and dmeventd logging Ensure different logging function for dmeventd.c logging and dm and lvm library. We can recognize we want to show every log_info() and log_notice() message from dmeventd.c code while not exposing those from libdm/libdevmapper-event Also switch to use log with errno - it's not changing anything and doesn't bring any more features yet to dmeventd logging but we just properly pass dm_errno_or_class properly through the whole code stack for possible future use (i.e. support of class logging for dmeventd). --- WHATS_NEW_DM | 1 + daemons/dmeventd/dmeventd.c | 23 +++++++++++++++++++---- daemons/dmeventd/plugins/lvm2/dmeventd_lvm.c | 2 +- 3 files changed, 21 insertions(+), 5 deletions(-) diff --git a/WHATS_NEW_DM b/WHATS_NEW_DM index 73a5171..d2d44ac 100644 --- a/WHATS_NEW_DM +++ b/WHATS_NEW_DM @@ -1,5 +1,6 @@ Version 1.02.136 - ====================================== + Make log messages from dm and lvm library differnt from dmeventd. Notice and Info messages are again logged from dmeventd and its plugins. Dmeventd now also respects DM_ABORT_ON_INTERNAL_ERRORS as libdm based tool. Report as non default dm logging also when logging with errno was changed. diff --git a/daemons/dmeventd/dmeventd.c b/daemons/dmeventd/dmeventd.c index 6024e56..58922ac 100644 --- a/daemons/dmeventd/dmeventd.c +++ b/daemons/dmeventd/dmeventd.c @@ -99,13 +99,28 @@ static time_t _idle_since = 0; static char **_initial_registrations = 0; /* FIXME Make configurable at runtime */ -__attribute__((format(printf, 4, 5))) + +/* All libdm messages */ +__attribute__((format(printf, 5, 6))) +static void _libdm_log(int level, const char *file, int line, + int dm_errno_or_class, const char *format, ...) +{ + va_list ap; + va_start(ap, format); + dm_event_log("#dm", level, file, line, dm_errno_or_class, format, ap); + va_end(ap); +} + +/* All dmeventd messages */ +#undef LOG_MESG +#define LOG_MESG(l, f, ln, e, x...) _dmeventd_log(l, f, ln, e, ## x) +__attribute__((format(printf, 5, 6))) static void _dmeventd_log(int level, const char *file, int line, - const char *format, ...) + int dm_errno_or_class, const char *format, ...) { va_list ap; va_start(ap, format); - dm_event_log("dm", level, file, line, 0, format, ap); + dm_event_log("dmeventd", level, file, line, dm_errno_or_class, format, ap); va_end(ap); } @@ -2191,7 +2206,7 @@ int main(int argc, char *argv[]) openlog("dmeventd", LOG_PID, LOG_DAEMON); dm_event_log_set(_debug_level, _use_syslog); - dm_log_init(_dmeventd_log); + dm_log_with_errno_init(_libdm_log); (void) dm_prepare_selinux_context(DMEVENTD_PIDFILE, S_IFREG); if (dm_create_lockfile(DMEVENTD_PIDFILE) == 0) diff --git a/daemons/dmeventd/plugins/lvm2/dmeventd_lvm.c b/daemons/dmeventd/plugins/lvm2/dmeventd_lvm.c index f36feb4..0cca98f 100644 --- a/daemons/dmeventd/plugins/lvm2/dmeventd_lvm.c +++ b/daemons/dmeventd/plugins/lvm2/dmeventd_lvm.c @@ -32,7 +32,7 @@ static int _register_count = 0; static struct dm_pool *_mem_pool = NULL; static void *_lvm_handle = NULL; -DM_EVENT_LOG_FN("lvm") +DM_EVENT_LOG_FN("#lvm") static void _lvm2_print_log(int level, const char *file, int line, int dm_errno_or_class, const char *msg)

1 0

master - dmeventd: debug only subsystemd with # sign
by Zdenek Kabelac 03 Nov '16

03 Nov '16

Gitweb: http://git.fedorahosted.org/git/?p=lvm2.git;a=commitdiff;h=cd468b6218fc5c46… Commit: cd468b6218fc5c46e98ee0061010724c298c312c Parent: 33dd1f7747ecb4e16fb807af6673592d1b0d4c3d Author: Zdenek Kabelac <zkabelac(a)redhat.com> AuthorDate: Thu Nov 3 12:01:01 2016 +0100 Committer: Zdenek Kabelac <zkabelac(a)redhat.com> CommitterDate: Thu Nov 3 12:43:09 2016 +0100 dmeventd: debug only subsystemd with # sign Reword the logging logic and try to restore previous logging behavior for 'standalone' running daemon while preserving debuggable feautures it has gained. So actual rules: dmeventd without any '-d' option will syslog all messages from dmeventd.c it dmeventd plugins. log_notice()==log_verbose() log_info()==log_very_verbose() But to show also log_debug() used has to give '-ddd'. When user specified '-d, -dd, -ddd, -dddd' it will also enable tracing of messages from libdm & lib executed code - which is mainly useful for testing i.e.: 'dmeventd -fldddd' --- WHATS_NEW_DM | 1 + daemons/dmeventd/libdevmapper-event.c | 26 ++++++++++++++++++-------- 2 files changed, 19 insertions(+), 8 deletions(-) diff --git a/WHATS_NEW_DM b/WHATS_NEW_DM index fa77d10..73a5171 100644 --- a/WHATS_NEW_DM +++ b/WHATS_NEW_DM @@ -1,5 +1,6 @@ Version 1.02.136 - ====================================== + Notice and Info messages are again logged from dmeventd and its plugins. Dmeventd now also respects DM_ABORT_ON_INTERNAL_ERRORS as libdm based tool. Report as non default dm logging also when logging with errno was changed. Use log_level() macro to consistently decode message log level in dmeventd. diff --git a/daemons/dmeventd/libdevmapper-event.c b/daemons/dmeventd/libdevmapper-event.c index 12173fd..b23b6c1 100644 --- a/daemons/dmeventd/libdevmapper-event.c +++ b/daemons/dmeventd/libdevmapper-event.c @@ -872,22 +872,31 @@ void dm_event_log(const char *subsys, int level, const char *file, FILE *stream = log_stderr(level) ? stderr : stdout; int prio; time_t now; + int log_with_debug = 0; + + if (subsys[0] == '#') { + /* Subsystems starting with '#' are logged + * only when debugging is enabled. */ + log_with_debug++; + subsys++; + } switch (log_level(level)) { case _LOG_DEBUG: + /* Never shown without -ddd */ if (_debug_level < 3) return; prio = LOG_DEBUG; indent = " "; break; case _LOG_INFO: - if (_debug_level < 2) + if (log_with_debug && _debug_level < 2) return; prio = LOG_INFO; indent = " "; break; case _LOG_NOTICE: - if (_debug_level < 1) + if (log_with_debug && _debug_level < 1) return; prio = LOG_NOTICE; indent = " "; @@ -913,12 +922,13 @@ void dm_event_log(const char *subsys, int level, const char *file, if (!start) start = now; now -= start; - fprintf(stream, "[%2d:%02d] %8x:%-6s%s", - (int)now / 60, (int)now % 60, - // TODO: Maybe use shorter ID - // ((int)(pthread_self()) >> 6) & 0xffff, - (int)pthread_self(), subsys, - (_debug_level > 3) ? "" : indent); + if (_debug_level) + fprintf(stream, "[%2d:%02d] %8x:%-6s%s", + (int)now / 60, (int)now % 60, + // TODO: Maybe use shorter ID + // ((int)(pthread_self()) >> 6) & 0xffff, + (int)pthread_self(), subsys, + (_debug_level > 3) ? "" : indent); if (_debug_level > 3) fprintf(stream, "%28s:%4d %s", file, line, indent); vfprintf(stream, _(format), ap);

1 0

master - dmeventd: abort on internal error
by Zdenek Kabelac 03 Nov '16

03 Nov '16

Gitweb: http://git.fedorahosted.org/git/?p=lvm2.git;a=commitdiff;h=33dd1f7747ecb4e1… Commit: 33dd1f7747ecb4e16fb807af6673592d1b0d4c3d Parent: e50d434a353efac7d4947c7deeaf7cfd773ea6e1 Author: Zdenek Kabelac <zkabelac(a)redhat.com> AuthorDate: Wed Nov 2 14:40:12 2016 +0100 Committer: Zdenek Kabelac <zkabelac(a)redhat.com> CommitterDate: Thu Nov 3 12:43:09 2016 +0100 dmeventd: abort on internal error Provide same support for DM_ABORT_ON_INTERNAL_ERRORS we do have with default libdm logging as dmeventd is libdm based tool. --- WHATS_NEW_DM | 1 + daemons/dmeventd/libdevmapper-event.c | 10 ++++++++++ 2 files changed, 11 insertions(+), 0 deletions(-) diff --git a/WHATS_NEW_DM b/WHATS_NEW_DM index 8cf0e05..fa77d10 100644 --- a/WHATS_NEW_DM +++ b/WHATS_NEW_DM @@ -1,5 +1,6 @@ Version 1.02.136 - ====================================== + Dmeventd now also respects DM_ABORT_ON_INTERNAL_ERRORS as libdm based tool. Report as non default dm logging also when logging with errno was changed. Use log_level() macro to consistently decode message log level in dmeventd. Still produce output when dmsetup dependency tree building finds dev missing. diff --git a/daemons/dmeventd/libdevmapper-event.c b/daemons/dmeventd/libdevmapper-event.c index 8c21537..12173fd 100644 --- a/daemons/dmeventd/libdevmapper-event.c +++ b/daemons/dmeventd/libdevmapper-event.c @@ -865,6 +865,7 @@ void dm_event_log(const char *subsys, int level, const char *file, int line, int dm_errno_or_class, const char *format, va_list ap) { + static int _abort_on_internal_errors = -1; static pthread_mutex_t _log_mutex = PTHREAD_MUTEX_INITIALIZER; static time_t start = 0; const char *indent = ""; @@ -926,6 +927,15 @@ void dm_event_log(const char *subsys, int level, const char *file, } pthread_mutex_unlock(&_log_mutex); + + if (_abort_on_internal_errors < 0) + /* Set when env DM_ABORT_ON_INTERNAL_ERRORS is not "0" */ + _abort_on_internal_errors = + strcmp(getenv("DM_ABORT_ON_INTERNAL_ERRORS") ? : "0", "0"); + + if (_abort_on_internal_errors && + !strncmp(format, INTERNAL_ERROR, sizeof(INTERNAL_ERROR) - 1)) + abort(); } #if 0 /* left out for now */

1 0

master - libdm: report logging with errno as changed default
by Zdenek Kabelac 03 Nov '16

03 Nov '16

Gitweb: http://git.fedorahosted.org/git/?p=lvm2.git;a=commitdiff;h=e50d434a353efac7… Commit: e50d434a353efac7d4947c7deeaf7cfd773ea6e1 Parent: 6af26273cb8c0ef310296ba0f4dd42751ab25b0a Author: Zdenek Kabelac <zkabelac(a)redhat.com> AuthorDate: Thu Nov 3 12:07:27 2016 +0100 Committer: Zdenek Kabelac <zkabelac(a)redhat.com> CommitterDate: Thu Nov 3 12:43:09 2016 +0100 libdm: report logging with errno as changed default When user changes logging with 'dm_log_with_errno_init()' also report this as non default dm logging. --- WHATS_NEW_DM | 1 + libdm/libdm-common.c | 2 +- 2 files changed, 2 insertions(+), 1 deletions(-) diff --git a/WHATS_NEW_DM b/WHATS_NEW_DM index 0b2cd3d..8cf0e05 100644 --- a/WHATS_NEW_DM +++ b/WHATS_NEW_DM @@ -1,5 +1,6 @@ Version 1.02.136 - ====================================== + Report as non default dm logging also when logging with errno was changed. Use log_level() macro to consistently decode message log level in dmeventd. Still produce output when dmsetup dependency tree building finds dev missing. Check and report pthread_sigmask() failure in dmeventd. diff --git a/libdm/libdm-common.c b/libdm/libdm-common.c index 7756009..5deb555 100644 --- a/libdm/libdm-common.c +++ b/libdm/libdm-common.c @@ -174,7 +174,7 @@ void dm_log_init(dm_log_fn fn) int dm_log_is_non_default(void) { - return (dm_log == _default_log) ? 0 : 1; + return (dm_log == _default_log && dm_log_with_errno == _default_log_with_errno) ? 0 : 1; } void dm_log_with_errno_init(dm_log_with_errno_fn fn)

1 0

master - logging: add more log macros
by Zdenek Kabelac 03 Nov '16

03 Nov '16

Gitweb: http://git.fedorahosted.org/git/?p=lvm2.git;a=commitdiff;h=6af26273cb8c0ef3… Commit: 6af26273cb8c0ef310296ba0f4dd42751ab25b0a Parent: 96118a2508e1cd3aaf5ba7a0129ff8ecc7ac4af2 Author: Zdenek Kabelac <zkabelac(a)redhat.com> AuthorDate: Wed Nov 2 14:39:13 2016 +0100 Committer: Zdenek Kabelac <zkabelac(a)redhat.com> CommitterDate: Thu Nov 3 12:43:09 2016 +0100 logging: add more log macros Introduce macros: log_level(), log_stderr(), log_once(), log_bypass_report() For easier and more consisten way how to 'decoder' bits of info from passed 'level'. This patch fixes potential problem when 'level' of message might not have always masked right bits. --- WHATS_NEW_DM | 1 + daemons/dmeventd/libdevmapper-event.c | 4 ++-- lib/log/log.c | 12 ++++++------ lib/log/log.h | 4 ++++ libdm/libdm-common.c | 4 ++-- 5 files changed, 15 insertions(+), 10 deletions(-) diff --git a/WHATS_NEW_DM b/WHATS_NEW_DM index 58a302e..0b2cd3d 100644 --- a/WHATS_NEW_DM +++ b/WHATS_NEW_DM @@ -1,5 +1,6 @@ Version 1.02.136 - ====================================== + Use log_level() macro to consistently decode message log level in dmeventd. Still produce output when dmsetup dependency tree building finds dev missing. Check and report pthread_sigmask() failure in dmeventd. Check mem alloc fail in _canonicalize_field_ids(). diff --git a/daemons/dmeventd/libdevmapper-event.c b/daemons/dmeventd/libdevmapper-event.c index d395ed3..8c21537 100644 --- a/daemons/dmeventd/libdevmapper-event.c +++ b/daemons/dmeventd/libdevmapper-event.c @@ -868,11 +868,11 @@ void dm_event_log(const char *subsys, int level, const char *file, static pthread_mutex_t _log_mutex = PTHREAD_MUTEX_INITIALIZER; static time_t start = 0; const char *indent = ""; - FILE *stream = stdout; + FILE *stream = log_stderr(level) ? stderr : stdout; int prio; time_t now; - switch (level & ~(_LOG_STDERR | _LOG_ONCE)) { + switch (log_level(level)) { case _LOG_DEBUG: if (_debug_level < 3) return; diff --git a/lib/log/log.c b/lib/log/log.c index c933154..2207c7e 100644 --- a/lib/log/log.c +++ b/lib/log/log.c @@ -476,9 +476,9 @@ static void _vprint_log(int level, const char *file, int line, int dm_errno_or_c int bufused, n; const char *trformat; /* Translated format string */ char *newbuf; - int use_stderr = level & _LOG_STDERR; - int log_once = level & _LOG_ONCE; - int log_bypass_report = level & _LOG_BYPASS_REPORT; + int use_stderr = log_stderr(level); + int log_once = log_once(level); + int log_bypass_report = log_bypass_report(level); int fatal_internal_error = 0; size_t msglen; const char *indent_spaces = ""; @@ -489,7 +489,7 @@ static void _vprint_log(int level, const char *file, int line, int dm_errno_or_c struct dm_report *orig_report; int logged_via_report = 0; - level &= ~(_LOG_STDERR|_LOG_ONCE|_LOG_BYPASS_REPORT); + level = log_level(level); if (_abort_on_internal_errors_env_present < 0) { if ((env_str = getenv("DM_ABORT_ON_INTERNAL_ERRORS"))) { @@ -715,8 +715,8 @@ void print_log_libdm(int level, const char *file, int line, int dm_errno_or_clas * LOG_WARN level and it's not going to stderr (so we're * printing common message that is not an error/warning). */ - if (!(level & _LOG_STDERR) && - ((level & ~(_LOG_STDERR|_LOG_ONCE|_LOG_BYPASS_REPORT)) == _LOG_WARN)) + if (!log_stderr(level) && + (log_level(level) == _LOG_WARN)) level |= _LOG_BYPASS_REPORT; _log_stream.out.stream = report_stream; diff --git a/lib/log/log.h b/lib/log/log.h index dac627e..0ce4fda 100644 --- a/lib/log/log.h +++ b/lib/log/log.h @@ -50,6 +50,10 @@ #define _LOG_STDERR 0x0080 /* force things to go to stderr, even if loglevel would make them go to stdout */ #define _LOG_ONCE 0x0100 /* downgrade to NOTICE if this has been already logged */ #define _LOG_BYPASS_REPORT 0x0200 /* do not log through report even if report available */ +#define log_level(x) ((x) & 0x0f) /* obtain message level */ +#define log_stderr(x) ((x) & _LOG_STDERR) /* obtain stderr bit */ +#define log_once(x) ((x) & _LOG_ONCE) /* obtain once bit */ +#define log_bypass_report(x) ((x) & _LOG_BYPASS_REPORT)/* obtain bypass bit */ #define INTERNAL_ERROR "Internal error: " diff --git a/libdm/libdm-common.c b/libdm/libdm-common.c index 6ac936f..7756009 100644 --- a/libdm/libdm-common.c +++ b/libdm/libdm-common.c @@ -114,9 +114,9 @@ static void _default_log_line(int level, const char *f, va_list ap) { static int _abort_on_internal_errors = -1; - FILE *out = (level & _LOG_STDERR) ? stderr : stdout; + FILE *out = log_stderr(level) ? stderr : stdout; - level &= ~(_LOG_STDERR | _LOG_BYPASS_REPORT); + level = log_level(level); if (level <= _LOG_WARN || _verbose) { if (level < _LOG_WARN)

1 0

master - lvmdbusd: Stop using threads for job wait
by tasleson 02 Nov '16

02 Nov '16

Gitweb: http://git.fedorahosted.org/git/?p=lvm2.git;a=commitdiff;h=96118a2508e1cd3a… Commit: 96118a2508e1cd3aaf5ba7a0129ff8ecc7ac4af2 Parent: 95abadd13c468b56612c1966d28daddfdeee6e2e Author: Tony Asleson <tasleson(a)redhat.com> AuthorDate: Wed Nov 2 14:14:56 2016 -0500 Committer: Tony Asleson <tasleson(a)redhat.com> CommitterDate: Wed Nov 2 16:39:13 2016 -0500 lvmdbusd: Stop using threads for job wait Instead of creating a thread to handle the case where a client is calling job.Wait, we will utilize a timer. This significantly reduces the number of threads that get created and destroyed while the service is running. --- daemons/lvmdbusd/background.py | 29 +------------- daemons/lvmdbusd/job.py | 83 ++++++++++++++++++++++++++++++++++++++- 2 files changed, 81 insertions(+), 31 deletions(-) diff --git a/daemons/lvmdbusd/background.py b/daemons/lvmdbusd/background.py index e8b42fe..0220b97 100644 --- a/daemons/lvmdbusd/background.py +++ b/daemons/lvmdbusd/background.py @@ -12,8 +12,7 @@ import subprocess from . import cfg from .cmdhandler import options_to_cli_args import dbus -from .utils import pv_range_append, pv_dest_ranges, log_error, log_debug, \ - mt_async_result +from .utils import pv_range_append, pv_dest_ranges, log_error, log_debug import traceback import os @@ -184,29 +183,3 @@ def add(command, reporting_job): with _rlock: _thread_list.append(t) - -def wait_thread(job, timeout, cb, cbe): - # We need to put the wait on it's own thread, so that we don't block the - # entire dbus queue processing thread - try: - mt_async_result(cb, job.state.Wait(timeout)) - except Exception as e: - mt_async_result(cbe, "Wait exception: %s" % str(e)) - return 0 - - -def add_wait(job, timeout, cb, cbe): - - if timeout == 0: - # Users are basically polling, do not create thread - mt_async_result(cb, job.Complete) - else: - t = threading.Thread( - target=wait_thread, - name="thread job.Wait: %s" % job.dbus_object_path(), - args=(job, timeout, cb, cbe) - ) - - t.start() - with _rlock: - _thread_list.append(t) diff --git a/daemons/lvmdbusd/job.py b/daemons/lvmdbusd/job.py index 1158370..81048a6 100644 --- a/daemons/lvmdbusd/job.py +++ b/daemons/lvmdbusd/job.py @@ -8,12 +8,54 @@ # along with this program. If not, see <http://www.gnu.org/licenses/>. from .automatedproperties import AutomatedProperties -from .utils import job_obj_path_generate +from .utils import job_obj_path_generate, mt_async_result, log_debug from . import cfg from .cfg import JOB_INTERFACE import dbus import threading -from . import background +from gi.repository import GLib + + +# Class that handles a client waiting for something to be complete. We either +# get a timeout or the operation is done. +class WaitingClient(object): + + # A timeout occurred + @staticmethod + def _timeout(wc): + with wc.rlock: + if wc.in_use: + wc.in_use = False + # Remove ourselves from waiting client + wc.job_state.remove_waiting_client(wc) + wc.timer_id = -1 + mt_async_result(wc.cb, wc.job_state.Complete) + wc.job_state = None + + def __init__(self, job_state, tmo, cb, cbe): + self.rlock = threading.RLock() + self.job_state = job_state + self.cb = cb + self.cbe = cbe + self.in_use = True # Indicates if object is in play + self.timer_id = -1 + if tmo > 0: + self.timer_id = GLib.timeout_add_seconds( + tmo, WaitingClient._timeout, self) + + # The job finished before the timer popped and we are being notified that + # it's done + def notify(self): + with self.rlock: + if self.in_use: + self.in_use = False + # Clear timer + if self.timer_id != -1: + GLib.source_remove(self.timer_id) + self.timer_id = -1 + + mt_async_result(self.cb, self.job_state.Complete) + self.job_state = None # noinspection PyPep8Naming @@ -27,6 +69,7 @@ class JobState(object): self._cond = threading.Condition(self.rlock) self._ec = 0 self._stderr = '' + self._waiting_clients = [] # This is an lvm command that is just taking too long and doesn't # support background operation @@ -58,6 +101,7 @@ class JobState(object): self._complete = value self._percent = 100 self._cond.notify_all() + self.notify_waiting_clients() @property def GetError(self): @@ -101,6 +145,35 @@ class JobState(object): return self._request.result() return '/' + def add_waiting_client(self, client): + with self.rlock: + # Avoid race condition where it goes complete before we get added + # to the list of waiting clients + if self.Complete: + client.notify() + else: + self._waiting_clients.append(client) + + def remove_waiting_client(self, client): + # If a waiting client timer pops before the job is done we will allow + # the client to remove themselves from the list. As we have a lock + # here and a lock in the waiting client too, and they can be obtained + # in different orders, a dead lock can occur. + # As this remove is really optional, we will try to acquire the lock + # and remove. If we are unsuccessful it's not fatal, we just delay + # the time when the objects can be garbage collected by python + if self.rlock.acquire(False): + try: + self._waiting_clients.remove(client) + finally: + self.rlock.release() + + def notify_waiting_clients(self): + with self.rlock: + for c in self._waiting_clients: + c.notify() + + self._waiting_clients = [] # noinspection PyPep8Naming class Job(AutomatedProperties): @@ -155,7 +228,11 @@ class Job(AutomatedProperties): out_signature='b', async_callbacks=('cb', 'cbe')) def Wait(self, timeout, cb, cbe): - background.add_wait(self, timeout, cb, cbe) + if timeout == 0 or self.state.Complete: + cb(dbus.Boolean(self.state.Complete)) + else: + self.state.add_waiting_client( + WaitingClient(self.state, timeout, cb, cbe)) @property def Result(self):

1 0

master - lvmdbusd: main.py: change debug msg text
by tasleson 02 Nov '16

02 Nov '16

Gitweb: http://git.fedorahosted.org/git/?p=lvm2.git;a=commitdiff;h=95abadd13c468b56… Commit: 95abadd13c468b56612c1966d28daddfdeee6e2e Parent: 60de09b00caf034367278adea420b67700c01b71 Author: Tony Asleson <tasleson(a)redhat.com> AuthorDate: Tue Nov 1 17:52:51 2016 -0500 Committer: Tony Asleson <tasleson(a)redhat.com> CommitterDate: Wed Nov 2 16:39:13 2016 -0500 lvmdbusd: main.py: change debug msg text --- daemons/lvmdbusd/main.py | 2 +- 1 files changed, 1 insertions(+), 1 deletions(-) diff --git a/daemons/lvmdbusd/main.py b/daemons/lvmdbusd/main.py index 93e035f..5fe1018 100644 --- a/daemons/lvmdbusd/main.py +++ b/daemons/lvmdbusd/main.py @@ -85,7 +85,7 @@ def process_request(): log_debug( "Inspect method %s for too many refreshes" % (str(req.method))) - log_debug("Complete ") + log_debug("Method complete ") except queue.Empty: pass except Exception:

1 0

master - lvmdbusd: Don't use dbus lib in worker thread
by tasleson 02 Nov '16

02 Nov '16

Gitweb: http://git.fedorahosted.org/git/?p=lvm2.git;a=commitdiff;h=60de09b00caf0343… Commit: 60de09b00caf034367278adea420b67700c01b71 Parent: 38dd79307a51faedb75e092a7913781e6eb88902 Author: Tony Asleson <tasleson(a)redhat.com> AuthorDate: Tue Nov 1 17:52:18 2016 -0500 Committer: Tony Asleson <tasleson(a)redhat.com> CommitterDate: Wed Nov 2 16:39:03 2016 -0500 lvmdbusd: Don't use dbus lib in worker thread Simplify the code paths so that we don't utilize the dbus library code when we are in worker thread context. ref. https://bugs.freedesktop.org/show_bug.cgi?id=98521 --- daemons/lvmdbusd/lv.py | 24 +++++++----------------- daemons/lvmdbusd/manager.py | 16 ++++------------ daemons/lvmdbusd/pv.py | 6 +++--- daemons/lvmdbusd/vg.py | 13 ++----------- 4 files changed, 16 insertions(+), 43 deletions(-) diff --git a/daemons/lvmdbusd/lv.py b/daemons/lvmdbusd/lv.py index c356799..e130ae4 100644 --- a/daemons/lvmdbusd/lv.py +++ b/daemons/lvmdbusd/lv.py @@ -21,7 +21,7 @@ from .utils import n, n32 from .loader import common from .state import State from . import background -from .utils import round_size +from .utils import round_size, mt_remove_dbus_objects from .job import JobState @@ -415,7 +415,6 @@ class Lv(LvCommon): rc, out, err = cmdhandler.lv_remove(lv_name, remove_options) if rc == 0: - cfg.om.remove_object(dbo, True) cfg.load() else: # Need to work on error handling, need consistent @@ -515,15 +514,9 @@ class Lv(LvCommon): rc, out, err = cmdhandler.vg_lv_snapshot( lv_name, snapshot_options, name, optional_size) if rc == 0: - return_path = '/' + cfg.load() full_name = "%s/%s" % (dbo.vg_name_lookup(), name) - lvs = load_lvs([full_name], emit_signal=True)[0] - for l in lvs: - return_path = l.dbus_object_path() - - # Refresh self and all included PVs - cfg.load(cache_refresh=False) - return return_path + return cfg.om.get_object_path_by_lvm_id(full_name) else: raise dbus.exceptions.DBusException( LV_INTERFACE, @@ -752,9 +745,8 @@ class LvThinPool(Lv): lv_name, create_options, name, size_bytes) if rc == 0: full_name = "%s/%s" % (dbo.vg_name_lookup(), name) - lvs = load_lvs([full_name], emit_signal=True)[0] - for l in lvs: - lv_created = l.dbus_object_path() + cfg.load() + lv_created = cfg.om.get_object_path_by_lvm_id(full_name) else: raise dbus.exceptions.DBusException( LV_INTERFACE, @@ -816,8 +808,7 @@ class LvCachePool(Lv): # When we cache an LV, the cache pool and the lv that is getting # cached need to be removed from the object manager and # re-created as their interfaces have changed! - cfg.om.remove_object(dbo, emit_signal=True) - cfg.om.remove_object(lv_to_cache, emit_signal=True) + mt_remove_dbus_objects((dbo, lv_to_cache)) cfg.load() lv_converted = cfg.om.get_object_path_by_lvm_id(fcn) @@ -879,8 +870,7 @@ class LvCacheLv(Lv): if rc == 0: # The cache pool gets removed as hidden and put back to # visible, so lets delete - cfg.om.remove_object(cache_pool, emit_signal=True) - cfg.om.remove_object(dbo, emit_signal=True) + mt_remove_dbus_objects((cache_pool, dbo)) cfg.load() uncached_lv_path = cfg.om.get_object_path_by_lvm_id(lv_name) diff --git a/daemons/lvmdbusd/manager.py b/daemons/lvmdbusd/manager.py index e377442..e81ee1f 100644 --- a/daemons/lvmdbusd/manager.py +++ b/daemons/lvmdbusd/manager.py @@ -42,12 +42,10 @@ class Manager(AutomatedProperties): raise dbus.exceptions.DBusException( MANAGER_INTERFACE, "PV Already exists!") - created_pv = [] rc, out, err = cmdhandler.pv_create(create_options, [device]) if rc == 0: - pvs = load_pvs([device], emit_signal=True)[0] - for p in pvs: - created_pv = p.dbus_object_path() + cfg.load() + created_pv = cfg.om.get_object_path_by_lvm_id(device) else: raise dbus.exceptions.DBusException( MANAGER_INTERFACE, @@ -80,20 +78,14 @@ class Manager(AutomatedProperties): MANAGER_INTERFACE, 'object path = %s not found' % p) rc, out, err = cmdhandler.vg_create(create_options, pv_devices, name) - created_vg = "/" if rc == 0: - vgs = load_vgs([name], emit_signal=True)[0] - for v in vgs: - created_vg = v.dbus_object_path() - - # Update the PVS - load_pvs(refresh=True, emit_signal=True, cache_refresh=False) + cfg.load() + return cfg.om.get_object_path_by_lvm_id(name) else: raise dbus.exceptions.DBusException( MANAGER_INTERFACE, 'Exit code %s, stderr = %s' % (str(rc), err)) - return created_vg @dbus.service.method( dbus_interface=MANAGER_INTERFACE, diff --git a/daemons/lvmdbusd/pv.py b/daemons/lvmdbusd/pv.py index ad8d8b3..fa07f98 100644 --- a/daemons/lvmdbusd/pv.py +++ b/daemons/lvmdbusd/pv.py @@ -18,7 +18,7 @@ from .utils import vg_obj_path_generate, n, pv_obj_path_generate, \ from .loader import common from .request import RequestEntry from .state import State -from .utils import round_size +from .utils import round_size, mt_remove_dbus_objects # noinspection PyUnusedLocal @@ -140,7 +140,7 @@ class Pv(AutomatedProperties): if dbo: rc, out, err = cmdhandler.pv_remove(pv_name, remove_options) if rc == 0: - cfg.om.remove_object(dbo, True) + mt_remove_dbus_objects((dbo,)) else: # Need to work on error handling, need consistent raise dbus.exceptions.DBusException( @@ -174,7 +174,7 @@ class Pv(AutomatedProperties): rc, out, err = cmdhandler.pv_resize(pv_name, new_size_bytes, resize_options) if rc == 0: - dbo.refresh() + cfg.load() else: raise dbus.exceptions.DBusException( PV_INTERFACE, diff --git a/daemons/lvmdbusd/vg.py b/daemons/lvmdbusd/vg.py index 70ccad6..d84bb75 100644 --- a/daemons/lvmdbusd/vg.py +++ b/daemons/lvmdbusd/vg.py @@ -19,7 +19,7 @@ from .request import RequestEntry from .loader import common from .state import State from . import background -from .utils import round_size +from .utils import round_size, mt_remove_dbus_objects from .job import JobState @@ -191,14 +191,7 @@ class Vg(AutomatedProperties): rc, out, err = cmdhandler.vg_remove(vg_name, remove_options) if rc == 0: - # Remove the VG - cfg.om.remove_object(dbo, True) - - # If an LV has hidden LVs, things can get quite involved, - # especially if it's the last thin pool to get removed, so - # lets refresh all cfg.load() - else: # Need to work on error handling, need consistent raise dbus.exceptions.DBusException( @@ -605,9 +598,7 @@ class Vg(AutomatedProperties): rc, out, err = create_method( md.lv_full_name(), data.lv_full_name(), create_options) if rc == 0: - cfg.om.remove_object(md, emit_signal=True) - cfg.om.remove_object(data, emit_signal=True) - + mt_remove_dbus_objects((md, data)) cache_pool_lv = Vg.fetch_new_lv(vg_name, new_name) else: raise dbus.exceptions.DBusException(

1 0

master - lvmdbusd: Execute load in main thread
by tasleson 02 Nov '16

02 Nov '16

Gitweb: http://git.fedorahosted.org/git/?p=lvm2.git;a=commitdiff;h=38dd79307a51faed… Commit: 38dd79307a51faedb75e092a7913781e6eb88902 Parent: 24803bbaadd8bd497e2ca337786b01725df61736 Author: Tony Asleson <tasleson(a)redhat.com> AuthorDate: Tue Nov 1 17:50:10 2016 -0500 Committer: Tony Asleson <tasleson(a)redhat.com> CommitterDate: Wed Nov 2 16:38:49 2016 -0500 lvmdbusd: Execute load in main thread We will fetch the lvm state in non-main thread and only process the new data with the main thread to prevent hanging the main thread event loop. ref. https://bugs.freedesktop.org/show_bug.cgi?id=98521 --- daemons/lvmdbusd/fetch.py | 33 +++++++++++++++++++++++++-------- daemons/lvmdbusd/main.py | 2 +- 2 files changed, 26 insertions(+), 9 deletions(-) diff --git a/daemons/lvmdbusd/fetch.py b/daemons/lvmdbusd/fetch.py index 51f130f..7626460 100644 --- a/daemons/lvmdbusd/fetch.py +++ b/daemons/lvmdbusd/fetch.py @@ -11,20 +11,37 @@ from .pv import load_pvs from .vg import load_vgs from .lv import load_lvs from . import cfg +from .utils import MThreadRunner, log_debug -def load(refresh=True, emit_signal=True, cache_refresh=True, log=True): +def _main_thread_load(refresh=True, emit_signal=True): num_total_changes = 0 + num_total_changes += load_pvs( + refresh=refresh, + emit_signal=emit_signal, + cache_refresh=False)[1] + num_total_changes += load_vgs( + refresh=refresh, + emit_signal=emit_signal, + cache_refresh=False)[1] + num_total_changes += load_lvs( + refresh=refresh, + emit_signal=emit_signal, + cache_refresh=False)[1] + + return num_total_changes + + +def load(refresh=True, emit_signal=True, cache_refresh=True, log=True, + need_main_thread=True): # Go through and load all the PVs, VGs and LVs if cache_refresh: cfg.db.refresh(log) - num_total_changes += load_pvs(refresh=refresh, emit_signal=emit_signal, - cache_refresh=False)[1] - num_total_changes += load_vgs(refresh=refresh, emit_signal=emit_signal, - cache_refresh=False)[1] - num_total_changes += load_lvs(refresh=refresh, emit_signal=emit_signal, - cache_refresh=False)[1] + if need_main_thread: + rc = MThreadRunner(_main_thread_load, refresh, emit_signal).done() + else: + rc = _main_thread_load(refresh, emit_signal) - return num_total_changes + return rc diff --git a/daemons/lvmdbusd/main.py b/daemons/lvmdbusd/main.py index 2dca703..93e035f 100644 --- a/daemons/lvmdbusd/main.py +++ b/daemons/lvmdbusd/main.py @@ -162,7 +162,7 @@ def main(): # Using a thread to process requests. thread_list.append(threading.Thread(target=process_request)) - cfg.load(refresh=False, emit_signal=False) + cfg.load(refresh=False, emit_signal=False, need_main_thread=False) cfg.loop = GLib.MainLoop() for process in thread_list:

1 0

master - lvmdbusd: Return results in main thread
by tasleson 02 Nov '16

02 Nov '16

Gitweb: http://git.fedorahosted.org/git/?p=lvm2.git;a=commitdiff;h=24803bbaadd8bd49… Commit: 24803bbaadd8bd497e2ca337786b01725df61736 Parent: c8e8439b3dc037fd73a2eab94e7e796cfb8283a1 Author: Tony Asleson <tasleson(a)redhat.com> AuthorDate: Tue Nov 1 17:48:39 2016 -0500 Committer: Tony Asleson <tasleson(a)redhat.com> CommitterDate: Wed Nov 2 16:38:00 2016 -0500 lvmdbusd: Return results in main thread Also introduce some additional new code to execute code other code in main thread too. ref. https://bugs.freedesktop.org/show_bug.cgi?id=98521 --- daemons/lvmdbusd/background.py | 9 +++-- daemons/lvmdbusd/request.py | 12 ++++---- daemons/lvmdbusd/utils.py | 63 ++++++++++++++++++++++++++++++++++++++++ 3 files changed, 74 insertions(+), 10 deletions(-) diff --git a/daemons/lvmdbusd/background.py b/daemons/lvmdbusd/background.py index ab0ac2a..e8b42fe 100644 --- a/daemons/lvmdbusd/background.py +++ b/daemons/lvmdbusd/background.py @@ -12,7 +12,8 @@ import subprocess from . import cfg from .cmdhandler import options_to_cli_args import dbus -from .utils import pv_range_append, pv_dest_ranges, log_error, log_debug +from .utils import pv_range_append, pv_dest_ranges, log_error, log_debug, \ + mt_async_result import traceback import os @@ -188,9 +189,9 @@ def wait_thread(job, timeout, cb, cbe): # We need to put the wait on it's own thread, so that we don't block the # entire dbus queue processing thread try: - cb(job.state.Wait(timeout)) + mt_async_result(cb, job.state.Wait(timeout)) except Exception as e: - cbe("Wait exception: %s" % str(e)) + mt_async_result(cbe, "Wait exception: %s" % str(e)) return 0 @@ -198,7 +199,7 @@ def add_wait(job, timeout, cb, cbe): if timeout == 0: # Users are basically polling, do not create thread - cb(job.Complete) + mt_async_result(cb, job.Complete) else: t = threading.Thread( target=wait_thread, diff --git a/daemons/lvmdbusd/request.py b/daemons/lvmdbusd/request.py index c48d043..ca45e8c 100644 --- a/daemons/lvmdbusd/request.py +++ b/daemons/lvmdbusd/request.py @@ -13,7 +13,7 @@ from gi.repository import GLib from .job import Job from . import cfg import traceback -from .utils import log_error +from .utils import log_error, mt_async_result class RequestEntry(object): @@ -57,9 +57,9 @@ class RequestEntry(object): self._job = Job(self, self._job_state) cfg.om.register_object(self._job, True) if self._return_tuple: - self.cb(('/', self._job.dbus_object_path())) + mt_async_result(self.cb, ('/', self._job.dbus_object_path())) else: - self.cb(self._job.dbus_object_path()) + mt_async_result(self.cb, self._job.dbus_object_path()) def run_cmd(self): try: @@ -110,9 +110,9 @@ class RequestEntry(object): if error_rc == 0: if self.cb: if self._return_tuple: - self.cb((result, '/')) + mt_async_result(self.cb, (result, '/')) else: - self.cb(result) + mt_async_result(self.cb, result) else: if self.cb_error: if not error_exception: @@ -123,7 +123,7 @@ class RequestEntry(object): else: error_exception = Exception(error_msg) - self.cb_error(error_exception) + mt_async_result(self.cb_error, error_exception) else: # We have a job and it's complete, indicate that it's done. # TODO: We need to signal the job is done too. diff --git a/daemons/lvmdbusd/utils.py b/daemons/lvmdbusd/utils.py index ef7e61f..12b797e 100644 --- a/daemons/lvmdbusd/utils.py +++ b/daemons/lvmdbusd/utils.py @@ -17,6 +17,8 @@ import datetime import dbus from lvmdbusd import cfg +from gi.repository import GLib +import threading STDOUT_TTY = os.isatty(sys.stdout.fileno()) @@ -494,3 +496,64 @@ def validate_tag(interface, tag): raise dbus.exceptions.DBusException( interface, 'tag (%s) contains invalid character, allowable set(%s)' % (tag, _ALLOWABLE_TAG_CH)) + + +# The methods below which start with mt_* are used to execute the desired code +# on the the main thread of execution to alleviate any issues the dbus-python +# library with regards to multi-threaded access. Essentially, we are trying to +# ensure all dbus library interaction is done from the same thread! + + +def _async_result(call_back, results): + log_debug('Results = %s' % str(results)) + call_back(results) + +# Return result in main thread +def mt_async_result(call_back, results): + GLib.idle_add(_async_result, call_back, results) + + +# Run the supplied function and arguments on the main thread and wait for them +# to complete while allowing the ability to get the return value too. +# +# Example: +# result = MThreadRunner(foo, arg1, arg2).done() +# +class MThreadRunner(object): + + @staticmethod + def runner(obj): + obj._run() + with obj.cond: + obj.function_complete = True + obj.cond.notify_all() + + def __init__(self, function, *args): + self.f = function + self.rc = None + self.args = args + self.function_complete = False + self.cond = threading.Condition(threading.Lock()) + + def done(self): + GLib.idle_add(MThreadRunner.runner, self) + with self.cond: + if not self.function_complete: + self.cond.wait() + return self.rc + + def _run(self): + if len(self.args): + self.rc = self.f(*self.args) + else: + self.rc = self.f() + + +def _remove_objects(dbus_objects_rm): + for o in dbus_objects_rm: + cfg.om.remove_object(o, emit_signal=True) + + +# Remove dbus objects from main thread +def mt_remove_dbus_objects(objs): + MThreadRunner(_remove_objects, objs).done()

1 0

2026

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

lvm2-commits November 2016