Commit b73de8b Improve the logging situation

9 files Authored and Committed by pingou 7 months ago
Improve the logging situation

Place a logging configuration dictionary in pagure's configuration file,
use module specific logger and drop the use of the logger object shared
between modules.

Signed-off-by: Pierre-Yves Chibon <pingou@pingoured.fr>

    
 1 @@ -18,6 +18,7 @@
 2   
 3   import datetime  # noqa: E402
 4   import logging  # noqa: E402
 5 + import logging.config  # noqa: E402
 6   import os  # noqa: E402
 7   import re  # noqa: E402
 8   import urlparse  # noqa: E402
 9 @@ -38,7 +39,7 @@
10   import pagure.exceptions  # noqa: E402
11   
12   # Create the application.
13 - APP = MultiStaticFlask(__name__)
14 + APP = MultiStaticFlask('pagure')
15   
16   if perfrepo:
17       # Do this as early as possible.
18 @@ -55,6 +56,8 @@
19   if 'PAGURE_CONFIG' in os.environ:
20       APP.config.from_envvar('PAGURE_CONFIG')
21   
22 + logging.config.dictConfig(APP.config.get('LOGGING') or {'version': 1})
23 + 
24   
25   if APP.config.get('THEME_TEMPLATE_FOLDER', False):
26       # Jinja can be told to look for templates in different folders
27 @@ -145,7 +148,7 @@
28                               is_admin=is_admin(),
29                           )
30                       except pagure.exceptions.PagureException as err:
31 -                         LOG.debug(err)
32 +                         APP.logger.debug(err)
33                   # Remove the old groups
34                   for group in groups - fas_groups:
35                       try:
36 @@ -158,13 +161,12 @@
37                               force=True,
38                           )
39                       except pagure.exceptions.PagureException as err:
40 -                         LOG.debug(err)
41 +                         APP.logger.debug(err)
42   
43               SESSION.commit()
44           except SQLAlchemyError as err:
45               SESSION.rollback()
46 -             LOG.debug(err)
47 -             LOG.exception(err)
48 +             APP.logger.exception(err)
49               flask.flash(
50                   'Could not set up you as a user properly, please contact '
51                   'an admin', 'error')
52 @@ -197,14 +199,6 @@
53           from_email=APP.config.get('FROM_EMAIL', 'pagure@fedoraproject.org')
54       ))
55   
56 - # Send classic logs into syslog
57 - SHANDLER = logging.StreamHandler()
58 - SHANDLER.setLevel(APP.config.get('LOG_LEVEL', 'INFO'))
59 - APP.logger.addHandler(SHANDLER)
60 - 
61 - LOG = APP.logger
62 - LOG.setLevel(APP.config.get('LOG_LEVEL', 'INFO'))
63 - pagure.lib.set_log(LOG)
64   
65   APP.wsgi_app = pagure.proxy.ReverseProxied(APP.wsgi_app)
66   
67 @@ -689,7 +683,7 @@
68               pygit2.clone_repository(
69                   remote_git, repopath, checkout_branch=branch_from)
70           except Exception as err:
71 -             LOG.exception(err)
72 +             APP.logger.exception(err)
73               flask.abort(
74                   500,
75                   'The following error was raised when trying to clone the '
76 @@ -700,16 +694,17 @@
77           try:
78               repo.pull(branch=branch_from, force=True)
79           except pygit2.GitError as err:
80 -             LOG.debug('Error pull the repo: %s -- error: %s' % (repopath, err))
81 +             APP.logger.debug(
82 +                 'Error pull the repo: %s -- error: %s' % (repopath, err))
83               if str(err).lower() != 'no content-type header in response':
84 -                 LOG.exception(err)
85 +                 APP.logger.exception(err)
86                   flask.abort(
87                       500,
88                       'The following error was raised when trying to pull the '
89                       'changes from the remote: %s' % str(err)
90                   )
91           except pagure.exceptions.PagureException as err:
92 -             LOG.exception(err)
93 +             APP.logger.exception(err)
94               flask.abort(500, str(err))
95   
96       return repopath
 1 @@ -258,3 +258,45 @@
 2   EXCLUDE_GROUP_INDEX = []
 3   
 4   TRIGGER_CI = ['pretty please pagure-ci rebuild']
 5 + 
 6 + 
 7 + LOGGING = {
 8 +     'version': 1,
 9 +     'disable_existing_loggers': False,
10 +     'formatters': {
11 +         'standard': {
12 +             'format': '%(asctime)s [%(levelname)s] %(name)s: %(message)s'
13 +         },
14 +     },
15 +     'handlers': {
16 +         'console': {
17 +             'level': 'INFO',
18 +             'formatter': 'standard',
19 +             'class': 'logging.StreamHandler',
20 +             'stream': 'ext://sys.stdout',
21 +         },
22 +     },
23 +     # The root logger configuration; this is a catch-all configuration
24 +     # that applies to all log messages not handled by a different logger
25 +     'root': {
26 +         'level': 'INFO',
27 +         'handlers': ['console'],
28 +     },
29 +     'loggers': {
30 +         'pagure': {
31 +             'handlers': ['console'],
32 +             'level': 'INFO',
33 +             'propagate': False
34 +         },
35 +         'flask': {
36 +             'handlers': ['console'],
37 +             'level': 'INFO',
38 +             'propagate': False
39 +         },
40 +         'sqlalchemy': {
41 +             'handlers': ['console'],
42 +             'level': 'WARN',
43 +             'propagate': False
44 +         },
45 +     }
46 + }
 1 @@ -22,6 +22,7 @@
 2       import json
 3   
 4   import datetime
 5 + import logging
 6   import markdown
 7   import os
 8   import shutil
 9 @@ -56,7 +57,7 @@
10   
11   REDIS = None
12   PAGURE_CI = None
13 - LOG = None
14 + _log = logging.getLogger(__name__)
15   
16   
17   def set_redis(host, port, dbname):
18 @@ -72,12 +73,6 @@
19       PAGURE_CI = services
20   
21   
22 - def set_log(logger):
23 -     """ Set a logger that can be used in this module. """
24 -     global LOG
25 -     LOG = logger
26 - 
27 - 
28   def get_user(session, key):
29       """ Searches for a user in the database for a given username or email.
30       """
31 @@ -3400,7 +3395,7 @@
32           try:
33               text = md_processor.convert(text)
34           except Exception:
35 -             LOG.debug(
36 +             _log.debug(
37                   'A markdown error occured while processing: ``%s``',
38                   str(text))
39           return clean_input(text)
  1 @@ -17,6 +17,7 @@
  2   import datetime
  3   import hashlib
  4   import json
  5 + import logging
  6   import os
  7   import shutil
  8   import subprocess
  9 @@ -36,6 +37,9 @@
 10   from pagure.lib.repo import PagureRepo
 11   
 12   
 13 + _log = logging.getLogger(__name__)
 14 + 
 15 + 
 16   def commit_to_patch(repo_obj, commits):
 17       ''' For a given commit (PyGit2 commit object) of a specified git repo,
 18       returns a string representation of the changes the commit did in a
 19 @@ -88,6 +92,7 @@
 20       ''' Generate the configuration file for gitolite for all projects
 21       on the forge.
 22       '''
 23 +     _log.info('Write down the gitolite configuration file')
 24       global_pr_only = pagure.APP.config.get('PR_ONLY', False)
 25       config = []
 26       groups = {}
 27 @@ -97,6 +102,7 @@
 28           model.Project.id
 29       )
 30       for project in query.all():
 31 +         _log.debug('    Processing project: %s', project.fullname)
 32           for group in project.committer_groups:
 33               if group.group_name not in groups:
 34                   groups[group.group_name] = [
 35 @@ -154,6 +160,7 @@
 36       """ Return the gitolite command to run based on the info in the
 37       configuration file.
 38       """
 39 +     _log.info('Compiling the gitolite configuration')
 40       gitolite_folder = pagure.APP.config.get('GITOLITE_HOME', None)
 41       gitolite_version = pagure.APP.config.get('GITOLITE_VERSION', 3)
 42       if gitolite_folder:
 43 @@ -172,12 +179,14 @@
 44               raise pagure.exceptions.PagureException(
 45                   'Non-supported gitolite version "%s"' % gitolite_version
 46               )
 47 +         _log.debug('Command: %s', cmd)
 48           return cmd
 49   
 50   
 51   def generate_gitolite_acls():
 52       """ Generate the gitolite configuration file for all repos
 53       """
 54 +     _log.info('Refresh gitolite configuration')
 55       pagure.lib.git.write_gitolite_acls(
 56           pagure.SESSION, pagure.APP.config['GITOLITE_CONFIG'])
 57   
 58 @@ -200,6 +209,7 @@
 59       changes commit them and push them back to the original repo.
 60   
 61       """
 62 +     _log.info('Update the git repo: %s for: %s', repo.path, obj)
 63   
 64       if not repofolder:
 65           return
 66 @@ -298,6 +308,8 @@
 67       if not repofolder:
 68           return
 69   
 70 +     _log.info('Update the git repo: %s to remove: %s', repo.path, obj)
 71 + 
 72       # Get the fork
 73       repopath = os.path.join(repofolder, repo.path)
 74   
 75 @@ -800,6 +812,9 @@
 76       :arg filestream: the actual content of the file
 77   
 78       '''
 79 +     _log.info(
 80 +         'Addinf file: %s to the git repo: %s',
 81 +         repo.path, werkzeug.secure_filename(filename))
 82   
 83       if not ticketfolder:
 84           return
 85 @@ -913,6 +928,7 @@
 86       :arg user: the user object with its username and email
 87   
 88       '''
 89 +     _log.info('Updating file: %s in the repo: %s', filename, repo.path)
 90   
 91       # Get the fork
 92       repopath = pagure.get_repo_path(repo)
 93 @@ -1170,6 +1186,13 @@
 94           session, request, username, request_folder, domerge=True):
 95       ''' Merge the specified pull-request.
 96       '''
 97 +     if domerge:
 98 +         _log.info(
 99 +             '%s asked to merge the pull-request: %s', username, request)
100 +     else:
101 +         _log.info(
102 +             '%s asked to diff the pull-request: %s', username, request)
103 + 
104       if request.remote:
105           # Get the fork
106           repopath = pagure.get_remote_repo_path(
107 @@ -1185,18 +1208,21 @@
108   
109       # Clone the original repo into a temp folder
110       newpath = tempfile.mkdtemp(prefix='pagure-pr-merge')
111 +     _log.info('  working directory: %s', newpath)
112       new_repo = pygit2.clone_repository(parentpath, newpath)
113   
114       # Update the start and stop commits in the DB, one last time
115       diff_commits = diff_pull_request(
116           session, request, fork_obj, PagureRepo(parentpath),
117           requestfolder=request_folder, with_diff=False)
118 +     _log.info('  %s commit to merge', len(diff_commits))
119   
120       if request.project.settings.get(
121               'Enforce_signed-off_commits_in_pull-request', False):
122           for commit in diff_commits:
123               if 'signed-off-by' not in commit.message.lower():
124                   shutil.rmtree(newpath)
125 +                 _log.info('  Missing a required: signed-off-by: Bailing')
126                   raise pagure.exceptions.PagureException(
127                       'This repo enforces that all commits are '
128                       'signed off by their author. ')
129 @@ -1205,6 +1231,7 @@
130       branch_ref = get_branch_ref(new_repo, request.branch)
131       if not branch_ref:
132           shutil.rmtree(newpath)
133 +         _log.info('  Target branch could not be found')
134           raise pagure.exceptions.BranchNotFoundException(
135               'Branch %s could not be found in the repo %s' % (
136                   request.branch, request.project.fullname
137 @@ -1215,6 +1242,7 @@
138       branch = get_branch_ref(fork_obj, request.branch_from)
139       if not branch:
140           shutil.rmtree(newpath)
141 +         _log.info('  Branch of origin could not be found')
142           raise pagure.exceptions.BranchNotFoundException(
143               'Branch %s could not be found in the repo %s' % (
144                   request.branch_from, request.project_from.fullname
145 @@ -1227,14 +1255,17 @@
146       # Add the fork as remote repo
147       reponame = '%s_%s' % (request.user.user, request.uid)
148   
149 +     _log.info('  Adding remote: %s pointing to: %s', reponame, repopath)
150       remote = new_repo.create_remote(reponame, repopath)
151   
152       # Fetch the commits
153       remote.fetch()
154   
155       merge = new_repo.merge(repo_commit.oid)
156 +     _log.debug('  Merge: %s', merge)
157       if merge is None:
158           mergecode = new_repo.merge_analysis(repo_commit.oid)[0]
159 +         _log.debug('  Mergecode: %s', mergecode)
160   
161       refname = '%s:refs/heads/%s' % (branch_ref.name, request.branch)
162       if (
163 @@ -1244,6 +1275,7 @@
164                mergecode & pygit2.GIT_MERGE_ANALYSIS_UP_TO_DATE)):
165   
166           if domerge:
167 +             _log.info('  PR up to date, closing it')
168               pagure.lib.close_pull_request(
169                   session, request, username,
170                   requestfolder=request_folder)
171 @@ -1252,12 +1284,14 @@
172                   session.commit()
173               except SQLAlchemyError as err:  # pragma: no cover
174                   session.rollback()
175 +                 _log.exception('  Could not merge the PR in the DB')
176                   pagure.APP.logger.exception(err)
177                   raise pagure.exceptions.PagureException(
178                       'Could not close this pull-request')
179               raise pagure.exceptions.PagureException(
180                   'Nothing to do, changes were already merged')
181           else:
182 +             _log.info('  PR up to date, reporting it')
183               request.merge_status = 'NO_CHANGE'
184               session.commit()
185               shutil.rmtree(newpath)
186 @@ -1270,6 +1304,7 @@
187                mergecode & pygit2.GIT_MERGE_ANALYSIS_FASTFORWARD)):
188   
189           if domerge:
190 +             _log.info('  PR merged using fast-forward')
191               head = new_repo.lookup_reference('HEAD').get_object()
192               if not request.project.settings.get('always_merge', False):
193                   if merge is not None:
194 @@ -1292,11 +1327,13 @@
195                       tree,
196                       [head.hex, repo_commit.oid.hex])
197   
198 +             _log.info('  New head: %s', commit)
199               PagureRepo.push(ori_remote, refname)
200               fork_obj.run_hook(
201                   head.hex, commit, 'refs/heads/%s' % request.branch,
202                   username)
203           else:
204 +             _log.info('  PR merged using fast-forward, reporting it')
205               request.merge_status = 'FFORWARD'
206               session.commit()
207               shutil.rmtree(newpath)
208 @@ -1306,16 +1343,23 @@
209           tree = None
210           try:
211               tree = new_repo.index.write_tree()
212 -         except pygit2.GitError:
213 +         except pygit2.GitError as err:
214 +             _log.exception(
215 +                 '  Could not write down the new tree: merge conflicts')
216 +             pagure.APP.logger.exception(
217 +                 '  Could not write down the new tree: merge conflicts')
218               shutil.rmtree(newpath)
219               if domerge:
220 +                 _log.info('  Merge conflict: Bailing')
221                   raise pagure.exceptions.PagureException('Merge conflicts!')
222               else:
223 +                 _log.info('  Merge conflict, reporting it')
224                   request.merge_status = 'CONFLICTS'
225                   session.commit()
226                   return 'CONFLICTS'
227   
228           if domerge:
229 +             _log.info('  Writing down merge commit')
230               head = new_repo.lookup_reference('HEAD').get_object()
231               user_obj = pagure.lib.get_user(session, username)
232               author = pygit2.Signature(
233 @@ -1329,24 +1373,28 @@
234                   tree,
235                   [head.hex, repo_commit.oid.hex])
236   
237 +             _log.info('  New head: %s', commit)
238               PagureRepo.push(ori_remote, refname)
239               fork_obj.run_hook(
240                   head.hex, commit, 'refs/heads/%s' % request.branch,
241                   username)
242   
243           else:
244 +             _log.info('  PR can be merged with a merge commit, reporting it')
245               request.merge_status = 'MERGE'
246               session.commit()
247               shutil.rmtree(newpath)
248               return 'MERGE'
249   
250       # Update status
251 +     _log.info('  Closing the PR in the DB')
252       pagure.lib.close_pull_request(
253           session, request, username,
254           requestfolder=request_folder,
255       )
256       try:
257           # Reset the merge_status of all opened PR to refresh their cache
258 +         _log.info('  Clear the cached merged status of the other PRs')
259           pagure.lib.reset_status_pull_request(session, request.project)
260           session.commit()
261       except SQLAlchemyError as err:  # pragma: no cover
 1 @@ -30,7 +30,7 @@
 2   import pagure.lib
 3   import pagure.lib.git
 4   import pagure.forms
 5 - from pagure import APP, SESSION, LOG, login_required, __get_file_in_tree
 6 + from pagure import APP, SESSION, login_required, __get_file_in_tree
 7   
 8   
 9   def _get_parent_repo_path(repo):
10 @@ -562,7 +562,7 @@
11                   flask.flash('Comment removed')
12               except SQLAlchemyError as err:  # pragma: no cover
13                   SESSION.rollback()
14 -                 LOG.error(err)
15 +                 APP.logger.error(err)
16                   flask.flash(
17                       'Could not remove the comment: %s' % commentid, 'error')
18   
19 @@ -632,7 +632,7 @@
20                   flask.flash(message)
21           except SQLAlchemyError, err:  # pragma: no cover
22               SESSION.rollback()
23 -             LOG.error(err)
24 +             APP.logger.error(err)
25               if is_js:
26                   return 'error'
27               else:
 1 @@ -35,7 +35,7 @@
 2   import pagure.lib
 3   import pagure.lib.encoding_utils
 4   import pagure.forms
 5 - from pagure import (APP, SESSION, LOG, __get_file_in_tree,
 6 + from pagure import (APP, SESSION, __get_file_in_tree,
 7                       login_required, authenticated, urlpattern)
 8   
 9   
10 @@ -136,7 +136,7 @@
11               except SQLAlchemyError as err:  # pragma: no cover
12                   is_js = False
13                   SESSION.rollback()
14 -                 LOG.error(err)
15 +                 APP.logger.error(err)
16                   if not is_js:
17                       flask.flash(
18                           'Could not remove the comment: %s' % commentid,
19 @@ -428,7 +428,7 @@
20                   flask.flash(msg)
21           except SQLAlchemyError as err:  # pragma: no cover
22               SESSION.rollback()
23 -             LOG.error(err)
24 +             APP.logger.error(err)
25               flask.flash('Could not edit tag: %s' % tag, 'error')
26   
27           return flask.redirect(flask.url_for(
28 @@ -575,7 +575,7 @@
29                   flask.flash(msg)
30           except SQLAlchemyError as err:  # pragma: no cover
31               SESSION.rollback()
32 -             LOG.error(err)
33 +             APP.logger.error(err)
34               flask.flash(
35                   'Could not remove tag: %s' % ','.join(tags), 'error')
36   
37 @@ -1373,7 +1373,7 @@
38                   ktc.to_bytes(data))
39           except pagure.exceptions.PagureException:
40               # We cannot decode the file, so bail but warn the admins
41 -             LOG.exception('File could not be decoded')
42 +             APP.logger.exception('File could not be decoded')
43   
44       if encoding:
45           mimetype += '; charset={encoding}'.format(encoding=encoding)
46 @@ -1437,7 +1437,7 @@
47                   flask.flash(message)
48           except SQLAlchemyError, err:  # pragma: no cover
49               SESSION.rollback()
50 -             LOG.error(err)
51 +             APP.logger.error(err)
52               if is_js:
53                   return 'error'
54               flask.flash(
 1 @@ -49,7 +49,7 @@
 2   import pagure.forms
 3   import pagure
 4   import pagure.ui.plugins
 5 - from pagure import (APP, SESSION, LOG, __get_file_in_tree, login_required,
 6 + from pagure import (APP, SESSION, __get_file_in_tree, login_required,
 7                       admin_session_timedout)
 8   from pagure.lib import encoding_utils
 9   
10 @@ -492,7 +492,7 @@
11                   Image.open(StringIO(content.data))
12                   output_type = 'image'
13               except IOError as err:
14 -                 LOG.debug(
15 +                 APP.logger.debug(
16                       'Failed to load image %s, error: %s', filename, err
17                   )
18                   output_type = 'binary'
19 @@ -658,7 +658,7 @@
20               encoding = encoding_utils.guess_encoding(ktc.to_bytes(data))
21           except pagure.exceptions.PagureException:
22               # We cannot decode the file, so bail but warn the admins
23 -             LOG.exception('File could not be decoded')
24 +             APP.logger.exception('File could not be decoded')
25   
26       if encoding:
27           mimetype += '; charset={encoding}'.format(encoding=encoding)
28 @@ -699,7 +699,7 @@
29           content = encoding_utils.decode(content.data)
30       except pagure.exceptions.PagureException:
31           # We cannot decode the file, so bail but warn the admins
32 -         LOG.exception('File could not be decoded')
33 +         APP.logger.exception('File could not be decoded')
34           flask.abort(500, 'File could not be decoded')
35   
36       lexer = TextLexer()
 1 @@ -48,9 +48,13 @@
 2   if os.environ.get('FAITOUT_URL'):
 3       FAITOUT_URL = os.environ.get('FAITOUT_URL')
 4   HERE = os.path.join(os.path.dirname(os.path.abspath(__file__)))
 5 - LOG = logging.getLogger("pagure")
 6 + LOG = logging.getLogger(__name__)
 7   LOG.setLevel(logging.DEBUG)
 8   
 9 + PAGLOG = logging.getLogger('pagure')
10 + PAGLOG.setLevel(logging.CRITICAL)
11 + PAGLOG.handlers = []
12 + 
13   
14   LOG.info('BUILD_ID: %s', os.environ.get('BUILD_ID'))
15   if os.environ.get('BUILD_ID')or os.environ.get('FAITOUT_URL'):
16 @@ -67,7 +71,7 @@
17           pass
18   
19   # Remove the log handlers for the tests
20 - pagure.LOG.handlers = []
21 + pagure.APP.logger.handlers = []
22   
23   @contextmanager
24   def user_set(APP, user):
1 @@ -63,7 +63,6 @@
2   
3           pagure.APP.config['EMAIL_SEND'] = False
4           pagure.APP.config['OLD_VIEW_COMMIT_ENABLED'] = False
5 -         pagure.LOG.handlers = []
6   
7       def test_view_commit_old(self):
8           """ Test the view_commit_old endpoint. """