Merge #1340 Added an REST endpoint to display log messages

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")

module_build_service/models.py

@@ -279,6 +279,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
@@ -1002,6 +1003,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
@@ -1213,6 +1225,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
@@ -1298,6 +1311,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 "<ComponentBuild %s, %r, state: %r, task_id: %r, batch: %r, state_reason: %s>" % (
             self.package,
@@ -1348,6 +1373,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 (
+            "<LogMessage %s, component_build_id: %s, module_build_id: %r, message: %s,"
+            " time_created: %s>"
+        ) % (
+            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):

module_build_service/utils/reuse.py

@@ -269,12 +269,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:
@@ -292,7 +299,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(
@@ -306,13 +315,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
@@ -321,7 +334,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
@@ -338,7 +353,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
@@ -380,16 +397,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(

module_build_service/views.py

@@ -85,6 +85,14 @@ api_routes = {
         "url": "/module-build-service/<int:api_version>/import-module/",
         "options": {"methods": ["POST"]},
     },
+    "log_messages_module_build": {
+        "url": "/module-build-service/<int:api_version>/module-builds/<int:id>/messages",
+        "options": {"methods": ["GET"], "defaults": {"model": models.ModuleBuild}},
+    },
+    "log_messages_component_build": {
+        "url": "/module-build-service/<int:api_version>/component-builds/<int:id>/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.")
 

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()
 

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