From 8669ca2283e6d21f5a799ab2c0e7df090cd12f14 Mon Sep 17 00:00:00 2001 From: Lance Edgar Date: Sun, 25 Aug 2024 15:52:29 -0500 Subject: [PATCH] feat: add "progress" page for executing upgrades show scrolling stdout from subprocess nb. this does *not* show stderr, although that is captured --- src/wuttaweb/templates/progress.mako | 7 +- src/wuttaweb/templates/upgrade.mako | 64 +++++++++++++ src/wuttaweb/views/master.py | 129 ++++++++++++++++++++++----- src/wuttaweb/views/upgrades.py | 80 +++++++++++++++-- tests/views/test_master.py | 59 +++++++++--- tests/views/test_upgrades.py | 94 ++++++++++++++++++- 6 files changed, 392 insertions(+), 41 deletions(-) create mode 100644 src/wuttaweb/templates/upgrade.mako diff --git a/src/wuttaweb/templates/progress.mako b/src/wuttaweb/templates/progress.mako index 35223a1..ddf5a74 100644 --- a/src/wuttaweb/templates/progress.mako +++ b/src/wuttaweb/templates/progress.mako @@ -55,7 +55,7 @@ <%def name="modify_vue_vars()"> diff --git a/src/wuttaweb/templates/upgrade.mako b/src/wuttaweb/templates/upgrade.mako new file mode 100644 index 0000000..72a4424 --- /dev/null +++ b/src/wuttaweb/templates/upgrade.mako @@ -0,0 +1,64 @@ +## -*- coding: utf-8; -*- +<%inherit file="/progress.mako" /> + +<%def name="extra_styles()"> + ${parent.extra_styles()} + + + +<%def name="after_progress()"> +
+ + + + ## nb. we auto-scroll down to "see" this element +
+
+ + +<%def name="modify_vue_vars()"> + ${parent.modify_vue_vars()} + + diff --git a/src/wuttaweb/views/master.py b/src/wuttaweb/views/master.py index fe333b1..c5ff5d7 100644 --- a/src/wuttaweb/views/master.py +++ b/src/wuttaweb/views/master.py @@ -76,7 +76,7 @@ class MasterView(View): Optional reference to a data model class. While not strictly required, most views will set this to a SQLAlchemy mapped class, - e.g. :class:`wuttjamaican:wuttjamaican.db.model.auth.User`. + e.g. :class:`~wuttjamaican:wuttjamaican.db.model.base.Person`. Code should not access this directly but instead call :meth:`get_model_class()`. @@ -365,6 +365,7 @@ class MasterView(View): has_autocomplete = False downloadable = False executable = False + execute_progress_template = None configurable = False # current action @@ -725,7 +726,7 @@ class MasterView(View): len(records), model_title_plural, exc_info=True) if progress: - progress.handle_error(error, "Bulk deletion failed") + progress.handle_error(error) else: session.commit() @@ -953,21 +954,26 @@ class MasterView(View): * :meth:`execute_instance()` """ + route_prefix = self.get_route_prefix() model_title = self.get_model_title() obj = self.get_instance() - try: - self.execute_instance(obj) - except Exception as error: - log.exception("failed to execute %s: %s", model_title, obj) - error = str(error) or error.__class__.__name__ - self.request.session.flash(error, 'error') - else: - self.request.session.flash(f"{model_title} was executed.") + # make the progress tracker + progress = self.make_progress(f'{route_prefix}.execute', + success_msg=f"{model_title} was executed.", + success_url=self.get_action_url('view', obj)) - return self.redirect(self.get_action_url('view', obj)) + # start thread for execute; show progress page + key = self.request.matchdict + thread = threading.Thread(target=self.execute_thread, + args=(key, self.request.user.uuid), + kwargs={'progress': progress}) + thread.start() + return self.render_progress(progress, context={ + 'instance': obj, + }, template=self.execute_progress_template) - def execute_instance(self, obj): + def execute_instance(self, obj, user, progress=None): """ Perform the actual "execution" logic for a model record. Called by :meth:`execute()`. @@ -975,8 +981,43 @@ class MasterView(View): This method does nothing by default; subclass must override. :param obj: Reference to the model instance. + + :param user: Reference to the + :class:`~wuttjamaican:wuttjamaican.db.model.auth.User` who + is doing the execute. + + :param progress: Optional progress indicator factory. """ + def execute_thread(self, key, user_uuid, progress=None): + """ """ + model = self.app.model + model_title = self.get_model_title() + + # nb. use new session, separate from web transaction + session = self.app.make_session() + + # fetch model instance and user for this session + obj = self.get_instance(session=session, matchdict=key) + user = session.get(model.User, user_uuid) + + try: + self.execute_instance(obj, user, progress=progress) + + except Exception as error: + session.rollback() + log.warning("%s failed to execute: %s", model_title, obj, exc_info=True) + if progress: + progress.handle_error(error) + + else: + session.commit() + if progress: + progress.handle_success() + + finally: + session.close() + ############################## # configure methods ############################## @@ -1847,23 +1888,69 @@ class MasterView(View): # for key in self.get_model_key(): # grid.set_link(key) - def get_instance(self, session=None): + def get_instance(self, session=None, matchdict=None): """ - This should return the "current" model instance based on the - request details (e.g. route kwargs). + This should return the appropriate model instance, based on + the ``matchdict`` of model keys. - If the instance cannot be found, this should raise a HTTP 404 - exception, i.e. :meth:`~wuttaweb.views.base.View.notfound()`. + Normally this is called with no arguments, in which case the + :attr:`pyramid:pyramid.request.Request.matchdict` is used, and + will return the "current" model instance based on the request + (route/params). - There is no "sane" default logic here; subclass *must* - override or else a ``NotImplementedError`` is raised. + If a ``matchdict`` is provided then that is used instead, to + obtain the model keys. In the simple/common example of a + "native" model in WuttaWeb, this would look like:: + + keys = {'uuid': '38905440630d11ef9228743af49773a4'} + obj = self.get_instance(matchdict=keys) + + Although some models may have different, possibly composite + key names to use instead. The specific keys this logic is + expecting are the same as returned by :meth:`get_model_key()`. + + If this method is unable to locate the instance, it should + raise a 404 error, + i.e. :meth:`~wuttaweb.views.base.View.notfound()`. + + Default implementation of this method should work okay for + views which define a :attr:`model_class`. For other views + however it will raise ``NotImplementedError``, so subclass + may need to define. + + .. warning:: + + If you are defining this method for a subclass, please note + this point regarding the 404 "not found" logic. + + It is *not* enough to simply *return* this 404 response, + you must explicitly *raise* the error. For instance:: + + def get_instance(self, **kwargs): + + # ..try to locate instance.. + obj = self.locate_instance_somehow() + + if not obj: + + # NB. THIS MAY NOT WORK AS EXPECTED + #return self.notfound() + + # nb. should always do this in get_instance() + raise self.notfound() + + This lets calling code not have to worry about whether or + not this method might return ``None``. It can safely + assume it will get back a model instance, or else a 404 + will kick in and control flow goes elsewhere. """ model_class = self.get_model_class() if model_class: session = session or self.Session() + matchdict = matchdict or self.request.matchdict def filtr(query, model_key): - key = self.request.matchdict[model_key] + key = matchdict[model_key] query = query.filter(getattr(self.model_class, model_key) == key) return query @@ -2126,7 +2213,7 @@ class MasterView(View): Returns the model class for the view (if defined). A model class will *usually* be a SQLAlchemy mapped class, - e.g. :class:`wuttjamaican:wuttjamaican.db.model.base.Person`. + e.g. :class:`~wuttjamaican:wuttjamaican.db.model.base.Person`. There is no default value here, but a subclass may override by assigning :attr:`model_class`. diff --git a/src/wuttaweb/views/upgrades.py b/src/wuttaweb/views/upgrades.py index ee4a2bd..03570f3 100644 --- a/src/wuttaweb/views/upgrades.py +++ b/src/wuttaweb/views/upgrades.py @@ -36,6 +36,7 @@ from wuttjamaican.db.model import Upgrade from wuttaweb.views import MasterView from wuttaweb.forms import widgets from wuttaweb.forms.schema import UserRef, WuttaEnum, FileDownload +from wuttaweb.progress import get_progress_session log = logging.getLogger(__name__) @@ -57,6 +58,7 @@ class UpgradeView(MasterView): """ model_class = Upgrade executable = True + execute_progress_template = '/upgrade.mako' downloadable = True configurable = True @@ -222,7 +224,7 @@ class UpgradeView(MasterView): path = os.path.join(path, filename) return path - def execute_instance(self, upgrade): + def execute_instance(self, upgrade, user, progress=None): """ This method runs the actual upgrade. @@ -236,28 +238,79 @@ class UpgradeView(MasterView): either ``SUCCESS`` or ``FAILURE``. """ enum = self.app.enum - script = self.config.require(f'{self.app.appname}.upgrades.command', - session=self.Session()) + + # locate file paths + script = self.config.require(f'{self.app.appname}.upgrades.command') stdout_path = self.get_upgrade_filepath(upgrade, 'stdout.log') stderr_path = self.get_upgrade_filepath(upgrade, 'stderr.log') + # record the fact that execution has begun for this upgrade + # nb. this is done in separate session to ensure it sticks, + # but also update local object to reflect the change + with self.app.short_session(commit=True) as s: + alt = s.merge(upgrade) + alt.status = enum.UpgradeStatus.EXECUTING + upgrade.status = enum.UpgradeStatus.EXECUTING + # run the command log.debug("running upgrade command: %s", script) with open(stdout_path, 'wb') as stdout: with open(stderr_path, 'wb') as stderr: - upgrade.exit_code = subprocess.call(script, shell=True, + upgrade.exit_code = subprocess.call(script, shell=True, text=True, stdout=stdout, stderr=stderr) logger = log.warning if upgrade.exit_code != 0 else log.debug - logger("upgrade command had non-zero exit code: %s", upgrade.exit_code) + logger("upgrade command had exit code: %s", upgrade.exit_code) # declare it complete upgrade.executed = datetime.datetime.now() - upgrade.executed_by = self.request.user + upgrade.executed_by = user if upgrade.exit_code == 0: upgrade.status = enum.UpgradeStatus.SUCCESS else: upgrade.status = enum.UpgradeStatus.FAILURE + def execute_progress(self): + """ """ + route_prefix = self.get_route_prefix() + upgrade = self.get_instance() + session = get_progress_session(self.request, f'{route_prefix}.execute') + + # session has 'complete' flag set when operation is over + if session.get('complete'): + + # set a flash msg for user if one is defined. this is the + # time to do it since user is about to get redirected. + msg = session.get('success_msg') + if msg: + self.request.session.flash(msg) + + elif session.get('error'): # uh-oh + + # set an error flash msg for user. this is the time to do it + # since user is about to get redirected. + msg = session.get('error_msg', "An unspecified error occurred.") + self.request.session.flash(msg, 'error') + + # our return value will include all from progress session + data = dict(session) + + # add whatever might be new from upgrade process STDOUT + path = self.get_upgrade_filepath(upgrade, filename='stdout.log') + offset = session.get('stdout.offset', 0) + if os.path.exists(path): + size = os.path.getsize(path) - offset + if size > 0: + # with open(path, 'rb') as f: + with open(path) as f: + f.seek(offset) + chunk = f.read(size) + # data['stdout'] = chunk.decode('utf8').replace('\n', '
') + data['stdout'] = chunk.replace('\n', '
') + session['stdout.offset'] = offset + size + session.save() + + return data + def configure_get_simple_settings(self): """ """ @@ -283,6 +336,21 @@ class UpgradeView(MasterView): cls.model_class = app.model.Upgrade cls._defaults(config) + cls._upgrade_defaults(config) + + @classmethod + def _upgrade_defaults(cls, config): + route_prefix = cls.get_route_prefix() + permission_prefix = cls.get_permission_prefix() + instance_url_prefix = cls.get_instance_url_prefix() + + # execution progress + config.add_route(f'{route_prefix}.execute_progress', + f'{instance_url_prefix}/execute/progress') + config.add_view(cls, attr='execute_progress', + route_name=f'{route_prefix}.execute_progress', + permission=f'{permission_prefix}.execute', + renderer='json') def defaults(config, **kwargs): diff --git a/tests/views/test_master.py b/tests/views/test_master.py index f979479..7b75e0a 100644 --- a/tests/views/test_master.py +++ b/tests/views/test_master.py @@ -1342,8 +1342,11 @@ class TestMasterView(WebTestCase): def test_execute(self): self.pyramid_config.add_route('settings.view', '/settings/{name}') + self.pyramid_config.add_route('progress', '/progress/{key}') model = self.app.model self.app.save_setting(self.session, 'foo', 'bar') + user = model.User(username='barney') + self.session.add(user) self.session.commit() with patch.multiple(mod.MasterView, create=True, @@ -1352,18 +1355,54 @@ class TestMasterView(WebTestCase): Session=MagicMock(return_value=self.session)): view = self.make_view() self.request.matchdict = {'name': 'foo'} + self.request.session.id = 'mockid' + self.request.user = user - # basic usage, redirects to view obj url - response = view.execute() - self.assertEqual(response.status_code, 302) - self.assertEqual(self.request.session.pop_flash(), ["Setting was executed."]) - - # execution error - with patch.object(view, 'execute_instance', side_effect=RuntimeError): + # basic usage; user is shown progress page + with patch.object(mod, 'threading') as threading: response = view.execute() - self.assertEqual(response.status_code, 302) - self.assertEqual(self.request.session.pop_flash(), []) - self.assertEqual(self.request.session.pop_flash('error'), ["RuntimeError"]) + threading.Thread.return_value.start.assert_called_once_with() + self.assertEqual(response.status_code, 200) + + def test_execute_thread(self): + model = self.app.model + enum = self.app.enum + user = model.User(username='barney') + self.session.add(user) + upgrade = model.Upgrade(description='test', created_by=user, + status=enum.UpgradeStatus.PENDING) + self.session.add(upgrade) + self.session.commit() + + with patch.multiple(mod.MasterView, create=True, + model_class=model.Upgrade): + view = self.make_view() + + # basic execute, no progress + with patch.object(view, 'execute_instance') as execute_instance: + view.execute_thread({'uuid': upgrade.uuid}, user.uuid) + execute_instance.assert_called_once() + + # basic execute, with progress + with patch.object(view, 'execute_instance') as execute_instance: + progress = MagicMock() + view.execute_thread({'uuid': upgrade.uuid}, user.uuid, progress=progress) + execute_instance.assert_called_once() + progress.handle_success.assert_called_once_with() + + # error, no progress + with patch.object(view, 'execute_instance') as execute_instance: + execute_instance.side_effect = RuntimeError + view.execute_thread({'uuid': upgrade.uuid}, user.uuid) + execute_instance.assert_called_once() + + # error, with progress + with patch.object(view, 'execute_instance') as execute_instance: + progress = MagicMock() + execute_instance.side_effect = RuntimeError + view.execute_thread({'uuid': upgrade.uuid}, user.uuid, progress=progress) + execute_instance.assert_called_once() + progress.handle_error.assert_called_once() def test_configure(self): self.pyramid_config.include('wuttaweb.views.common') diff --git a/tests/views/test_upgrades.py b/tests/views/test_upgrades.py index 5d6db33..6c89d5b 100644 --- a/tests/views/test_upgrades.py +++ b/tests/views/test_upgrades.py @@ -7,6 +7,7 @@ from unittest.mock import patch, MagicMock from wuttaweb.views import upgrades as mod from wuttjamaican.exc import ConfigurationError +from wuttaweb.progress import get_progress_session from tests.util import WebTestCase @@ -220,7 +221,7 @@ class TestUpgradeView(WebTestCase): python = sys.executable # script not yet confiugred - self.assertRaises(ConfigurationError, view.execute_instance, upgrade) + self.assertRaises(ConfigurationError, view.execute_instance, upgrade, user) # script w/ success goodpy = self.write_file('good.py', """ @@ -234,7 +235,7 @@ sys.exit(0) self.assertEqual(upgrade.status, enum.UpgradeStatus.PENDING) with patch.object(view, 'Session', return_value=self.session): with patch.object(self.config, 'usedb', new=True): - view.execute_instance(upgrade) + view.execute_instance(upgrade, user) self.assertIsNotNone(upgrade.executed) self.assertIs(upgrade.executed_by, user) self.assertEqual(upgrade.status, enum.UpgradeStatus.SUCCESS) @@ -261,7 +262,7 @@ sys.exit(42) self.assertEqual(upgrade.status, enum.UpgradeStatus.PENDING) with patch.object(view, 'Session', return_value=self.session): with patch.object(self.config, 'usedb', new=True): - view.execute_instance(upgrade) + view.execute_instance(upgrade, user) self.assertIsNotNone(upgrade.executed) self.assertIs(upgrade.executed_by, user) self.assertEqual(upgrade.status, enum.UpgradeStatus.FAILURE) @@ -270,6 +271,93 @@ sys.exit(42) with open(view.get_upgrade_filepath(upgrade, 'stderr.log')) as f: self.assertEqual(f.read(), 'hello from bad.py') + def test_execute_progress(self): + model = self.app.model + enum = self.app.enum + view = self.make_view() + + user = model.User(username='barney') + self.session.add(user) + upgrade = model.Upgrade(description='test', created_by=user, + status=enum.UpgradeStatus.PENDING) + self.session.add(upgrade) + self.session.commit() + + stdout = self.write_file('stdout.log', 'hello 001\n') + + self.request.matchdict = {'uuid': upgrade.uuid} + with patch.multiple(mod.UpgradeView, + Session=MagicMock(return_value=self.session), + get_upgrade_filepath=MagicMock(return_value=stdout)): + + # nb. this is used to identify progress tracker + self.request.session.id = 'mockid#1' + + # first call should get the full contents + context = view.execute_progress() + self.assertFalse(context.get('complete')) + self.assertFalse(context.get('error')) + # nb. newline is converted to
+ self.assertEqual(context['stdout'], 'hello 001
') + + # next call should get any new contents + with open(stdout, 'a') as f: + f.write('hello 002\n') + context = view.execute_progress() + self.assertFalse(context.get('complete')) + self.assertFalse(context.get('error')) + self.assertEqual(context['stdout'], 'hello 002
') + + # nb. switch to a different progress tracker + self.request.session.id = 'mockid#2' + + # first call should get the full contents + context = view.execute_progress() + self.assertFalse(context.get('complete')) + self.assertFalse(context.get('error')) + self.assertEqual(context['stdout'], 'hello 001
hello 002
') + + # mark progress complete + session = get_progress_session(self.request, 'upgrades.execute') + session.load() + session['complete'] = True + session['success_msg'] = 'yay!' + session.save() + + # next call should reflect that + self.assertEqual(self.request.session.pop_flash(), []) + context = view.execute_progress() + self.assertTrue(context.get('complete')) + self.assertFalse(context.get('error')) + # nb. this is missing b/c we already got all contents + self.assertNotIn('stdout', context) + self.assertEqual(self.request.session.pop_flash(), ['yay!']) + + # nb. switch to a different progress tracker + self.request.session.id = 'mockid#3' + + # first call should get the full contents + context = view.execute_progress() + self.assertFalse(context.get('complete')) + self.assertFalse(context.get('error')) + self.assertEqual(context['stdout'], 'hello 001
hello 002
') + + # mark progress error + session = get_progress_session(self.request, 'upgrades.execute') + session.load() + session['error'] = True + session['error_msg'] = 'omg!' + session.save() + + # next call should reflect that + self.assertEqual(self.request.session.pop_flash('error'), []) + context = view.execute_progress() + self.assertFalse(context.get('complete')) + self.assertTrue(context.get('error')) + # nb. this is missing b/c we already got all contents + self.assertNotIn('stdout', context) + self.assertEqual(self.request.session.pop_flash('error'), ['omg!']) + def test_configure_get_simple_settings(self): # sanity/coverage check view = self.make_view()