From c5d484fb815453b824183566de8efdfa651ba71f Mon Sep 17 00:00:00 2001 From: Martin Curlej Date: Jul 31 2019 11:32:33 +0000 Subject: Added an REST endpoint to display log messages The issue is that users don't get feedback from MBS about why a component was not reused. There was added logic which enables to store log messages in the database and can be viewed through the REST api of MBS. Ticket-ID: #1284 Signed-off-by: Martin Curlej --- diff --git a/module_build_service/migrations/versions/0b00036c540f_add_log_messages_table.py b/module_build_service/migrations/versions/0b00036c540f_add_log_messages_table.py new file mode 100644 index 0000000..a521e9c --- /dev/null +++ b/module_build_service/migrations/versions/0b00036c540f_add_log_messages_table.py @@ -0,0 +1,30 @@ +"""add log_messages table + +Revision ID: 0b00036c540f +Revises: 40b2c7d988d7 +Create Date: 2019-07-14 07:24:21.059144 + +""" + +# revision identifiers, used by Alembic. +revision = "0b00036c540f" +down_revision = "40b2c7d988d7" + +from alembic import op +import sqlalchemy as sa + + +def upgrade(): + op.create_table("log_messages", + sa.Column("id", sa.Integer(), nullable=False), + sa.Column("component_build_id", sa.Integer(), nullable=True), + sa.Column("module_build_id", sa.Integer(), nullable=False), + sa.Column("message", sa.String(), nullable=False), + sa.ForeignKeyConstraint(["component_build_id"], ["component_builds.id"], ), + sa.ForeignKeyConstraint(["module_build_id"], ["module_builds.id"], ), + sa.PrimaryKeyConstraint("id"), + ) + + +def downgrade(): + op.drop_table("log_messages") diff --git a/module_build_service/models.py b/module_build_service/models.py index df1f849..84c572c 100644 --- a/module_build_service/models.py +++ b/module_build_service/models.py @@ -276,6 +276,7 @@ class ModuleBuild(MBSBase): "VirtualStream", secondary=module_builds_to_virtual_streams, back_populates="module_builds") reused_module_id = db.Column(db.Integer, db.ForeignKey("module_builds.id")) reused_module = db.relationship("ModuleBuild", remote_side="ModuleBuild.id") + log_messages = db.relationship("LogMessage", backref="module_build", lazy="dynamic") # List of arches against which the module is built. # NOTE: It is not filled for imported modules, because imported module builds have not been @@ -965,6 +966,17 @@ class ModuleBuild(MBSBase): return rv + def log_message(self, session, message): + log.info(message) + log_msg = LogMessage( + component_build_id=None, + module_build_id=self.id, + message=message, + time_created=datetime.utcnow(), + ) + session.add(log_msg) + session.commit() + def tasks(self, db_session): """ :return: dictionary containing the tasks associated with the build @@ -1176,6 +1188,7 @@ class ComponentBuild(MBSBase): module_id = db.Column(db.Integer, db.ForeignKey("module_builds.id"), nullable=False) module_build = db.relationship("ModuleBuild", backref="component_builds", lazy=False) reused_component_id = db.Column(db.Integer, db.ForeignKey("component_builds.id")) + log_messages = db.relationship("LogMessage", backref="component_build", lazy="dynamic") # Weight defines the complexity of the component build as calculated by the builder's # get_build_weights function @@ -1261,6 +1274,18 @@ class ComponentBuild(MBSBase): return json + def log_message(self, session, message): + log.info(message) + log_msg = LogMessage( + component_build_id=self.id, + module_build_id=self.module_id, + message=message, + time_created=datetime.utcnow(), + ) + + session.add(log_msg) + session.commit() + def __repr__(self): return "" % ( self.package, @@ -1311,6 +1336,36 @@ class ComponentBuildTrace(MBSBase): ) +class LogMessage(MBSBase): + __tablename__ = "log_messages" + id = db.Column(db.Integer, primary_key=True) + component_build_id = db.Column(db.Integer, db.ForeignKey("component_builds.id"), nullable=True) + module_build_id = db.Column(db.Integer, db.ForeignKey("module_builds.id"), nullable=False) + message = db.Column(db.String, nullable=False) + time_created = db.Column(db.DateTime, nullable=False) + + def json(self): + retval = { + "id": self.id, + "time_created": _utc_datetime_to_iso(self.time_created), + "message": self.message, + } + + return retval + + def __repr__(self): + return ( + "" + ) % ( + self.id, + self.component_build_id, + self.module_build_id, + self.message, + self.time_created, + ) + + def session_before_commit_handlers(session): # new and updated items for item in set(session.new) | set(session.dirty): diff --git a/module_build_service/utils/reuse.py b/module_build_service/utils/reuse.py index 4119bab..2d32567 100644 --- a/module_build_service/utils/reuse.py +++ b/module_build_service/utils/reuse.py @@ -252,12 +252,19 @@ def get_reusable_component( # If the rebuild strategy is "all", that means that nothing can be reused if module.rebuild_strategy == "all": - log.info('Cannot re-use the component because the rebuild strategy is "all".') + message = ("Cannot reuse the component {component_name} because the module " + "rebuild strategy is \"all\".").format( + component_name=component_name) + module.log_message(db_session, message) return None if not previous_module_build: previous_module_build = get_reusable_module(db_session, module) if not previous_module_build: + message = ("Cannot reuse because no previous build of " + "module {module_name} found!").format( + module_name=module.name) + module.log_message(db_session, message) return None if not mmd: @@ -275,7 +282,9 @@ def get_reusable_component( or not new_module_build_component.batch or not new_module_build_component.ref ): - log.info("Cannot re-use. New component not found in the db.") + message = ("Cannot reuse the component {} because it can't be found in the " + "database").format(component_name) + module.log_message(db_session, message) return None prev_module_build_component = models.ComponentBuild.from_component_name( @@ -289,13 +298,17 @@ def get_reusable_component( or not prev_module_build_component.batch or not prev_module_build_component.ref ): - log.info("Cannot re-use. Previous component not found in the db.") + message = ("Cannot reuse the component {} because a previous build of " + "it can't be found in the database").format(component_name) + new_module_build_component.log_message(db_session, message) return None # Make sure the ref for the component that is trying to be reused # hasn't changed since the last build if prev_module_build_component.ref != new_module_build_component.ref: - log.info("Cannot re-use. Component commit hashes do not match.") + message = ("Cannot reuse the component because the commit hash changed" + " since the last build") + new_module_build_component.log_message(db_session, message) return None # At this point we've determined that both module builds contain the component @@ -304,7 +317,9 @@ def get_reusable_component( # Make sure the batch number for the component that is trying to be reused # hasn't changed since the last build if prev_module_build_component.batch != new_module_build_component.batch: - log.info("Cannot re-use. Batch numbers do not match.") + message = ("Cannot reuse the component because it is being built in " + "a different batch than in the compatible module build") + new_module_build_component.log_message(db_session, message) return None # If the mmd.buildopts.macros.rpms changed, we cannot reuse @@ -321,7 +336,9 @@ def get_reusable_component( old_modulemd_macros = None if modulemd_macros != old_modulemd_macros: - log.info("Cannot re-use. Old modulemd macros do not match the new.") + message = ("Cannot reuse the component because the modulemd's macros are" + " different than those of the compatible module build") + new_module_build_component.log_message(db_session, message) return None # At this point we've determined that both module builds contain the component @@ -363,16 +380,22 @@ def get_reusable_component( # If the previous batches don't have the same ordering and hashes, then the # component can't be reused if previous_module_build_components != new_module_build_components: - log.info("Cannot re-use. Ordering or commit hashes of previous batches differ.") + message = ("Cannot reuse the component because a component in a previous" + " batch has been rebuilt") + new_module_build_component.log_message(db_session, message) return None for pkg_name in mmd.get_rpm_component_names(): pkg = mmd.get_rpm_component(pkg_name) if pkg_name not in old_mmd.get_rpm_component_names(): - log.info("Cannot re-use. Package lists are different.") + message = ("Cannot reuse the component because a component was added or " + "removed since the compatible module") + new_module_build_component.log_message(db_session, message) return None if set(pkg.get_arches()) != set(old_mmd.get_rpm_component(pkg_name).get_arches()): - log.info("Cannot re-use. Architectures are different for package: %s." % pkg_name) + message = ("Cannot reuse the component because the architectures for the package {}" + " have changed since the compatible module build").format(pkg_name) + new_module_build_component.log_message(db_session, message) return None reusable_component = db_session.query(models.ComponentBuild).filter_by( diff --git a/module_build_service/views.py b/module_build_service/views.py index 09d7a8e..ae73d35 100644 --- a/module_build_service/views.py +++ b/module_build_service/views.py @@ -85,6 +85,14 @@ api_routes = { "url": "/module-build-service//import-module/", "options": {"methods": ["POST"]}, }, + "log_messages_module_build": { + "url": "/module-build-service//module-builds//messages", + "options": {"methods": ["GET"], "defaults": {"model": models.ModuleBuild}}, + }, + "log_messages_component_build": { + "url": "/module-build-service//component-builds//messages", + "options": {"methods": ["GET"], "defaults": {"model": models.ComponentBuild}}, + }, } @@ -307,6 +315,30 @@ class ImportModuleAPI(MethodView): return jsonify(json_data), 201 +class LogMessageAPI(MethodView): + + @validate_api_version() + def get(self, api_version, id, model): + + if not model: + raise ValidationError("Model is not set for this log messages endpoint") + + query = model.query.filter_by(id=id).first().log_messages.order_by( + models.LogMessage.time_created.desc()) + + page = request.args.get("page", 1, type=int) + per_page = request.args.get("per_page", 10, type=int) + p_query = query.paginate(page, per_page, False) + + request_args = {"id": id} + json_data = {"meta": pagination_metadata(p_query, api_version, request_args)} + json_data["messages"] = [ + getattr(message, "json")() for message in p_query.items + ] + + return jsonify(json_data), 200 + + class BaseHandler(object): valid_params = set([ "branch", @@ -501,6 +533,7 @@ def register_api(): about_view = AboutAPI.as_view("about") rebuild_strategies_view = RebuildStrategies.as_view("rebuild_strategies") import_module = ImportModuleAPI.as_view("import_module") + log_message = LogMessageAPI.as_view("log_messages") for key, val in api_routes.items(): if key.startswith("component_build"): app.add_url_rule(val["url"], endpoint=key, view_func=component_view, **val["options"]) @@ -514,6 +547,8 @@ def register_api(): ) elif key == "import_module": app.add_url_rule(val["url"], endpoint=key, view_func=import_module, **val["options"]) + elif key.startswith("log_message"): + app.add_url_rule(val["url"], endpoint=key, view_func=log_message, **val["options"]) else: raise NotImplementedError("Unhandled api key.") diff --git a/tests/test_builder/test_koji.py b/tests/test_builder/test_koji.py index 76b8048..4d17d61 100644 --- a/tests/test_builder/test_koji.py +++ b/tests/test_builder/test_koji.py @@ -867,7 +867,8 @@ class TestKojiBuilder: ], ) current_module = module_build_service.models.ModuleBuild.get_by_id(db_session, 3) - rv = KojiModuleBuilder._get_filtered_rpms_on_self_dep(current_module, br_filtered_rpms) + with patch.object(module_build_service.models.ModuleBuild, 'log_message'): + rv = KojiModuleBuilder._get_filtered_rpms_on_self_dep(current_module, br_filtered_rpms) assert set(rv) == set(expected) session.assert_not_called() diff --git a/tests/test_views/test_views.py b/tests/test_views/test_views.py index 2161d9c..f4e8971 100644 --- a/tests/test_views/test_views.py +++ b/tests/test_views/test_views.py @@ -2741,3 +2741,39 @@ class TestViews: 'You cannot specify the parameter "reuse_components_from" when the "rebuild_strategy" ' 'parameter is set to "all"' ) + + +class TestLogMessageViews: + + def setup_method(self, test_method): + self.client = app.test_client() + init_data(2) + self.module_id = 2 + self.component_id = 1 + self.module_build = db.session.query(ModuleBuild).filter_by(id=self.module_id).first() + self.module_build.log_message(db.session, "Build-1 msg") + self.module_build.log_message(db.session, "Build-2 msg") + self.component_build = self.module_build.component_builds[0] + self.component_build.log_message(db.session, "Component-1 msg") + + def test_view_log_messages_for_module_builds(self): + url = "/module-build-service/1/module-builds/{module_id}/messages".format( + module_id=self.module_id) + res = self.client.get(url) + + json_res = str(res.data) + + assert "Build-1" in json_res + assert "Build-2" in json_res + assert "Component-1" in json_res + + def test_view_log_messages_for_component_builds(self): + url = "/module-build-service/1/component-builds/{component_id}/messages".format( + component_id=self.component_id) + res = self.client.get(url) + + json_res = str(res.data) + + assert "Build-1" not in json_res + assert "Build-2" not in json_res + assert "Component-1" in json_res