#2209 frontend: start logging important events
Merged 2 years ago by frostyx. Opened 2 years ago by frostyx.
copr/ frostyx/copr ess-logging  into  main

@@ -146,7 +146,8 @@ 

  from coprs.error_handlers import get_error_handler

  import coprs.context_processors

  

- setup_log()

+ with app.app_context():

+     setup_log()

  

  app.register_blueprint(api_ns.api_ns)

  app.register_blueprint(apiv3_ns.apiv3_ns)

@@ -2,8 +2,6 @@ 

  A place for exception-handling logic

  """

  

- import logging

- 

  import flask

  from sqlalchemy.exc import SQLAlchemyError

  from werkzeug.exceptions import (
@@ -12,10 +10,9 @@ 

      HTTPException,

      NotFound,

  )

+ from coprs import app

  from coprs.exceptions import CoprHttpException

  

- LOG = logging.getLogger(__name__)

- 

  

  def get_error_handler():

      """
@@ -42,7 +39,7 @@ 

          message = self.message(error)

          headers = getattr(error, "headers", None)

          message = self.override_message(message, error)

-         LOG.error("Response error: %s %s", code, message)

+         app.logger.error("Response error: %s %s", code, message)

          return self.render(message, code), code, headers

  

      @staticmethod
@@ -102,10 +99,10 @@ 

  

      def _log_admin_only_exception(self):

          # pylint: disable=no-self-use

-         LOG.exception("Admin-only exception\nRequest: %s %s\nUser: %s\n",

-                       flask.request.method,

-                       flask.request.url,

-                       flask.g.user.name if flask.g.user else None)

+         app.logger.exception("Admin-only exception\nRequest: %s %s\nUser: %s\n",

+                              flask.request.method,

+                              flask.request.url,

+                              flask.g.user.name if flask.g.user else None)

  

  

  class UIErrorHandler(BaseErrorHandler):

@@ -258,3 +258,11 @@ 

      e.g. display 16,724 instead of 16724, it's more readable.

      """

      return format(int(number), ',d')

+ 

+ 

+ @app.template_global("being_server_admin")

+ def being_server_admin(user, copr):

+     """

+     Is Copr maintainer using their special permissions to edit the project?

+     """

+     return helpers.being_server_admin(user, copr)

@@ -891,3 +891,22 @@ 

          )

  

      return _response()

+ 

+ 

+ def being_server_admin(user, copr):

+     """

+     Is Copr maintainer using their special permissions to edit the project?

+     """

+     if not user:

+         return False

+ 

+     if not user.admin:

+         return False

+ 

+     if user == copr.user:

+         return False

+ 

+     if user.can_edit(copr, ignore_admin=True):

+         return False

+ 

+     return True

@@ -1,6 +1,7 @@ 

  import logging

  from logging import Formatter

  from logging.handlers import SMTPHandler, WatchedFileHandler

+ import flask

  

  from coprs import app

  
@@ -19,10 +20,36 @@ 

  

  default_formatter = Formatter(

      "%(asctime)s [%(levelname)s]"

-     "[%(pathname)s:%(lineno)d|%(module)s:%(funcName)s] %(message)s"

+     "[%(pathname)s:%(lineno)d|%(module)s:%(funcName)s][%(user)s] %(message)s"

  )

  

  

+ class FlaskUserFilter(logging.Filter):

+     """

+     Define `%(user)s` key for the formatter string

+     """

+ 

+     def filter(self, record):

+         record.user = self._user()

+         return True

nice

+ 

+     def _user(self):

+         if not flask.g or not hasattr(flask.g, "user"):

+             return "SERVER"

+ 

+         if flask.g.user:

+             return flask.g.user.name

+ 

+         return self._backend() or "ANON"

+ 

+     @staticmethod

+     def _backend():

+         auth = flask.request.authorization

+         if auth and auth.password == app.config["BACKEND_PASSWORD"]:

+             return "backend: {0}".format(flask.request.remote_addr)

+         return None

+ 

+ 

  def setup_log():

      if not app.debug:

          # Send critical message by email
@@ -44,6 +71,7 @@ 

      log_level_text = app.config.get("LOGGING_LEVEL", 'info')

      log_level = getattr(logging, log_level_text.upper())

      handler.setLevel(log_level)

+     app.logger.addFilter(FlaskUserFilter())

      app.logger.setLevel(log_level)

      app.logger.addHandler(handler)

  

@@ -311,6 +311,10 @@ 

          if not user.admin and not copr.auto_prune:

              raise exceptions.NonAdminCannotDisableAutoPrunning()

  

+         if helpers.being_server_admin(user, copr):

+             app.logger.info("Admin '%s' using their permissions to update "

+                             "project '%s' settings", user.name, copr.full_name)

It is unfortunate we don't know what exactly is happening. But better than nothing for sure!

+ 

          db.session.add(copr)

  

      @classmethod
@@ -444,6 +448,12 @@ 

              user, copr, "Only owners and admins may update"

                          " their projects permissions.")

  

+         app.logger.info("User '%s' authorized permission change for project '%s'"

+                         " - The '%s' user is now 'builder=%s', 'admin=%s'",

+                         user.name, copr.full_name, copr_permission.user.name,

+                         helpers.PermissionEnum(new_builder),

+                         helpers.PermissionEnum(new_admin))

+ 

          (models.CoprPermission.query

           .filter(models.CoprPermission.copr_id == copr.id)

           .filter(models.CoprPermission.user_id == copr_permission.user_id)
@@ -452,6 +462,13 @@ 

  

      @classmethod

      def update_permissions_by_applier(cls, user, copr, copr_permission, new_builder, new_admin):

+         app.logger.info("User '%s' requests 'builder=%s', 'admin=%s' "

+                         "permissions for project '%s'",

+                         user.name,

+                         helpers.PermissionEnum(new_builder),

+                         helpers.PermissionEnum(new_admin),

+                         copr.full_name)

+ 

          if copr_permission:

              # preserve approved permissions if set

              if (not new_builder or
@@ -502,6 +519,11 @@ 

  

          cls.validate_permission(user, copr, permission, state)

  

+         app.logger.info("User '%s' authorized permission change for project '%s'"

+                         " - The '%s' user is now '%s=%s'",

+                         request_user.name, copr.full_name, user.name,

+                         permission, state)

+ 

          perm_o = models.CoprPermission(user_id=user.id, copr_id=copr.id)

          perm_o = db.session.merge(perm_o)

          old_state = perm_o.get_permission(permission)
@@ -525,6 +547,9 @@ 

                               "expected True or False".format(permission,

                                   req_bool))

  

+         app.logger.info("User '%s' requests '%s=%s' permission for project '%s'",

+                         user.name, permission, state, copr.full_name)

+ 

          cls.validate_permission(user, copr, permission, state)

          perm_o = models.CoprPermission(user_id=user.id, copr_id=copr.id)

          perm_o = db.session.merge(perm_o)
@@ -919,6 +944,10 @@ 

              user, copr_chroot.copr,

              "Only owners and admins may update their projects.")

  

+         if helpers.being_server_admin(user, copr_chroot.copr):

+             app.logger.info("Admin '%s' using their permissions to update "

+                             "chroot '%s'", user.name, copr_chroot.full_name)

+ 

          cls._update_chroot(buildroot_pkgs, repos, comps, comps_name,

                             copr_chroot, with_opts, without_opts, delete_after, delete_notify, module_toggle,

                             bootstrap, bootstrap_image, isolation)

@@ -328,3 +328,16 @@ 

                      builds[build].append(build_chroot)

                  break

          return builds

+ 

+ 

+     @classmethod

+     def log_being_admin(cls, user, package):

+         """

+         Log if a package is being updated by a Copr maintainer

+         """

+         if helpers.being_server_admin(user, package.copr):

+             app.logger.info("Admin '%s' using their permissions to update "

+                             "package '%s' in project '%s'",

+                             user.name,

+                             package.name,

+                             package.copr.full_name)

@@ -14,6 +14,7 @@ 

  

      @classmethod

      def get(cls, username):

+         app.logger.info("Querying user '%s' by username", username)

          return User.query.filter(User.username == username)

  

      @classmethod
@@ -40,6 +41,9 @@ 

          if not user.can_edit(copr):

              raise exceptions.InsufficientRightsException(message)

  

+         app.logger.info("User '%s' allowed to update project '%s'",

+                         user.name, copr.full_name)

+ 

      @classmethod

      def raise_if_cant_build_in_copr(cls, user, copr, message):

          """
@@ -50,6 +54,9 @@ 

          if not user.can_build_in(copr):

              raise exceptions.InsufficientRightsException(message)

  

+         app.logger.info("User '%s' allowed to build in project '%s'",

+                         user.name, copr.full_name)

+ 

      @classmethod

      def raise_if_not_in_group(cls, user, group):

          if not user.admin and group.fas_name not in user.user_teams:
@@ -57,6 +64,9 @@ 

                  "User '{}' doesn't have access to the copr group '{}' (fas_name='{}')"

                  .format(user.username, group.name, group.fas_name))

  

+         app.logger.info("User '%s' allowed to access group '%s' (fas_name='%s')",

+                         user.name, group.name, group.fas_name)

+ 

      @classmethod

      def get_group_by_alias(cls, name):

          return Group.query.filter(Group.name == name)
@@ -130,6 +140,7 @@ 

                  "openid_groups": None}

          for k, v in null.items():

              setattr(user, k, v)

+         app.logger.info("Deleting user '%s' data", user.name)

  

      @classmethod

      def create_user_wrapper(cls, username, email, timezone=None):
@@ -149,6 +160,7 @@ 

                      api_token=generate_api_token(

                          app.config["API_TOKEN_LENGTH"]),

                      api_token_expiration=expiration_date_token)

+         app.logger.info("Creating user '%s <%s>'", user.name, user.mail)

          return user

  

  
@@ -157,6 +169,7 @@ 

          self.user = user

  

      def dumps(self, pretty=False):

+         app.logger.info("Dumping all user data for '%s'", self.user.name)

          if pretty:

              return json.dumps(self.data, indent=2)

          return json.dumps(self.data)

@@ -162,13 +162,20 @@ 

          else:

              return False

  

-     def can_edit(self, copr):

+     def can_edit(self, copr, ignore_admin=False):

          """

          Determine if this user can edit the given copr.

          """

+         # People can obviously edit their personal projects, but the person who

+         # created a group project doesn't get any exclusive permissions to it.

+         # We still need to validate their group membership every time.

+         if not copr.group and copr.user == self:

+             return True

  

-         if copr.user == self or self.admin:

+         # Copr maintainers can edit every project

+         if not ignore_admin and self.admin:

              return True

+ 

          if (self.permissions_for_copr(copr) and

                  self.permissions_for_copr(copr).copr_admin ==

                  helpers.PermissionEnum("approved")):

@@ -2,7 +2,6 @@ 

  import base64

  import datetime

  import functools

- from logging import getLogger

  

  from flask import url_for

  import flask
@@ -18,8 +17,6 @@ 

  from .util import mm_serialize_one

  from coprs import app

  

- log = getLogger(__name__)

- 

  

  def render_copr_chroot(chroot):

      return {
@@ -93,7 +90,7 @@ 

                  userstring = base64.b64decode(base64string)

                  (api_login, token) = userstring.decode("utf-8").split(":")

          except Exception:

-             log.exception("Failed to get auth token from headers")

+             app.logger.exception("Failed to get auth token from headers")

              api_login = token = None

  

          token_auth = False

@@ -1,5 +1,3 @@ 

- from logging import getLogger

- 

  import flask

  from flask import url_for, make_response

  from flask_restful import Resource
@@ -18,8 +16,6 @@ 

  from ..exceptions import ObjectAlreadyExists, CannotProcessRequest, AccessForbidden

  from ..util import mm_deserialize, get_request_parser, arg_bool

  

- log = getLogger(__name__)

- 

  

  class ProjectListR(Resource):

  

@@ -1,9 +1,5 @@ 

  # coding: utf-8

  

- import logging

- 

- log = logging.getLogger(__name__)

- 

  import flask

  from flask import url_for, make_response

  from flask_restful import Resource

@@ -674,12 +674,11 @@ 

  

  

  {% macro warn_server_admin(copr) %}

-   {% if g.user and g.user.admin and g.user != copr.user %}

-     {% if not g.user.permissions_for_copr(copr) or g.user.permissions_for_copr(copr).copr_admin < 2 %}

-       {% set msg = "As a maintainer of this Copr instance, you have permissions to modify this project,

-                     but if you are acting as a regular user now, be aware that this is not your project." %}

-       {{ alert(msg, type="warning") }}

-     {% endif %}

+   {% if being_server_admin(g.user, copr) %}

+     {% set msg = "As a maintainer of this Copr instance, you have permissions "

+                   "to modify this project, but if you are acting as a regular "

+                   "user now, be aware that this is not your project." %}

+     {{ alert(msg, type="warning") }}

    {% endif %}

  {% endmacro %}

  

@@ -268,6 +268,7 @@ 

          if "chroot_denylist" in formdata:

              package.chroot_denylist_raw = form.chroot_denylist.data

  

+         PackagesLogic.log_being_admin(flask.g.user, package)

          db.session.add(package)

          db.session.commit()

      else:

@@ -16,10 +16,6 @@ 

  from coprs.views.backend_ns import backend_ns

  from sqlalchemy.sql import false, true

  

- import logging

- 

- log = logging.getLogger(__name__)

- 

  

  @backend_ns.after_request

  def send_frontend_version(response):
@@ -308,14 +304,14 @@ 

      def _stream():

          args = {"data_type": "for_backend"}

  

-         log.info("Generating SRPM builds")

+         app.logger.info("Generating SRPM builds")

          for build in BuildsLogic.get_pending_srpm_build_tasks(**args):

              if not build_ready(build):

                  continue

              record = get_srpm_build_record(build, for_backend=True)

              yield record

  

-         log.info("Generating RPM builds")

+         app.logger.info("Generating RPM builds")

          for build_chroot in BuildsLogic.get_pending_build_tasks(**args):

              if not build_ready(build_chroot.build):

                  continue
@@ -432,7 +428,7 @@ 

  

      if task_id == build.task_id:

          if build.source_status in run_statuses:

-             log.info("rescheduling source build %s", build.id)

+             app.logger.info("rescheduling source build %s", build.id)

              BuildsLogic.update_state_from_dict(build, {

                  "task_id": task_id,

                  "status": StatusEnum("pending")
@@ -445,7 +441,8 @@ 

      else:

          build_chroot = build.chroots_dict_by_name.get(chroot)

          if build_chroot and build_chroot.status in run_statuses:

-             log.info("rescheduling build {} chroot: {}".format(build.id, build_chroot.name))

+             app.logger.info("rescheduling build {} chroot: {}"

+                             .format(build.id, build_chroot.name))

              BuildsLogic.update_state_from_dict(build, {

                  "task_id": task_id,

                  "chroot": chroot,

@@ -244,7 +244,7 @@ 

  

      if "reset" in flask.request.form:

          try:

-             package = PackagesLogic.get(copr.main_dir.id, package_name)[0]

+             package = PackagesLogic.get(copr.id, package_name)[0]

          except IndexError:

              flask.flash("Package {0} does not exist in copr_dir {1}."

                          .format(package_name, copr.main_dir.full_name))
@@ -263,7 +263,7 @@ 

      if form.validate_on_submit():

          try:

              if package_name:

-                 package = PackagesLogic.get(copr.main_dir.id, package_name)[0]

+                 package = PackagesLogic.get(copr.id, package_name)[0]

              else:

                  package = PackagesLogic.add(flask.app.g.user, copr, form.package_name.data)

  
@@ -273,6 +273,7 @@ 

              package.chroot_denylist_raw = form.chroot_denylist.data

              package.max_builds = form.max_builds.data

  

+             PackagesLogic.log_being_admin(flask.g.user, package)

              db.session.add(package)

              db.session.commit()

          except (InsufficientRightsException, IndexError) as e:

@@ -126,6 +126,8 @@ 

          user = models.User.query.filter(

              models.User.username == username).first()

          if not user:  # create if not created already

+             app.logger.info("First login for user '%s', "

+                             "creating a database record", username)

              user = UsersLogic.create_user_wrapper(username, resp.email,

                                                    resp.timezone)

          else:
@@ -140,6 +142,10 @@ 

          flask.flash(u"Welcome, {0}".format(user.name), "success")

          flask.g.user = user

  

+         app.logger.info("%s '%s' logged in",

+                         "Admin" if user.admin else "User",

+                         user.name)

+ 

          if flask.request.url_root == oid.get_next_url():

              return flask.redirect(flask.url_for("coprs_ns.coprs_by_user",

                                                  username=user.name))
@@ -151,6 +157,8 @@ 

  

  @misc.route("/logout/")

  def logout():

+     if flask.g.user:

+         app.logger.info("User '%s' logging out", flask.g.user.name)

      flask.session.pop("openid", None)

      flask.session.pop("krb5_login", None)

      flask.flash(u"You were signed out")
@@ -182,6 +190,9 @@ 

              url = 'https://' + app.config["PUBLIC_COPR_HOSTNAME"]

              url = helpers.fix_protocol_for_frontend(url)

  

+             msg = "Attempting to use invalid or expired API login '%s'"

+             app.logger.info(msg, api_login)

+ 

              output = {

                  "output": "notok",

                  "error": "Login invalid/expired. Please visit {0}/api to get or renew your API token.".format(url),

@@ -4,10 +4,6 @@ 

  from coprs.logic import builds_logic

  from coprs.views.misc import login_required

  

- import logging

- 

- log = logging.getLogger(__name__)

- 

  

  @recent_ns.route("/")

  @recent_ns.route("/all/")

@@ -4,7 +4,6 @@ 

  import pprint

  import sys

  import os

- import logging

  import requests

  import re

  import munch
@@ -27,8 +26,7 @@ 

      helpers.BuildSourceEnum("distgit"),

  ]

  

- log = logging.getLogger(__name__)

- log.setLevel(logging.DEBUG)

+ log = app.logger

  

  TOPICS = {}

  for topic, url in app.config["PAGURE_EVENTS"].items():

@@ -9,7 +9,8 @@ 

  from coprs.helpers import parse_package_name, generate_repo_url, \

      fix_protocol_for_frontend, fix_protocol_for_backend, pre_process_repo_url, \

      parse_repo_params, pagure_html_diff_changed, SubdirMatch, \

-     raw_commit_changes, WorkList, pluralize, clone_sqlalchemy_instance

+     raw_commit_changes, WorkList, pluralize, clone_sqlalchemy_instance, \

+     being_server_admin

  

  from tests.coprs_test_case import CoprsTestCase

  
@@ -261,6 +262,20 @@ 

          assert "fedora-17-x86_64" in \

                  [m.name for m in target_copr.mock_chroots]

  

+     @pytest.mark.usefixtures("f_users", "f_fas_groups", "f_coprs",

+                              "f_group_copr", "f_db")

+     def test_being_server_admin(self):

+         assert self.u1.admin

+ 

+         assert not being_server_admin(self.u1, self.c1)

+         assert being_server_admin(self.u1, self.c2)

+ 

+         self.gc1.user = self.u2

+         assert not being_server_admin(self.u1, self.gc1)

+ 

+         self.u1.openid_groups["fas_groups"] = []

+         assert being_server_admin(self.u1, self.gc1)

+ 

  

  def test_worklist_class():

      """ test that all tasks are processed only once """

@@ -0,0 +1,261 @@ 

+ # pylint: disable=cyclic-import

+ # pylint: disable=no-self-use

+ 

+ from unittest import TestCase

+ from unittest.mock import patch, MagicMock

+ import pytest

+ import flask

+ from munch import Munch

+ from tests.coprs_test_case import CoprsTestCase, TransactionDecorator

+ from coprs import app, db, models, helpers

+ from coprs.views.misc import create_or_login, logout

+ 

+ from coprs.logic.users_logic import UsersLogic, UserDataDumper

+ from coprs.logic.coprs_logic import (

+     CoprsLogic,

+     CoprPermissionsLogic,

+     CoprChrootsLogic,

+ )

+ 

+ 

+ class TestLoggingRequestUser(CoprsTestCase, TestCase):

+ 

+     @pytest.mark.usefixtures("f_users", "f_coprs", "f_db")

+     def test_server(self):

+         with self.assertLogs(app.logger) as cm:

+             app.logger.info("FOO")

+             assert cm.records[0].user == "SERVER"

+ 

+     @pytest.mark.usefixtures("f_u1_ts_client", "f_users", "f_coprs", "f_db")

+     def test_user(self):

+         with self.assertLogs(app.logger) as cm:

+             self.api3.modify_project(self.c2.name, self.c2.owner_name)

+             assert cm.records[0].user == "user1"

+ 

+     @pytest.mark.usefixtures("f_users", "f_coprs", "f_db")

+     def test_anon(self):

+         with self.assertLogs(app.logger) as cm:

+             self.tc.get("/coprs/user2", follow_redirects=True)

+             assert cm.records[0].user == "ANON"

+ 

+ 

+ class TestLoggingUsersLogic(CoprsTestCase):

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_db")

+     def test_user_get(self, log):

+         UsersLogic.get("somebody")

+         log.info.assert_called_once_with(

+             "Querying user '%s' by username", "somebody")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_coprs", "f_db")

+     def test_raise_if_cant_update_copr(self, log):

+         UsersLogic.raise_if_cant_update_copr(self.u2, self.c2, None)

+         log.info.assert_called_once_with(

+             "User '%s' allowed to update project '%s'",

+             "user2", "user2/foocopr")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_coprs", "f_db")

+     def test_raise_if_cant_build_in_copr(self, log):

+         UsersLogic.raise_if_cant_build_in_copr(self.u2, self.c2, None)

+         log.info.assert_called_once_with(

+             "User '%s' allowed to build in project '%s'",

+             "user2", "user2/foocopr")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_coprs", "f_groups", "f_db")

+     def test_raise_if_not_in_group(self, log):

+         UsersLogic.raise_if_not_in_group(self.u1, self.g1)

+         log.info.assert_called_once_with(

+             "User '%s' allowed to access group '%s' (fas_name='%s')",

+             "user1", "group1", "fas_1")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_db")

+     def test_delete_user_data(self, log):

+         UsersLogic.delete_user_data(self.u2)

+         log.info.assert_called_once_with("Deleting user '%s' data", "user2")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_db")

+     def test_create_user_wrapper(self, log):

+         UsersLogic.create_user_wrapper("somebody", "somebody@example.test")

+         log.info.assert_called_once_with("Creating user '%s <%s>'",

+                                          "somebody", "somebody@example.test")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_db")

+     def test_user_data_dumper(self, log):

+         dumper = UserDataDumper(self.u2)

+         dumper.dumps()

+         log.info.assert_called_once_with("Dumping all user data for '%s'",

+                                          "user2")

+ 

+ 

+ class TestLoggingUserGeneral(CoprsTestCase):

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @TransactionDecorator("u2")

+     @pytest.mark.usefixtures("f_users", "f_db")

+     def test_delete_user_data(self, log):

+         self.tc.get("/user/info/download")

+         log.info.assert_called_once_with("Dumping all user data for '%s'",

+                                          "user2")

+ 

+ 

+ class TestLoggingCoprPermissionsLogic(CoprsTestCase):

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_coprs", "f_copr_permissions", "f_db")

+     def test_update_permissions(self, log):

+         perm = models.CoprPermission(

+             copr=self.c2,

+             user=self.u3,

+             copr_builder=helpers.PermissionEnum("request"),

+             copr_admin=helpers.PermissionEnum("request"))

+ 

+         CoprPermissionsLogic.update_permissions(

+             self.u2, self.c2, perm,

+             new_builder=helpers.PermissionEnum("approved"),

+             new_admin=helpers.PermissionEnum("nothing"))

+ 

+         log.info.assert_called_with(

+             "User '%s' authorized permission change for project '%s'"

+             " - The '%s' user is now 'builder=%s', 'admin=%s'",

+             "user2", "user2/foocopr", "user3", "approved", "nothing")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_coprs", "f_copr_permissions", "f_db")

+     def test_update_permissions_by_applier(self, log):

+         CoprPermissionsLogic.update_permissions_by_applier(

+             self.u2, self.c2, None,

+             new_builder=helpers.PermissionEnum("request"),

+             new_admin=helpers.PermissionEnum("nothing"))

+ 

+         msg = ("User '%s' requests 'builder=%s', 'admin=%s' "

+                "permissions for project '%s'")

+         log.info.assert_called_once_with(

+             msg, "user2", "request", "nothing", "user2/foocopr")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_coprs", "f_copr_permissions", "f_db")

+     def test_set_permissions(self, log):

+         CoprPermissionsLogic.set_permissions(

+             self.u2, self.c2, self.u3, "builder", "approved")

+         log.info.assert_called_with(

+             "User '%s' authorized permission change for project '%s'"

+             " - The '%s' user is now '%s=%s'",

+             "user2", "user2/foocopr", "user3", "builder", "approved")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_coprs", "f_db")

+     def test_request_permission(self, log):

+         CoprPermissionsLogic.request_permission(

+             self.c1, self.u2, "builder", True)

+         log.info.assert_called_once_with(

+             "User '%s' requests '%s=%s' permission for project '%s'",

+             "user2", "builder", "request", "user1/foocopr")

+ 

+ 

+ class TestLoggingAuth(CoprsTestCase):

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_db")

+     def test_create_or_login(self, log):

+         resp = Munch({

+             "identity_url": 'http://somebody.id.fedoraproject.org/',

+             "email": "somebody@example.com",

+             "timezone": "UTC",

+             "extensions": {},

+         })

+ 

+         # Log in as user

+         with app.test_request_context():

+             create_or_login(resp)

+ 

+         log.info.assert_any_call("First login for user '%s', creating "

+                                  "a database record", "somebody")

+         log.info.assert_called_with("%s '%s' logged in", "User", "somebody")

+ 

+         # Modify user to be an admin

+         user = models.User.query.filter_by(username="somebody").one()

+         user.admin = True

+         db.session.commit()

+ 

+         # Log in as admin

+         with app.test_request_context():

+             create_or_login(resp)

+ 

+         log.info.assert_called_with("%s '%s' logged in", "Admin", "somebody")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_db")

+     def test_logout(self, log):

+         with app.test_request_context():

+             flask.g.user = self.u2

+             logout()

+         log.info.assert_called_with("User '%s' logging out", "user2")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_mock_chroots", "f_db")

+     def test_api_login_required_invalid(self, log):

+         headers = self.api3_auth_headers(self.u2)

+         self.tc.post("/api_3/project/add/user2", headers=headers)

+ 

+         log.info.assert_called_once_with(

+             "Attempting to use invalid or expired API login '%s'", "abc")

+ 

+ 

+ class TestLoggingUsingAdminPermissions(CoprsTestCase):

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_coprs", "f_db")

+     def test_update_copr(self, log):

+         CoprsLogic.update(self.u1, self.c2)

+         log.info.assert_called_with(

+             "Admin '%s' using their permissions to update project '%s' settings",

+             "user1", "user2/foocopr")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_coprs", "f_mock_chroots", "f_db")

+     def test_update_copr_chroot(self, log):

+         CoprChrootsLogic.update_chroot(self.u1, self.c2.copr_chroots[0])

+         log.info.assert_called_with(

+             "Admin '%s' using their permissions to update chroot '%s'",

+             "user1", "user2/foocopr/fedora-17-x86_64")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_u1_ts_client", "f_coprs", "f_builds", "f_db")

+     def test_update_package_webui(self, log):

+         url = "/coprs/{0}/package/{1}/edit/scm".format(

+             self.c2.full_name, self.p2.name)

+ 

+         data = {

+             "clone_url": "https://gitlab.com/zhanggyb/nerd-fonts.git",

+             "package_name": self.p2.name,

+         }

+ 

+         self.tc.post(url, headers=self.auth_header, data=data)

+         log.info.assert_called_with(

+             "Admin '%s' using their permissions to update "

+             "package '%s' in project '%s'",

+             "user1", "whatsupthere-world", "user2/foocopr")

+ 

+     @patch("coprs.app.logger", return_value=MagicMock())

+     @pytest.mark.usefixtures("f_users", "f_u1_ts_client", "f_coprs", "f_builds", "f_db")

+     def test_update_package_apiv3(self, log):

+         url = "/api_3/package/edit/{0}/{1}/scm".format(

+             self.c2.full_name, self.p2.name)

+ 

+         data = {

+             "clone_url": "https://gitlab.com/zhanggyb/nerd-fonts.git",

+             "package_name": self.p2.name,

+         }

+ 

+         self.post_api3_with_auth(url, data, self.u1)

+         log.info.assert_called_with(

+             "Admin '%s' using their permissions to update "

+             "package '%s' in project '%s'",

+             "user1", "whatsupthere-world", "user2/foocopr")

Such as user management, permission management, logging, etc.

Metadata Update from @frostyx:
- Pull-request tagged with: wip

2 years ago

Of course, many more events need to be logged. I am just putting this here, so you can review if this is how we want to do it.

Build failed. More information on how to proceed and troubleshoot errors available at https://fedoraproject.org/wiki/Zuul-based-ci

I think we need to dump who is granting user.name to update the copr

Of course, many more events need to be logged.

Yeah, it would be nice to have some document with steps that need to be done.

I like this PR, but I think we should concentrate on "who is doing the changes", so
we can retrospectively find the attacker (or the attacked account). Perhaps we
could do some upper level hack in the logger? Like if flask.g.user is defined,
add a prefix f"{flask.g.user}'s action: "?

2 new commits added

  • wip
  • wip
2 years ago

Build failed. More information on how to proceed and troubleshoot errors available at https://fedoraproject.org/wiki/Zuul-based-ci

2 new commits added

  • wip
  • frontend: change logging formatter to show also flask.g.user
2 years ago

Build failed. More information on how to proceed and troubleshoot errors available at https://fedoraproject.org/wiki/Zuul-based-ci

1 new commit added

  • frontend: use logger from coprs.app instead of creating new ones
2 years ago

Build failed. More information on how to proceed and troubleshoot errors available at https://fedoraproject.org/wiki/Zuul-based-ci

5 new commits added

  • wip
  • frontend: don't use main_dir for getting packages
  • wip
  • frontend: move the logic about admin using his permissions from templates
  • log backend IP
2 years ago

Build failed. More information on how to proceed and troubleshoot errors available at https://fedoraproject.org/wiki/Zuul-based-ci

rebased onto b7cedd1d89b82e0f03612ee6d1afc72f35979cb1

2 years ago

Build failed. More information on how to proceed and troubleshoot errors available at https://fedoraproject.org/wiki/Zuul-based-ci

5 new commits added

  • frontend: start logging important events
  • frontend: use logger from coprs.app instead of creating new ones
  • frontend: change logging formatter to show also flask.g.user
  • frontend: don't use main_dir for getting packages
  • frontend: move the logic about admin using his permissions from templates
2 years ago

Build failed. More information on how to proceed and troubleshoot errors available at https://fedoraproject.org/wiki/Zuul-based-ci

PTAL,
The Zuul fails only because of a cyclic import coming from test_logging.py. I am intentionally testing many different things (hence many imports) inside that one file and there is one

coprs_frontend/tests/test_logging.py:1: R0401[cyclic-import]: Cyclic import (coprs.logic.coprs_logic -> coprs.logic.users_logic)

For some reason # pylint: disable=cyclic-import doesn't ignore it. If you think it should be fixed, I could create a tests/logging/ directory and split the test into multiple files.

Metadata Update from @frostyx:
- Pull-request untagged with: wip

2 years ago

Hm, sounds dangerous, at least for group projects.. Consider the original creator of the project leaves the team, so we remove the permissions for him in that project, but he is still the copr.user.

It is unfortunate we don't know what exactly is happening. But better than nothing for sure!

That's true, I will constrain the condition, only for non-group projects

But FTR, I don't think this is a new bug because the original line was if copr.user == self or self.admin:

rebased onto 6c65133b09f7086638318601e2150347b0ce4a2e

2 years ago

Build failed. More information on how to proceed and troubleshoot errors available at https://fedoraproject.org/wiki/Zuul-based-ci

Can you please drop here a small comment, just to inform any future reader (fuse against removal, I would swear we did something like this before).

rebased onto d461a91bb891ea22f4556e64af3484d8daacb3c5

2 years ago

Build succeeded.

rebased onto ff007d2

2 years ago

Pull-Request has been merged by frostyx

2 years ago

Build succeeded.

Metadata