debug: add new custom logging to track unique requests across systems.

rhodecode/lib/request.py

@@ -0,0 +1,29 b''
+# -*- coding: utf-8 -*-
+
+# Copyright (C) 2017-2018 RhodeCode GmbH
+#
+# This program is free software: you can redistribute it and/or modify
+# it under the terms of the GNU Affero General Public License, version 3
+# (only), as published by the Free Software Foundation.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU Affero General Public License
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.
+#
+# This program is dual-licensed. If you wish to learn more about the
+# RhodeCode Enterprise Edition, including its added features, Support services,
+# and proprietary license terms, please see https://rhodecode.com/licenses/
+
+from uuid import uuid4
+from pyramid.decorator import reify
+from pyramid.request import Request as _Request
+
+
+class Request(_Request):
+    @reify
+    def req_id(self):
+        return str(uuid4())

rhodecode/config/middleware.py

@@ -1,438 +1,440 b''
 # -*- coding: utf-8 -*-
 
 # Copyright (C) 2010-2018 RhodeCode GmbH
 #
 # This program is free software: you can redistribute it and/or modify
 # it under the terms of the GNU Affero General Public License, version 3
 # (only), as published by the Free Software Foundation.
 #
 # This program is distributed in the hope that it will be useful,
 # but WITHOUT ANY WARRANTY; without even the implied warranty of
 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 # GNU General Public License for more details.
 #
 # You should have received a copy of the GNU Affero General Public License
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 # This program is dual-licensed. If you wish to learn more about the
 # RhodeCode Enterprise Edition, including its added features, Support services,
 # and proprietary license terms, please see https://rhodecode.com/licenses/
 
 import logging
 import traceback
 import collections
 
 from paste.gzipper import make_gzip_middleware
 from pyramid.wsgi import wsgiapp
 from pyramid.authorization import ACLAuthorizationPolicy
 from pyramid.config import Configurator
 from pyramid.settings import asbool, aslist
 from pyramid.httpexceptions import (
     HTTPException, HTTPError, HTTPInternalServerError, HTTPFound, HTTPNotFound)
 from pyramid.events import ApplicationCreated
 from pyramid.renderers import render_to_response
 
 from rhodecode.model import meta
 from rhodecode.config import patches
 from rhodecode.config import utils as config_utils
 from rhodecode.config.environment import load_pyramid_environment
 
 from rhodecode.lib.middleware.vcs import VCSMiddleware
+from rhodecode.lib.request import Request
 from rhodecode.lib.vcs import VCSCommunicationError
 from rhodecode.lib.exceptions import VCSServerUnavailable
 from rhodecode.lib.middleware.appenlight import wrap_in_appenlight_if_enabled
 from rhodecode.lib.middleware.https_fixup import HttpsFixup
 from rhodecode.lib.celerylib.loader import configure_celery
 from rhodecode.lib.plugins.utils import register_rhodecode_plugin
 from rhodecode.lib.utils2 import aslist as rhodecode_aslist, AttributeDict
 from rhodecode.subscribers import (
     scan_repositories_if_enabled, write_js_routes_if_enabled,
     write_metadata_if_needed, inject_app_settings)
 
 
 log = logging.getLogger(__name__)
 
 
 def is_http_error(response):
     # error which should have traceback
     return response.status_code > 499
 
 
 def make_pyramid_app(global_config, **settings):
     """
     Constructs the WSGI application based on Pyramid.
 
     Specials:
 
     * The application can also be integrated like a plugin via the call to
       `includeme`. This is accompanied with the other utility functions which
       are called. Changing this should be done with great care to not break
       cases when these fragments are assembled from another place.
 
     """
     sanitize_settings_and_apply_defaults(settings)
 
     config = Configurator(settings=settings)
 
     # Apply compatibility patches
     patches.inspect_getargspec()
 
     load_pyramid_environment(global_config, settings)
 
     # Static file view comes first
     includeme_first(config)
 
     includeme(config)
 
     pyramid_app = config.make_wsgi_app()
     pyramid_app = wrap_app_in_wsgi_middlewares(pyramid_app, config)
     pyramid_app.config = config
 
     config.configure_celery(global_config['__file__'])
     # creating the app uses a connection - return it after we are done
     meta.Session.remove()
 
     log.info('Pyramid app %s created and configured.', pyramid_app)
     return pyramid_app
 
 
 def not_found_view(request):
     """
     This creates the view which should be registered as not-found-view to
     pyramid.
     """
 
     if not getattr(request, 'vcs_call', None):
         # handle like regular case with our error_handler
         return error_handler(HTTPNotFound(), request)
 
     # handle not found view as a vcs call
     settings = request.registry.settings
     ae_client = getattr(request, 'ae_client', None)
     vcs_app = VCSMiddleware(
         HTTPNotFound(), request.registry, settings,
         appenlight_client=ae_client)
 
     return wsgiapp(vcs_app)(None, request)
 
 
 def error_handler(exception, request):
     import rhodecode
     from rhodecode.lib import helpers
 
     rhodecode_title = rhodecode.CONFIG.get('rhodecode_title') or 'RhodeCode'
 
     base_response = HTTPInternalServerError()
     # prefer original exception for the response since it may have headers set
     if isinstance(exception, HTTPException):
         base_response = exception
     elif isinstance(exception, VCSCommunicationError):
         base_response = VCSServerUnavailable()
 
     if is_http_error(base_response):
         log.exception(
             'error occurred handling this request for path: %s', request.path)
 
     error_explanation = base_response.explanation or str(base_response)
     if base_response.status_code == 404:
         error_explanation += " Or you don't have permission to access it."
     c = AttributeDict()
     c.error_message = base_response.status
     c.error_explanation = error_explanation
     c.visual = AttributeDict()
 
     c.visual.rhodecode_support_url = (
         request.registry.settings.get('rhodecode_support_url') or
         request.route_url('rhodecode_support')
     )
     c.redirect_time = 0
     c.rhodecode_name = rhodecode_title
     if not c.rhodecode_name:
         c.rhodecode_name = 'Rhodecode'
 
     c.causes = []
     if is_http_error(base_response):
         c.causes.append('Server is overloaded.')
         c.causes.append('Server database connection is lost.')
         c.causes.append('Server expected unhandled error.')
 
     if hasattr(base_response, 'causes'):
         c.causes = base_response.causes
 
     c.messages = helpers.flash.pop_messages(request=request)
     c.traceback = traceback.format_exc()
     response = render_to_response(
         '/errors/error_document.mako', {'c': c, 'h': helpers}, request=request,
         response=base_response)
 
     return response
 
 
 def includeme_first(config):
     # redirect automatic browser favicon.ico requests to correct place
     def favicon_redirect(context, request):
         return HTTPFound(
             request.static_path('rhodecode:public/images/favicon.ico'))
 
     config.add_view(favicon_redirect, route_name='favicon')
     config.add_route('favicon', '/favicon.ico')
 
     def robots_redirect(context, request):
         return HTTPFound(
             request.static_path('rhodecode:public/robots.txt'))
 
     config.add_view(robots_redirect, route_name='robots')
     config.add_route('robots', '/robots.txt')
 
     config.add_static_view(
         '_static/deform', 'deform:static')
     config.add_static_view(
         '_static/rhodecode', path='rhodecode:public', cache_max_age=3600 * 24)
 
 
 def includeme(config):
     settings = config.registry.settings
+    config.set_request_factory(Request)
 
     # plugin information
     config.registry.rhodecode_plugins = collections.OrderedDict()
 
     config.add_directive(
         'register_rhodecode_plugin', register_rhodecode_plugin)
 
     config.add_directive('configure_celery', configure_celery)
 
     if asbool(settings.get('appenlight', 'false')):
         config.include('appenlight_client.ext.pyramid_tween')
 
     # Includes which are required. The application would fail without them.
     config.include('pyramid_mako')
     config.include('pyramid_beaker')
     config.include('rhodecode.lib.caches')
 
     config.include('rhodecode.authentication')
     config.include('rhodecode.integrations')
 
     # apps
     config.include('rhodecode.apps._base')
     config.include('rhodecode.apps.ops')
 
     config.include('rhodecode.apps.admin')
     config.include('rhodecode.apps.channelstream')
     config.include('rhodecode.apps.login')
     config.include('rhodecode.apps.home')
     config.include('rhodecode.apps.journal')
     config.include('rhodecode.apps.repository')
     config.include('rhodecode.apps.repo_group')
     config.include('rhodecode.apps.user_group')
     config.include('rhodecode.apps.search')
     config.include('rhodecode.apps.user_profile')
     config.include('rhodecode.apps.user_group_profile')
     config.include('rhodecode.apps.my_account')
     config.include('rhodecode.apps.svn_support')
     config.include('rhodecode.apps.ssh_support')
     config.include('rhodecode.apps.gist')
 
     config.include('rhodecode.apps.debug_style')
     config.include('rhodecode.tweens')
     config.include('rhodecode.api')
 
     config.add_route(
         'rhodecode_support', 'https://rhodecode.com/help/', static=True)
 
     config.add_translation_dirs('rhodecode:i18n/')
     settings['default_locale_name'] = settings.get('lang', 'en')
 
     # Add subscribers.
     config.add_subscriber(inject_app_settings, ApplicationCreated)
     config.add_subscriber(scan_repositories_if_enabled, ApplicationCreated)
     config.add_subscriber(write_metadata_if_needed, ApplicationCreated)
     config.add_subscriber(write_js_routes_if_enabled, ApplicationCreated)
 
     # events
     # TODO(marcink): this should be done when pyramid migration is finished
     # config.add_subscriber(
     #     'rhodecode.integrations.integrations_event_handler',
     #     'rhodecode.events.RhodecodeEvent')
 
     # request custom methods
     config.add_request_method(
         'rhodecode.lib.partial_renderer.get_partial_renderer',
         'get_partial_renderer')
 
     # Set the authorization policy.
     authz_policy = ACLAuthorizationPolicy()
     config.set_authorization_policy(authz_policy)
 
     # Set the default renderer for HTML templates to mako.
     config.add_mako_renderer('.html')
 
     config.add_renderer(
         name='json_ext',
         factory='rhodecode.lib.ext_json_renderer.pyramid_ext_json')
 
     # include RhodeCode plugins
     includes = aslist(settings.get('rhodecode.includes', []))
     for inc in includes:
         config.include(inc)
 
     # custom not found view, if our pyramid app doesn't know how to handle
     # the request pass it to potential VCS handling ap
     config.add_notfound_view(not_found_view)
     if not settings.get('debugtoolbar.enabled', False):
         # disabled debugtoolbar handle all exceptions via the error_handlers
         config.add_view(error_handler, context=Exception)
 
     # all errors including 403/404/50X
     config.add_view(error_handler, context=HTTPError)
 
 
 def wrap_app_in_wsgi_middlewares(pyramid_app, config):
     """
     Apply outer WSGI middlewares around the application.
     """
     settings = config.registry.settings
 
     # enable https redirects based on HTTP_X_URL_SCHEME set by proxy
     pyramid_app = HttpsFixup(pyramid_app, settings)
 
     pyramid_app, _ae_client = wrap_in_appenlight_if_enabled(
         pyramid_app, settings)
     config.registry.ae_client = _ae_client
 
     if settings['gzip_responses']:
         pyramid_app = make_gzip_middleware(
             pyramid_app, settings, compress_level=1)
 
     # this should be the outer most middleware in the wsgi stack since
     # middleware like Routes make database calls
     def pyramid_app_with_cleanup(environ, start_response):
         try:
             return pyramid_app(environ, start_response)
         finally:
             # Dispose current database session and rollback uncommitted
             # transactions.
             meta.Session.remove()
 
             # In a single threaded mode server, on non sqlite db we should have
             # '0 Current Checked out connections' at the end of a request,
             # if not, then something, somewhere is leaving a connection open
             pool = meta.Base.metadata.bind.engine.pool
             log.debug('sa pool status: %s', pool.status())
 
     return pyramid_app_with_cleanup
 
 
 def sanitize_settings_and_apply_defaults(settings):
     """
     Applies settings defaults and does all type conversion.
 
     We would move all settings parsing and preparation into this place, so that
     we have only one place left which deals with this part. The remaining parts
     of the application would start to rely fully on well prepared settings.
 
     This piece would later be split up per topic to avoid a big fat monster
     function.
     """
 
     settings.setdefault('rhodecode.edition', 'Community Edition')
 
     if 'mako.default_filters' not in settings:
         # set custom default filters if we don't have it defined
         settings['mako.imports'] = 'from rhodecode.lib.base import h_filter'
         settings['mako.default_filters'] = 'h_filter'
 
     if 'mako.directories' not in settings:
         mako_directories = settings.setdefault('mako.directories', [
             # Base templates of the original application
             'rhodecode:templates',
         ])
         log.debug(
             "Using the following Mako template directories: %s",
             mako_directories)
 
     # Default includes, possible to change as a user
     pyramid_includes = settings.setdefault('pyramid.includes', [
         'rhodecode.lib.middleware.request_wrapper',
     ])
     log.debug(
         "Using the following pyramid.includes: %s",
         pyramid_includes)
 
     # TODO: johbo: Re-think this, usually the call to config.include
     # should allow to pass in a prefix.
     settings.setdefault('rhodecode.api.url', '/_admin/api')
 
     # Sanitize generic settings.
     _list_setting(settings, 'default_encoding', 'UTF-8')
     _bool_setting(settings, 'is_test', 'false')
     _bool_setting(settings, 'gzip_responses', 'false')
 
     # Call split out functions that sanitize settings for each topic.
     _sanitize_appenlight_settings(settings)
     _sanitize_vcs_settings(settings)
 
     # configure instance id
     config_utils.set_instance_id(settings)
 
     return settings
 
 
 def _sanitize_appenlight_settings(settings):
     _bool_setting(settings, 'appenlight', 'false')
 
 
 def _sanitize_vcs_settings(settings):
     """
     Applies settings defaults and does type conversion for all VCS related
     settings.
     """
     _string_setting(settings, 'vcs.svn.compatible_version', '')
     _string_setting(settings, 'git_rev_filter', '--all')
     _string_setting(settings, 'vcs.hooks.protocol', 'http')
     _string_setting(settings, 'vcs.scm_app_implementation', 'http')
     _string_setting(settings, 'vcs.server', '')
     _string_setting(settings, 'vcs.server.log_level', 'debug')
     _string_setting(settings, 'vcs.server.protocol', 'http')
     _bool_setting(settings, 'startup.import_repos', 'false')
     _bool_setting(settings, 'vcs.hooks.direct_calls', 'false')
     _bool_setting(settings, 'vcs.server.enable', 'true')
     _bool_setting(settings, 'vcs.start_server', 'false')
     _list_setting(settings, 'vcs.backends', 'hg, git, svn')
     _int_setting(settings, 'vcs.connection_timeout', 3600)
 
     # Support legacy values of vcs.scm_app_implementation. Legacy
     # configurations may use 'rhodecode.lib.middleware.utils.scm_app_http'
     # which is now mapped to 'http'.
     scm_app_impl = settings['vcs.scm_app_implementation']
     if scm_app_impl == 'rhodecode.lib.middleware.utils.scm_app_http':
         settings['vcs.scm_app_implementation'] = 'http'
 
 
 def _int_setting(settings, name, default):
     settings[name] = int(settings.get(name, default))
 
 
 def _bool_setting(settings, name, default):
     input_val = settings.get(name, default)
     if isinstance(input_val, unicode):
         input_val = input_val.encode('utf8')
     settings[name] = asbool(input_val)
 
 
 def _list_setting(settings, name, default):
     raw_value = settings.get(name, default)
 
     old_separator = ','
     if old_separator in raw_value:
         # If we get a comma separated list, pass it to our own function.
         settings[name] = rhodecode_aslist(raw_value, sep=old_separator)
     else:
         # Otherwise we assume it uses pyramids space/newline separation.
         settings[name] = aslist(raw_value)
 
 
 def _string_setting(settings, name, default, lower=True):
     value = settings.get(name, default)
     if lower:
         value = value.lower()
     settings[name] = value

rhodecode/lib/logging_formatter.py

@@ -1,141 +1,170 b''
 # -*- coding: utf-8 -*-
 
 # Copyright (C) 2010-2018 RhodeCode GmbH
 #
 # This program is free software: you can redistribute it and/or modify
 # it under the terms of the GNU Affero General Public License, version 3
 # (only), as published by the Free Software Foundation.
 #
 # This program is distributed in the hope that it will be useful,
 # but WITHOUT ANY WARRANTY; without even the implied warranty of
 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 # GNU General Public License for more details.
 #
 # You should have received a copy of the GNU Affero General Public License
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 # This program is dual-licensed. If you wish to learn more about the
 # RhodeCode Enterprise Edition, including its added features, Support services,
 # and proprietary license terms, please see https://rhodecode.com/licenses/
 
 import sys
 import logging
 
 
 BLACK, RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE = xrange(30, 38)
 
 # Sequences
 RESET_SEQ = "\033[0m"
 COLOR_SEQ = "\033[0;%dm"
 BOLD_SEQ = "\033[1m"
 
 COLORS = {
     'CRITICAL': MAGENTA,
     'ERROR': RED,
     'WARNING': CYAN,
     'INFO': GREEN,
     'DEBUG': BLUE,
     'SQL': YELLOW
 }
 
 
 def one_space_trim(s):
     if s.find("  ") == -1:
         return s
     else:
         s = s.replace('  ', ' ')
         return one_space_trim(s)
 
 
 def format_sql(sql):
     sql = sql.replace('\n', '')
     sql = one_space_trim(sql)
     sql = sql\
         .replace(',', ',\n\t')\
         .replace('SELECT', '\n\tSELECT \n\t')\
         .replace('UPDATE', '\n\tUPDATE \n\t')\
         .replace('DELETE', '\n\tDELETE \n\t')\
         .replace('FROM', '\n\tFROM')\
         .replace('ORDER BY', '\n\tORDER BY')\
         .replace('LIMIT', '\n\tLIMIT')\
         .replace('WHERE', '\n\tWHERE')\
         .replace('AND', '\n\tAND')\
         .replace('LEFT', '\n\tLEFT')\
         .replace('INNER', '\n\tINNER')\
         .replace('INSERT', '\n\tINSERT')\
         .replace('DELETE', '\n\tDELETE')
     return sql
 
 
 class ExceptionAwareFormatter(logging.Formatter):
     """
     Extended logging formatter which prints out remote tracebacks.
     """
 
     def formatException(self, ei):
         ex_type, ex_value, ex_tb = ei
 
         local_tb = logging.Formatter.formatException(self, ei)
         if hasattr(ex_value, '_vcs_server_traceback'):
 
             def formatRemoteTraceback(remote_tb_lines):
                 result = ["\n +--- This exception occured remotely on VCSServer - Remote traceback:\n\n"]
                 result.append(remote_tb_lines)
                 result.append("\n +--- End of remote traceback\n")
                 return result
 
             try:
                 if ex_type is not None and ex_value is None and ex_tb is None:
                     # possible old (3.x) call syntax where caller is only
                     # providing exception object
                     if type(ex_type) is not type:
                         raise TypeError(
                             "invalid argument: ex_type should be an exception "
                             "type, or just supply no arguments at all")
                 if ex_type is None and ex_tb is None:
                     ex_type, ex_value, ex_tb = sys.exc_info()
 
                 remote_tb = getattr(ex_value, "_vcs_server_traceback", None)
 
                 if remote_tb:
                     remote_tb = formatRemoteTraceback(remote_tb)
                     return local_tb + ''.join(remote_tb)
             finally:
                 # clean up cycle to traceback, to allow proper GC
                 del ex_type, ex_value, ex_tb
 
         return local_tb
 
 
 class ColorFormatter(ExceptionAwareFormatter):
 
     def format(self, record):
         """
         Changes record's levelname to use with COLORS enum
         """
 
         levelname = record.levelname
         start = COLOR_SEQ % (COLORS[levelname])
         def_record = logging.Formatter.format(self, record)
         end = RESET_SEQ
 
         colored_record = ''.join([start, def_record, end])
         return colored_record
 
 
+def _inject_req_id(record):
+    from pyramid.threadlocal import get_current_request
+    req = get_current_request()
+    req_id = 'req_id:%-36s ' % (getattr(req, 'req_id', None))
+    record.req_id = req_id
+
+
+class RequestTrackingFormatter(ExceptionAwareFormatter):
+    def format(self, record):
+        _inject_req_id(record)
+        def_record = logging.Formatter.format(self, record)
+        return def_record
+
+
+class ColorRequestTrackingFormatter(ColorFormatter):
+    def format(self, record):
+        """
+        Changes record's levelname to use with COLORS enum
+        """
+        _inject_req_id(record)
+        levelname = record.levelname
+        start = COLOR_SEQ % (COLORS[levelname])
+        def_record = logging.Formatter.format(self, record)
+        end = RESET_SEQ
+
+        colored_record = ''.join([start, def_record, end])
+        return colored_record
+
+
 class ColorFormatterSql(logging.Formatter):
 
     def format(self, record):
         """
         Changes record's levelname to use with COLORS enum
         """
 
         start = COLOR_SEQ % (COLORS['SQL'])
         def_record = format_sql(logging.Formatter.format(self, record))
         end = RESET_SEQ
 
         colored_record = ''.join([start, def_record, end])
         return colored_record
 
 # marcink: needs to stay with this name for backward .ini compatability
 Pyro4AwareFormatter = ExceptionAwareFormatter

rhodecode/lib/middleware/vcs.py

@@ -1,244 +1,244 b''
 # -*- coding: utf-8 -*-
 
 # Copyright (C) 2010-2018 RhodeCode GmbH
 #
 # This program is free software: you can redistribute it and/or modify
 # it under the terms of the GNU Affero General Public License, version 3
 # (only), as published by the Free Software Foundation.
 #
 # This program is distributed in the hope that it will be useful,
 # but WITHOUT ANY WARRANTY; without even the implied warranty of
 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 # GNU General Public License for more details.
 #
 # You should have received a copy of the GNU Affero General Public License
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 # This program is dual-licensed. If you wish to learn more about the
 # RhodeCode Enterprise Edition, including its added features, Support services,
 # and proprietary license terms, please see https://rhodecode.com/licenses/
 
 import gzip
 import shutil
 import logging
 import tempfile
 import urlparse
 
 from webob.exc import HTTPNotFound
 
 import rhodecode
 from rhodecode.lib.middleware.appenlight import wrap_in_appenlight_if_enabled
 from rhodecode.lib.middleware.simplegit import SimpleGit, GIT_PROTO_PAT
 from rhodecode.lib.middleware.simplehg import SimpleHg
 from rhodecode.lib.middleware.simplesvn import SimpleSvn
 from rhodecode.model.settings import VcsSettingsModel
 
 log = logging.getLogger(__name__)
 
 VCS_TYPE_KEY = '_rc_vcs_type'
 VCS_TYPE_SKIP = '_rc_vcs_skip'
 
 
 def is_git(environ):
     """
     Returns True if requests should be handled by GIT wsgi middleware
     """
     is_git_path = GIT_PROTO_PAT.match(environ['PATH_INFO'])
     log.debug(
         'request path: `%s` detected as GIT PROTOCOL %s', environ['PATH_INFO'],
         is_git_path is not None)
 
     return is_git_path
 
 
 def is_hg(environ):
     """
     Returns True if requests target is mercurial server - header
     ``HTTP_ACCEPT`` of such request would start with ``application/mercurial``.
     """
     is_hg_path = False
 
     http_accept = environ.get('HTTP_ACCEPT')
 
     if http_accept and http_accept.startswith('application/mercurial'):
         query = urlparse.parse_qs(environ['QUERY_STRING'])
         if 'cmd' in query:
             is_hg_path = True
 
     log.debug(
         'request path: `%s` detected as HG PROTOCOL %s', environ['PATH_INFO'],
         is_hg_path)
 
     return is_hg_path
 
 
 def is_svn(environ):
     """
     Returns True if requests target is Subversion server
     """
 
     http_dav = environ.get('HTTP_DAV', '')
     magic_path_segment = rhodecode.CONFIG.get(
         'rhodecode_subversion_magic_path', '/!svn')
     is_svn_path = (
         'subversion' in http_dav or
         magic_path_segment in environ['PATH_INFO']
         or environ['REQUEST_METHOD'] in ['PROPFIND', 'PROPPATCH']
     )
     log.debug(
         'request path: `%s` detected as SVN PROTOCOL %s', environ['PATH_INFO'],
         is_svn_path)
 
     return is_svn_path
 
 
 class GunzipMiddleware(object):
     """
     WSGI middleware that unzips gzip-encoded requests before
     passing on to the underlying application.
     """
 
     def __init__(self, application):
         self.app = application
 
     def __call__(self, environ, start_response):
         accepts_encoding_header = environ.get('HTTP_CONTENT_ENCODING', b'')
 
         if b'gzip' in accepts_encoding_header:
             log.debug('gzip detected, now running gunzip wrapper')
             wsgi_input = environ['wsgi.input']
 
             if not hasattr(environ['wsgi.input'], 'seek'):
                 # The gzip implementation in the standard library of Python 2.x
                 # requires the '.seek()' and '.tell()' methods to be available
                 # on the input stream.  Read the data into a temporary file to
                 # work around this limitation.
 
                 wsgi_input = tempfile.SpooledTemporaryFile(64 * 1024 * 1024)
                 shutil.copyfileobj(environ['wsgi.input'], wsgi_input)
                 wsgi_input.seek(0)
 
             environ['wsgi.input'] = gzip.GzipFile(fileobj=wsgi_input, mode='r')
             # since we "Ungzipped" the content we say now it's no longer gzip
             # content encoding
             del environ['HTTP_CONTENT_ENCODING']
 
             # content length has changes ? or i'm not sure
             if 'CONTENT_LENGTH' in environ:
                 del environ['CONTENT_LENGTH']
         else:
             log.debug('content not gzipped, gzipMiddleware passing '
                       'request further')
         return self.app(environ, start_response)
 
 
 def is_vcs_call(environ):
     if VCS_TYPE_KEY in environ:
         raw_type = environ[VCS_TYPE_KEY]
         return raw_type and raw_type != VCS_TYPE_SKIP
     return False
 
 
 def detect_vcs_request(environ, backends):
     checks = {
         'hg': (is_hg, SimpleHg),
         'git': (is_git, SimpleGit),
         'svn': (is_svn, SimpleSvn),
     }
     handler = None
 
     if VCS_TYPE_KEY in environ:
         raw_type = environ[VCS_TYPE_KEY]
         if raw_type == VCS_TYPE_SKIP:
             log.debug('got `skip` marker for vcs detection, skipping...')
             return handler
 
         _check, handler = checks.get(raw_type) or [None, None]
         if handler:
             log.debug('got handler:%s from environ', handler)
 
     if not handler:
-        log.debug('checking if request is of VCS type in order: %s', backends)
+        log.debug('request start: checking if request is of VCS type in order: %s', backends)
         for vcs_type in backends:
             vcs_check, _handler = checks[vcs_type]
             if vcs_check(environ):
                 log.debug('vcs handler found %s', _handler)
                 handler = _handler
                 break
 
     return handler
 
 
 class VCSMiddleware(object):
 
     def __init__(self, app, registry, config, appenlight_client):
         self.application = app
         self.registry = registry
         self.config = config
         self.appenlight_client = appenlight_client
         self.use_gzip = True
         # order in which we check the middlewares, based on vcs.backends config
         self.check_middlewares = config['vcs.backends']
 
     def vcs_config(self, repo_name=None):
         """
         returns serialized VcsSettings
         """
         try:
             return VcsSettingsModel(
                 repo=repo_name).get_ui_settings_as_config_obj()
         except Exception:
             pass
 
     def wrap_in_gzip_if_enabled(self, app, config):
         if self.use_gzip:
             app = GunzipMiddleware(app)
         return app
 
     def _get_handler_app(self, environ):
         app = None
         log.debug('VCSMiddleware: detecting vcs type.')
         handler = detect_vcs_request(environ, self.check_middlewares)
         if handler:
             app = handler(self.config, self.registry)
 
         return app
 
     def __call__(self, environ, start_response):
         # check if we handle one of interesting protocols, optionally extract
         # specific vcsSettings and allow changes of how things are wrapped
         vcs_handler = self._get_handler_app(environ)
         if vcs_handler:
             # translate the _REPO_ID into real repo NAME for usage
             # in middleware
             environ['PATH_INFO'] = vcs_handler._get_by_id(environ['PATH_INFO'])
 
             # Set acl, url and vcs repo names.
             vcs_handler.set_repo_names(environ)
 
             # register repo config back to the handler
             vcs_conf = self.vcs_config(vcs_handler.acl_repo_name)
             # maybe damaged/non existent settings. We still want to
             # pass that point to validate on is_valid_and_existing_repo
             # and return proper HTTP Code back to client
             if vcs_conf:
                 vcs_handler.repo_vcs_config = vcs_conf
 
             # check for type, presence in database and on filesystem
             if not vcs_handler.is_valid_and_existing_repo(
                     vcs_handler.acl_repo_name,
                     vcs_handler.base_path,
                     vcs_handler.SCM):
                 return HTTPNotFound()(environ, start_response)
 
             environ['REPO_NAME'] = vcs_handler.url_repo_name
 
             # Wrap handler in middlewares if they are enabled.
             vcs_handler = self.wrap_in_gzip_if_enabled(
                 vcs_handler, self.config)
             vcs_handler, _ = wrap_in_appenlight_if_enabled(
                 vcs_handler, self.config, self.appenlight_client)
 
             return vcs_handler(environ, start_response)
 
         return self.application(environ, start_response)

rhodecode/lib/pyramid_utils.py

@@ -1,58 +1,59 b''
 # -*- coding: utf-8 -*-
 
 # Copyright (C) 2016-2018 RhodeCode GmbH
 #
 # This program is free software: you can redistribute it and/or modify
 # it under the terms of the GNU Affero General Public License, version 3
 # (only), as published by the Free Software Foundation.
 #
 # This program is distributed in the hope that it will be useful,
 # but WITHOUT ANY WARRANTY; without even the implied warranty of
 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 # GNU General Public License for more details.
 #
 # You should have received a copy of the GNU Affero General Public License
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 # This program is dual-licensed. If you wish to learn more about the
 # RhodeCode Enterprise Edition, including its added features, Support services,
 # and proprietary license terms, please see https://rhodecode.com/licenses/
 
 import os
 from pyramid.compat import configparser
 from pyramid.paster import bootstrap as pyramid_bootstrap, setup_logging  # noqa
-from pyramid.request import Request
 from pyramid.scripting import prepare
 
+from rhodecode.lib.request import Request
+
 
 def get_config(ini_path, **kwargs):
     parser = configparser.ConfigParser(**kwargs)
     parser.read(ini_path)
     return parser
 
 
 def get_app_config(ini_path):
     from paste.deploy.loadwsgi import appconfig
     return appconfig('config:{}'.format(ini_path), relative_to=os.getcwd())
 
 
 def bootstrap(config_uri, request=None, options=None, env=None):
     if env:
         os.environ.update(env)
 
     config = get_config(config_uri)
     base_url = 'http://rhodecode.local'
     try:
         base_url = config.get('app:main', 'app.base_url')
     except (configparser.NoSectionError, configparser.NoOptionError):
         pass
 
     request = request or Request.blank('/', base_url=base_url)
 
     return pyramid_bootstrap(config_uri, request=request, options=options)
 
 
 def prepare_request(environ):
     request = Request.blank('/', environ=environ)
     prepare(request)  # set pyramid threadlocal request
     return request

rhodecode/lib/utils.py

@@ -1,779 +1,779 b''
 # -*- coding: utf-8 -*-
 
 # Copyright (C) 2010-2018 RhodeCode GmbH
 #
 # This program is free software: you can redistribute it and/or modify
 # it under the terms of the GNU Affero General Public License, version 3
 # (only), as published by the Free Software Foundation.
 #
 # This program is distributed in the hope that it will be useful,
 # but WITHOUT ANY WARRANTY; without even the implied warranty of
 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 # GNU General Public License for more details.
 #
 # You should have received a copy of the GNU Affero General Public License
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 # This program is dual-licensed. If you wish to learn more about the
 # RhodeCode Enterprise Edition, including its added features, Support services,
 # and proprietary license terms, please see https://rhodecode.com/licenses/
 
 """
 Utilities library for RhodeCode
 """
 
 import datetime
 import decorator
 import json
 import logging
 import os
 import re
 import shutil
 import tempfile
 import traceback
 import tarfile
 import warnings
 import hashlib
 from os.path import join as jn
 
 import paste
 import pkg_resources
 from webhelpers.text import collapse, remove_formatting, strip_tags
 from mako import exceptions
 from pyramid.threadlocal import get_current_registry
-from pyramid.request import Request
+from rhodecode.lib.request import Request
 
 from rhodecode.lib.fakemod import create_module
 from rhodecode.lib.vcs.backends.base import Config
 from rhodecode.lib.vcs.exceptions import VCSError
 from rhodecode.lib.vcs.utils.helpers import get_scm, get_scm_backend
 from rhodecode.lib.utils2 import (
     safe_str, safe_unicode, get_current_rhodecode_user, md5)
 from rhodecode.model import meta
 from rhodecode.model.db import (
     Repository, User, RhodeCodeUi, UserLog, RepoGroup, UserGroup)
 from rhodecode.model.meta import Session
 
 
 log = logging.getLogger(__name__)
 
 REMOVED_REPO_PAT = re.compile(r'rm__\d{8}_\d{6}_\d{6}__.*')
 
 # String which contains characters that are not allowed in slug names for
 # repositories or repository groups. It is properly escaped to use it in
 # regular expressions.
 SLUG_BAD_CHARS = re.escape('`?=[]\;\'"<>,/~!@#$%^&*()+{}|:')
 
 # Regex that matches forbidden characters in repo/group slugs.
 SLUG_BAD_CHAR_RE = re.compile('[{}]'.format(SLUG_BAD_CHARS))
 
 # Regex that matches allowed characters in repo/group slugs.
 SLUG_GOOD_CHAR_RE = re.compile('[^{}]'.format(SLUG_BAD_CHARS))
 
 # Regex that matches whole repo/group slugs.
 SLUG_RE = re.compile('[^{}]+'.format(SLUG_BAD_CHARS))
 
 _license_cache = None
 
 
 def repo_name_slug(value):
     """
     Return slug of name of repository
     This function is called on each creation/modification
     of repository to prevent bad names in repo
     """
     replacement_char = '-'
 
     slug = remove_formatting(value)
     slug = SLUG_BAD_CHAR_RE.sub('', slug)
     slug = re.sub('[\s]+', '-', slug)
     slug = collapse(slug, replacement_char)
     return slug
 
 
 #==============================================================================
 # PERM DECORATOR HELPERS FOR EXTRACTING NAMES FOR PERM CHECKS
 #==============================================================================
 def get_repo_slug(request):
     _repo = ''
 
     if hasattr(request, 'db_repo'):
         # if our requests has set db reference use it for name, this
         # translates the example.com/_<id> into proper repo names
         _repo = request.db_repo.repo_name
     elif getattr(request, 'matchdict', None):
         # pyramid
         _repo = request.matchdict.get('repo_name')
 
     if _repo:
         _repo = _repo.rstrip('/')
     return _repo
 
 
 def get_repo_group_slug(request):
     _group = ''
     if hasattr(request, 'db_repo_group'):
         # if our requests has set db reference use it for name, this
         # translates the example.com/_<id> into proper repo group names
         _group = request.db_repo_group.group_name
     elif getattr(request, 'matchdict', None):
         # pyramid
         _group = request.matchdict.get('repo_group_name')
 
 
     if _group:
         _group = _group.rstrip('/')
     return _group
 
 
 def get_user_group_slug(request):
     _user_group = ''
 
     if hasattr(request, 'db_user_group'):
         _user_group = request.db_user_group.users_group_name
     elif getattr(request, 'matchdict', None):
         # pyramid
         _user_group = request.matchdict.get('user_group_id')
         _user_group_name = request.matchdict.get('user_group_name')
         try:
             if _user_group:
                 _user_group = UserGroup.get(_user_group)
             elif _user_group_name:
                 _user_group = UserGroup.get_by_group_name(_user_group_name)
 
             if _user_group:
                 _user_group = _user_group.users_group_name
         except Exception:
             log.exception('Failed to get user group by id and name')
             # catch all failures here
             return None
 
     return _user_group
 
 
 def get_filesystem_repos(path, recursive=False, skip_removed_repos=True):
     """
     Scans given path for repos and return (name,(type,path)) tuple
 
     :param path: path to scan for repositories
     :param recursive: recursive search and return names with subdirs in front
     """
 
     # remove ending slash for better results
     path = path.rstrip(os.sep)
     log.debug('now scanning in %s location recursive:%s...', path, recursive)
 
     def _get_repos(p):
         dirpaths = _get_dirpaths(p)
         if not _is_dir_writable(p):
             log.warning('repo path without write access: %s', p)
 
         for dirpath in dirpaths:
             if os.path.isfile(os.path.join(p, dirpath)):
                 continue
             cur_path = os.path.join(p, dirpath)
 
             # skip removed repos
             if skip_removed_repos and REMOVED_REPO_PAT.match(dirpath):
                 continue
 
             #skip .<somethin> dirs
             if dirpath.startswith('.'):
                 continue
 
             try:
                 scm_info = get_scm(cur_path)
                 yield scm_info[1].split(path, 1)[-1].lstrip(os.sep), scm_info
             except VCSError:
                 if not recursive:
                     continue
                 #check if this dir containts other repos for recursive scan
                 rec_path = os.path.join(p, dirpath)
                 if os.path.isdir(rec_path):
                     for inner_scm in _get_repos(rec_path):
                         yield inner_scm
 
     return _get_repos(path)
 
 
 def _get_dirpaths(p):
     try:
         # OS-independable way of checking if we have at least read-only
         # access or not.
         dirpaths = os.listdir(p)
     except OSError:
         log.warning('ignoring repo path without read access: %s', p)
         return []
 
     # os.listpath has a tweak: If a unicode is passed into it, then it tries to
     # decode paths and suddenly returns unicode objects itself. The items it
     # cannot decode are returned as strings and cause issues.
     #
     # Those paths are ignored here until a solid solution for path handling has
     # been built.
     expected_type = type(p)
 
     def _has_correct_type(item):
         if type(item) is not expected_type:
             log.error(
                 u"Ignoring path %s since it cannot be decoded into unicode.",
                 # Using "repr" to make sure that we see the byte value in case
                 # of support.
                 repr(item))
             return False
         return True
 
     dirpaths = [item for item in dirpaths if _has_correct_type(item)]
 
     return dirpaths
 
 
 def _is_dir_writable(path):
     """
     Probe if `path` is writable.
 
     Due to trouble on Cygwin / Windows, this is actually probing if it is
     possible to create a file inside of `path`, stat does not produce reliable
     results in this case.
     """
     try:
         with tempfile.TemporaryFile(dir=path):
             pass
     except OSError:
         return False
     return True
 
 
 def is_valid_repo(repo_name, base_path, expect_scm=None, explicit_scm=None, config=None):
     """
     Returns True if given path is a valid repository False otherwise.
     If expect_scm param is given also, compare if given scm is the same
     as expected from scm parameter. If explicit_scm is given don't try to
     detect the scm, just use the given one to check if repo is valid
 
     :param repo_name:
     :param base_path:
     :param expect_scm:
     :param explicit_scm:
     :param config:
 
     :return True: if given path is a valid repository
     """
     full_path = os.path.join(safe_str(base_path), safe_str(repo_name))
     log.debug('Checking if `%s` is a valid path for repository. '
               'Explicit type: %s', repo_name, explicit_scm)
 
     try:
         if explicit_scm:
             detected_scms = [get_scm_backend(explicit_scm)(
                 full_path, config=config).alias]
         else:
             detected_scms = get_scm(full_path)
 
         if expect_scm:
             return detected_scms[0] == expect_scm
         log.debug('path: %s is an vcs object:%s', full_path, detected_scms)
         return True
     except VCSError:
         log.debug('path: %s is not a valid repo !', full_path)
         return False
 
 
 def is_valid_repo_group(repo_group_name, base_path, skip_path_check=False):
     """
     Returns True if given path is a repository group, False otherwise
 
     :param repo_name:
     :param base_path:
     """
     full_path = os.path.join(safe_str(base_path), safe_str(repo_group_name))
     log.debug('Checking if `%s` is a valid path for repository group',
               repo_group_name)
 
     # check if it's not a repo
     if is_valid_repo(repo_group_name, base_path):
         log.debug('Repo called %s exist, it is not a valid '
                   'repo group' % repo_group_name)
         return False
 
     try:
         # we need to check bare git repos at higher level
         # since we might match branches/hooks/info/objects or possible
         # other things inside bare git repo
         scm_ = get_scm(os.path.dirname(full_path))
         log.debug('path: %s is a vcs object:%s, not valid '
                   'repo group' % (full_path, scm_))
         return False
     except VCSError:
         pass
 
     # check if it's a valid path
     if skip_path_check or os.path.isdir(full_path):
         log.debug('path: %s is a valid repo group !', full_path)
         return True
 
     log.debug('path: %s is not a valid repo group !', full_path)
     return False
 
 
 def ask_ok(prompt, retries=4, complaint='[y]es or [n]o please!'):
     while True:
         ok = raw_input(prompt)
         if ok.lower() in ('y', 'ye', 'yes'):
             return True
         if ok.lower() in ('n', 'no', 'nop', 'nope'):
             return False
         retries = retries - 1
         if retries < 0:
             raise IOError
         print(complaint)
 
 # propagated from mercurial documentation
 ui_sections = [
     'alias', 'auth',
     'decode/encode', 'defaults',
     'diff', 'email',
     'extensions', 'format',
     'merge-patterns', 'merge-tools',
     'hooks', 'http_proxy',
     'smtp', 'patch',
     'paths', 'profiling',
     'server', 'trusted',
     'ui', 'web', ]
 
 
 def config_data_from_db(clear_session=True, repo=None):
     """
     Read the configuration data from the database and return configuration
     tuples.
     """
     from rhodecode.model.settings import VcsSettingsModel
 
     config = []
 
     sa = meta.Session()
     settings_model = VcsSettingsModel(repo=repo, sa=sa)
 
     ui_settings = settings_model.get_ui_settings()
 
     ui_data = []
     for setting in ui_settings:
         if setting.active:
             ui_data.append((setting.section, setting.key, setting.value))
             config.append((
                 safe_str(setting.section), safe_str(setting.key),
                 safe_str(setting.value)))
         if setting.key == 'push_ssl':
             # force set push_ssl requirement to False, rhodecode
             # handles that
             config.append((
                 safe_str(setting.section), safe_str(setting.key), False))
     log.debug(
         'settings ui from db: %s',
         ','.join(map(lambda s: '[{}] {}={}'.format(*s), ui_data)))
     if clear_session:
         meta.Session.remove()
 
     # TODO: mikhail: probably it makes no sense to re-read hooks information.
     # It's already there and activated/deactivated
     skip_entries = []
     enabled_hook_classes = get_enabled_hook_classes(ui_settings)
     if 'pull' not in enabled_hook_classes:
         skip_entries.append(('hooks', RhodeCodeUi.HOOK_PRE_PULL))
     if 'push' not in enabled_hook_classes:
         skip_entries.append(('hooks', RhodeCodeUi.HOOK_PRE_PUSH))
         skip_entries.append(('hooks', RhodeCodeUi.HOOK_PRETX_PUSH))
         skip_entries.append(('hooks', RhodeCodeUi.HOOK_PUSH_KEY))
 
     config = [entry for entry in config if entry[:2] not in skip_entries]
 
     return config
 
 
 def make_db_config(clear_session=True, repo=None):
     """
     Create a :class:`Config` instance based on the values in the database.
     """
     config = Config()
     config_data = config_data_from_db(clear_session=clear_session, repo=repo)
     for section, option, value in config_data:
         config.set(section, option, value)
     return config
 
 
 def get_enabled_hook_classes(ui_settings):
     """
     Return the enabled hook classes.
 
     :param ui_settings: List of ui_settings as returned
         by :meth:`VcsSettingsModel.get_ui_settings`
 
     :return: a list with the enabled hook classes. The order is not guaranteed.
     :rtype: list
     """
     enabled_hooks = []
     active_hook_keys = [
         key for section, key, value, active in ui_settings
         if section == 'hooks' and active]
 
     hook_names = {
         RhodeCodeUi.HOOK_PUSH: 'push',
         RhodeCodeUi.HOOK_PULL: 'pull',
         RhodeCodeUi.HOOK_REPO_SIZE: 'repo_size'
     }
 
     for key in active_hook_keys:
         hook = hook_names.get(key)
         if hook:
             enabled_hooks.append(hook)
 
     return enabled_hooks
 
 
 def set_rhodecode_config(config):
     """
     Updates pyramid config with new settings from database
 
     :param config:
     """
     from rhodecode.model.settings import SettingsModel
     app_settings = SettingsModel().get_all_settings()
 
     for k, v in app_settings.items():
         config[k] = v
 
 
 def get_rhodecode_realm():
     """
     Return the rhodecode realm from database.
     """
     from rhodecode.model.settings import SettingsModel
     realm = SettingsModel().get_setting_by_name('realm')
     return safe_str(realm.app_settings_value)
 
 
 def get_rhodecode_base_path():
     """
     Returns the base path. The base path is the filesystem path which points
     to the repository store.
     """
     from rhodecode.model.settings import SettingsModel
     paths_ui = SettingsModel().get_ui_by_section_and_key('paths', '/')
     return safe_str(paths_ui.ui_value)
 
 
 def map_groups(path):
     """
     Given a full path to a repository, create all nested groups that this
     repo is inside. This function creates parent-child relationships between
     groups and creates default perms for all new groups.
 
     :param paths: full path to repository
     """
     from rhodecode.model.repo_group import RepoGroupModel
     sa = meta.Session()
     groups = path.split(Repository.NAME_SEP)
     parent = None
     group = None
 
     # last element is repo in nested groups structure
     groups = groups[:-1]
     rgm = RepoGroupModel(sa)
     owner = User.get_first_super_admin()
     for lvl, group_name in enumerate(groups):
         group_name = '/'.join(groups[:lvl] + [group_name])
         group = RepoGroup.get_by_group_name(group_name)
         desc = '%s group' % group_name
 
         # skip folders that are now removed repos
         if REMOVED_REPO_PAT.match(group_name):
             break
 
         if group is None:
             log.debug('creating group level: %s group_name: %s',
                        lvl, group_name)
             group = RepoGroup(group_name, parent)
             group.group_description = desc
             group.user = owner
             sa.add(group)
             perm_obj = rgm._create_default_perms(group)
             sa.add(perm_obj)
             sa.flush()
 
         parent = group
     return group
 
 
 def repo2db_mapper(initial_repo_list, remove_obsolete=False):
     """
     maps all repos given in initial_repo_list, non existing repositories
     are created, if remove_obsolete is True it also checks for db entries
     that are not in initial_repo_list and removes them.
 
     :param initial_repo_list: list of repositories found by scanning methods
     :param remove_obsolete: check for obsolete entries in database
     """
     from rhodecode.model.repo import RepoModel
     from rhodecode.model.repo_group import RepoGroupModel
     from rhodecode.model.settings import SettingsModel
 
     sa = meta.Session()
     repo_model = RepoModel()
     user = User.get_first_super_admin()
     added = []
 
     # creation defaults
     defs = SettingsModel().get_default_repo_settings(strip_prefix=True)
     enable_statistics = defs.get('repo_enable_statistics')
     enable_locking = defs.get('repo_enable_locking')
     enable_downloads = defs.get('repo_enable_downloads')
     private = defs.get('repo_private')
 
     for name, repo in initial_repo_list.items():
         group = map_groups(name)
         unicode_name = safe_unicode(name)
         db_repo = repo_model.get_by_repo_name(unicode_name)
         # found repo that is on filesystem not in RhodeCode database
         if not db_repo:
             log.info('repository %s not found, creating now', name)
             added.append(name)
             desc = (repo.description
                     if repo.description != 'unknown'
                     else '%s repository' % name)
 
             db_repo = repo_model._create_repo(
                 repo_name=name,
                 repo_type=repo.alias,
                 description=desc,
                 repo_group=getattr(group, 'group_id', None),
                 owner=user,
                 enable_locking=enable_locking,
                 enable_downloads=enable_downloads,
                 enable_statistics=enable_statistics,
                 private=private,
                 state=Repository.STATE_CREATED
             )
             sa.commit()
             # we added that repo just now, and make sure we updated server info
             if db_repo.repo_type == 'git':
                 git_repo = db_repo.scm_instance()
                 # update repository server-info
                 log.debug('Running update server info')
                 git_repo._update_server_info()
 
             db_repo.update_commit_cache()
 
         config = db_repo._config
         config.set('extensions', 'largefiles', '')
         repo = db_repo.scm_instance(config=config)
         repo.install_hooks()
 
     removed = []
     if remove_obsolete:
         # remove from database those repositories that are not in the filesystem
         for repo in sa.query(Repository).all():
             if repo.repo_name not in initial_repo_list.keys():
                 log.debug("Removing non-existing repository found in db `%s`",
                           repo.repo_name)
                 try:
                     RepoModel(sa).delete(repo, forks='detach', fs_remove=False)
                     sa.commit()
                     removed.append(repo.repo_name)
                 except Exception:
                     # don't hold further removals on error
                     log.error(traceback.format_exc())
                     sa.rollback()
 
         def splitter(full_repo_name):
             _parts = full_repo_name.rsplit(RepoGroup.url_sep(), 1)
             gr_name = None
             if len(_parts) == 2:
                 gr_name = _parts[0]
             return gr_name
 
         initial_repo_group_list = [splitter(x) for x in
                                    initial_repo_list.keys() if splitter(x)]
 
         # remove from database those repository groups that are not in the
         # filesystem due to parent child relationships we need to delete them
         # in a specific order of most nested first
         all_groups = [x.group_name for x in sa.query(RepoGroup).all()]
         nested_sort = lambda gr: len(gr.split('/'))
         for group_name in sorted(all_groups, key=nested_sort, reverse=True):
             if group_name not in initial_repo_group_list:
                 repo_group = RepoGroup.get_by_group_name(group_name)
                 if (repo_group.children.all() or
                     not RepoGroupModel().check_exist_filesystem(
                         group_name=group_name, exc_on_failure=False)):
                     continue
 
                 log.info(
                     'Removing non-existing repository group found in db `%s`',
                     group_name)
                 try:
                     RepoGroupModel(sa).delete(group_name, fs_remove=False)
                     sa.commit()
                     removed.append(group_name)
                 except Exception:
                     # don't hold further removals on error
                     log.exception(
                         'Unable to remove repository group `%s`',
                         group_name)
                     sa.rollback()
                     raise
 
     return added, removed
 
 
 def load_rcextensions(root_path):
     import rhodecode
     from rhodecode.config import conf
 
     path = os.path.join(root_path, 'rcextensions', '__init__.py')
     if os.path.isfile(path):
         rcext = create_module('rc', path)
         EXT = rhodecode.EXTENSIONS = rcext
         log.debug('Found rcextensions now loading %s...', rcext)
 
         # Additional mappings that are not present in the pygments lexers
         conf.LANGUAGES_EXTENSIONS_MAP.update(getattr(EXT, 'EXTRA_MAPPINGS', {}))
 
         # auto check if the module is not missing any data, set to default if is
         # this will help autoupdate new feature of rcext module
         #from rhodecode.config import rcextensions
         #for k in dir(rcextensions):
         #    if not k.startswith('_') and not hasattr(EXT, k):
         #        setattr(EXT, k, getattr(rcextensions, k))
 
 
 def get_custom_lexer(extension):
     """
     returns a custom lexer if it is defined in rcextensions module, or None
     if there's no custom lexer defined
     """
     import rhodecode
     from pygments import lexers
 
     # custom override made by RhodeCode
     if extension in ['mako']:
         return lexers.get_lexer_by_name('html+mako')
 
     # check if we didn't define this extension as other lexer
     extensions = rhodecode.EXTENSIONS and getattr(rhodecode.EXTENSIONS, 'EXTRA_LEXERS', None)
     if extensions and extension in rhodecode.EXTENSIONS.EXTRA_LEXERS:
         _lexer_name = rhodecode.EXTENSIONS.EXTRA_LEXERS[extension]
         return lexers.get_lexer_by_name(_lexer_name)
 
 
 #==============================================================================
 # TEST FUNCTIONS AND CREATORS
 #==============================================================================
 def create_test_index(repo_location, config):
     """
     Makes default test index.
     """
     import rc_testdata
 
     rc_testdata.extract_search_index(
         'vcs_search_index', os.path.dirname(config['search.location']))
 
 
 def create_test_directory(test_path):
     """
     Create test directory if it doesn't exist.
     """
     if not os.path.isdir(test_path):
         log.debug('Creating testdir %s', test_path)
         os.makedirs(test_path)
 
 
 def create_test_database(test_path, config):
     """
     Makes a fresh database.
     """
     from rhodecode.lib.db_manage import DbManage
 
     # PART ONE create db
     dbconf = config['sqlalchemy.db1.url']
     log.debug('making test db %s', dbconf)
 
     dbmanage = DbManage(log_sql=False, dbconf=dbconf, root=config['here'],
                         tests=True, cli_args={'force_ask': True})
     dbmanage.create_tables(override=True)
     dbmanage.set_db_version()
     # for tests dynamically set new root paths based on generated content
     dbmanage.create_settings(dbmanage.config_prompt(test_path))
     dbmanage.create_default_user()
     dbmanage.create_test_admin_and_users()
     dbmanage.create_permissions()
     dbmanage.populate_default_permissions()
     Session().commit()
 
 
 def create_test_repositories(test_path, config):
     """
     Creates test repositories in the temporary directory. Repositories are
     extracted from archives within the rc_testdata package.
     """
     import rc_testdata
     from rhodecode.tests import HG_REPO, GIT_REPO, SVN_REPO
 
     log.debug('making test vcs repositories')
 
     idx_path = config['search.location']
     data_path = config['cache_dir']
 
     # clean index and data
     if idx_path and os.path.exists(idx_path):
         log.debug('remove %s', idx_path)
         shutil.rmtree(idx_path)
 
     if data_path and os.path.exists(data_path):
         log.debug('remove %s', data_path)
         shutil.rmtree(data_path)
 
     rc_testdata.extract_hg_dump('vcs_test_hg', jn(test_path, HG_REPO))
     rc_testdata.extract_git_dump('vcs_test_git', jn(test_path, GIT_REPO))
 
     # Note: Subversion is in the process of being integrated with the system,
     # until we have a properly packed version of the test svn repository, this
     # tries to copy over the repo from a package "rc_testdata"
     svn_repo_path = rc_testdata.get_svn_repo_archive()
     with tarfile.open(svn_repo_path) as tar:
         tar.extractall(jn(test_path, SVN_REPO))
 
 
 def password_changed(auth_user, session):
     # Never report password change in case of default user or anonymous user.
     if auth_user.username == User.DEFAULT_USER or auth_user.user_id is None:
         return False
 
     password_hash = md5(auth_user.password) if auth_user.password else None
     rhodecode_user = session.get('rhodecode_user', {})
     session_password_hash = rhodecode_user.get('password', '')
     return password_hash != session_password_hash
 
 
 def read_opensource_licenses():
     global _license_cache
 
     if not _license_cache:
         licenses = pkg_resources.resource_string(
             'rhodecode', 'config/licenses.json')
         _license_cache = json.loads(licenses)
 
     return _license_cache
 
 
 def generate_platform_uuid():
     """
     Generates platform UUID based on it's name
     """
     import platform
 
     try:
         uuid_list = [platform.platform()]
         return hashlib.sha256(':'.join(uuid_list)).hexdigest()
     except Exception as e:
         log.error('Failed to generate host uuid: %s' % e)
         return 'UNDEFINED'

rhodecode/subscribers.py

@@ -1,322 +1,324 b''
 # -*- coding: utf-8 -*-
 
 # Copyright (C) 2010-2018 RhodeCode GmbH
 #
 # This program is free software: you can redistribute it and/or modify
 # it under the terms of the GNU Affero General Public License, version 3
 # (only), as published by the Free Software Foundation.
 #
 # This program is distributed in the hope that it will be useful,
 # but WITHOUT ANY WARRANTY; without even the implied warranty of
 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 # GNU General Public License for more details.
 #
 # You should have received a copy of the GNU Affero General Public License
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 # This program is dual-licensed. If you wish to learn more about the
 # RhodeCode Enterprise Edition, including its added features, Support services,
 # and proprietary license terms, please see https://rhodecode.com/licenses/
 import io
 import re
 import datetime
 import logging
 import Queue
 import subprocess32
 import os
 
 
 from dateutil.parser import parse
 from pyramid.i18n import get_localizer
 from pyramid.threadlocal import get_current_request
 from pyramid.interfaces import IRoutesMapper
 from pyramid.settings import asbool
 from pyramid.path import AssetResolver
 from threading import Thread
 
 from rhodecode.translation import _ as tsf
 from rhodecode.config.jsroutes import generate_jsroutes_content
 from rhodecode.lib import auth
 from rhodecode.lib.base import get_auth_user
 
 
 import rhodecode
 
 
 log = logging.getLogger(__name__)
 
 
 def add_renderer_globals(event):
     from rhodecode.lib import helpers
 
     # TODO: When executed in pyramid view context the request is not available
     # in the event. Find a better solution to get the request.
     request = event['request'] or get_current_request()
 
     # Add Pyramid translation as '_' to context
     event['_'] = request.translate
     event['_ungettext'] = request.plularize
     event['h'] = helpers
 
 
 def add_localizer(event):
     request = event.request
     localizer = request.localizer
 
     def auto_translate(*args, **kwargs):
         return localizer.translate(tsf(*args, **kwargs))
 
     request.translate = auto_translate
     request.plularize = localizer.pluralize
 
 
 def set_user_lang(event):
     request = event.request
     cur_user = getattr(request, 'user', None)
 
     if cur_user:
         user_lang = cur_user.get_instance().user_data.get('language')
         if user_lang:
             log.debug('lang: setting current user:%s language to: %s', cur_user, user_lang)
             event.request._LOCALE_ = user_lang
 
 
 def add_request_user_context(event):
     """
     Adds auth user into request context
     """
     request = event.request
+    # access req_id as soon as possible
+    req_id = request.req_id
 
     if hasattr(request, 'vcs_call'):
         # skip vcs calls
         return
 
     if hasattr(request, 'rpc_method'):
         # skip api calls
         return
 
     auth_user = get_auth_user(request)
     request.user = auth_user
     request.environ['rc_auth_user'] = auth_user
-
+    request.environ['rc_req_id'] = req_id
 
 def inject_app_settings(event):
     settings = event.app.registry.settings
     # inject info about available permissions
     auth.set_available_permissions(settings)
 
 
 def scan_repositories_if_enabled(event):
     """
     This is subscribed to the `pyramid.events.ApplicationCreated` event. It
     does a repository scan if enabled in the settings.
     """
     settings = event.app.registry.settings
     vcs_server_enabled = settings['vcs.server.enable']
     import_on_startup = settings['startup.import_repos']
     if vcs_server_enabled and import_on_startup:
         from rhodecode.model.scm import ScmModel
         from rhodecode.lib.utils import repo2db_mapper, get_rhodecode_base_path
         repositories = ScmModel().repo_scan(get_rhodecode_base_path())
         repo2db_mapper(repositories, remove_obsolete=False)
 
 
 def write_metadata_if_needed(event):
     """
     Writes upgrade metadata
     """
     import rhodecode
     from rhodecode.lib import system_info
     from rhodecode.lib import ext_json
 
     fname = '.rcmetadata.json'
     ini_loc = os.path.dirname(rhodecode.CONFIG.get('__file__'))
     metadata_destination = os.path.join(ini_loc, fname)
 
     def get_update_age():
         now = datetime.datetime.utcnow()
 
         with open(metadata_destination, 'rb') as f:
             data = ext_json.json.loads(f.read())
             if 'created_on' in data:
                 update_date = parse(data['created_on'])
                 diff = now - update_date
                 return diff.total_seconds() / 60.0
 
         return 0
 
     def write():
         configuration = system_info.SysInfo(
             system_info.rhodecode_config)()['value']
         license_token = configuration['config']['license_token']
 
         setup = dict(
             workers=configuration['config']['server:main'].get(
                 'workers', '?'),
             worker_type=configuration['config']['server:main'].get(
                 'worker_class', 'sync'),
         )
         dbinfo = system_info.SysInfo(system_info.database_info)()['value']
         del dbinfo['url']
 
         metadata = dict(
             desc='upgrade metadata info',
             license_token=license_token,
             created_on=datetime.datetime.utcnow().isoformat(),
             usage=system_info.SysInfo(system_info.usage_info)()['value'],
             platform=system_info.SysInfo(system_info.platform_type)()['value'],
             database=dbinfo,
             cpu=system_info.SysInfo(system_info.cpu)()['value'],
             memory=system_info.SysInfo(system_info.memory)()['value'],
             setup=setup
         )
 
         with open(metadata_destination, 'wb') as f:
             f.write(ext_json.json.dumps(metadata))
 
     settings = event.app.registry.settings
     if settings.get('metadata.skip'):
         return
 
     # only write this every 24h, workers restart caused unwanted delays
     try:
         age_in_min = get_update_age()
     except Exception:
         age_in_min = 0
 
     if age_in_min > 60 * 60 * 24:
         return
 
     try:
         write()
     except Exception:
         pass
 
 
 def write_js_routes_if_enabled(event):
     registry = event.app.registry
 
     mapper = registry.queryUtility(IRoutesMapper)
     _argument_prog = re.compile('\{(.*?)\}|:\((.*)\)')
 
     def _extract_route_information(route):
         """
         Convert a route into tuple(name, path, args), eg:
             ('show_user', '/profile/%(username)s', ['username'])
         """
 
         routepath = route.pattern
         pattern = route.pattern
 
         def replace(matchobj):
             if matchobj.group(1):
                 return "%%(%s)s" % matchobj.group(1).split(':')[0]
             else:
                 return "%%(%s)s" % matchobj.group(2)
 
         routepath = _argument_prog.sub(replace, routepath)
 
         if not routepath.startswith('/'):
             routepath = '/'+routepath
 
         return (
             route.name,
             routepath,
             [(arg[0].split(':')[0] if arg[0] != '' else arg[1])
               for arg in _argument_prog.findall(pattern)]
         )
 
     def get_routes():
         # pyramid routes
         for route in mapper.get_routes():
             if not route.name.startswith('__'):
                 yield _extract_route_information(route)
 
     if asbool(registry.settings.get('generate_js_files', 'false')):
         static_path = AssetResolver().resolve('rhodecode:public').abspath()
         jsroutes = get_routes()
         jsroutes_file_content = generate_jsroutes_content(jsroutes)
         jsroutes_file_path = os.path.join(
             static_path, 'js', 'rhodecode', 'routes.js')
 
         with io.open(jsroutes_file_path, 'w', encoding='utf-8') as f:
             f.write(jsroutes_file_content)
 
 
 class Subscriber(object):
     """
     Base class for subscribers to the pyramid event system.
     """
     def __call__(self, event):
         self.run(event)
 
     def run(self, event):
         raise NotImplementedError('Subclass has to implement this.')
 
 
 class AsyncSubscriber(Subscriber):
     """
     Subscriber that handles the execution of events in a separate task to not
     block the execution of the code which triggers the event. It puts the
     received events into a queue from which the worker process takes them in
     order.
     """
     def __init__(self):
         self._stop = False
         self._eventq = Queue.Queue()
         self._worker = self.create_worker()
         self._worker.start()
 
     def __call__(self, event):
         self._eventq.put(event)
 
     def create_worker(self):
         worker = Thread(target=self.do_work)
         worker.daemon = True
         return worker
 
     def stop_worker(self):
         self._stop = False
         self._eventq.put(None)
         self._worker.join()
 
     def do_work(self):
         while not self._stop:
             event = self._eventq.get()
             if event is not None:
                 self.run(event)
 
 
 class AsyncSubprocessSubscriber(AsyncSubscriber):
     """
     Subscriber that uses the subprocess32 module to execute a command if an
     event is received. Events are handled asynchronously.
     """
 
     def __init__(self, cmd, timeout=None):
         super(AsyncSubprocessSubscriber, self).__init__()
         self._cmd = cmd
         self._timeout = timeout
 
     def run(self, event):
         cmd = self._cmd
         timeout = self._timeout
         log.debug('Executing command %s.', cmd)
 
         try:
             output = subprocess32.check_output(
                 cmd, timeout=timeout, stderr=subprocess32.STDOUT)
             log.debug('Command finished %s', cmd)
             if output:
                 log.debug('Command output: %s', output)
         except subprocess32.TimeoutExpired as e:
             log.exception('Timeout while executing command.')
             if e.output:
                 log.error('Command output: %s', e.output)
         except subprocess32.CalledProcessError as e:
             log.exception('Error while executing command.')
             if e.output:
                 log.error('Command output: %s', e.output)
         except:
             log.exception(
                 'Exception while executing command %s.', cmd)