auth: use more consistent logging on failed logs.

- auth-token, auth-rhodecode uses info for OK, and warn for failed logins.
- using error logs can cause wrong expectations about failure to loging due to an error.

rhodecode/authentication/plugins/auth_rhodecode.py

@@ -1,143 +1,143 b''
 # -*- coding: utf-8 -*-
 
 # Copyright (C) 2012-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/
 
 """
 RhodeCode authentication plugin for built in internal auth
 """
 
 import logging
 
 from rhodecode.translation import _
 
 from rhodecode.authentication.base import RhodeCodeAuthPluginBase, hybrid_property
 from rhodecode.authentication.routes import AuthnPluginResourceBase
 from rhodecode.lib.utils2 import safe_str
 from rhodecode.model.db import User
 
 log = logging.getLogger(__name__)
 
 
 def plugin_factory(plugin_id, *args, **kwds):
     plugin = RhodeCodeAuthPlugin(plugin_id)
     return plugin
 
 
 class RhodecodeAuthnResource(AuthnPluginResourceBase):
     pass
 
 
 class RhodeCodeAuthPlugin(RhodeCodeAuthPluginBase):
 
     def includeme(self, config):
         config.add_authn_plugin(self)
         config.add_authn_resource(self.get_id(), RhodecodeAuthnResource(self))
         config.add_view(
             'rhodecode.authentication.views.AuthnPluginViewBase',
             attr='settings_get',
             renderer='rhodecode:templates/admin/auth/plugin_settings.mako',
             request_method='GET',
             route_name='auth_home',
             context=RhodecodeAuthnResource)
         config.add_view(
             'rhodecode.authentication.views.AuthnPluginViewBase',
             attr='settings_post',
             renderer='rhodecode:templates/admin/auth/plugin_settings.mako',
             request_method='POST',
             route_name='auth_home',
             context=RhodecodeAuthnResource)
 
     def get_display_name(self):
         return _('Rhodecode')
 
     @hybrid_property
     def name(self):
         return "rhodecode"
 
     def user_activation_state(self):
         def_user_perms = User.get_default_user().AuthUser().permissions['global']
         return 'hg.register.auto_activate' in def_user_perms
 
     def allows_authentication_from(
             self, user, allows_non_existing_user=True,
             allowed_auth_plugins=None, allowed_auth_sources=None):
         """
         Custom method for this auth that doesn't accept non existing users.
         We know that user exists in our database.
         """
         allows_non_existing_user = False
         return super(RhodeCodeAuthPlugin, self).allows_authentication_from(
             user, allows_non_existing_user=allows_non_existing_user)
 
     def auth(self, userobj, username, password, settings, **kwargs):
         if not userobj:
             log.debug('userobj was:%s skipping' % (userobj, ))
             return None
         if userobj.extern_type != self.name:
             log.warning(
                 "userobj:%s extern_type mismatch got:`%s` expected:`%s`" %
                 (userobj, userobj.extern_type, self.name))
             return None
 
         user_attrs = {
             "username": userobj.username,
             "firstname": userobj.firstname,
             "lastname": userobj.lastname,
             "groups": [],
             'user_group_sync': False,
             "email": userobj.email,
             "admin": userobj.admin,
             "active": userobj.active,
             "active_from_extern": userobj.active,
             "extern_name": userobj.user_id,
             "extern_type": userobj.extern_type,
         }
 
         log.debug("User attributes:%s" % (user_attrs, ))
         if userobj.active:
             from rhodecode.lib import auth
             crypto_backend = auth.crypto_backend()
             password_encoded = safe_str(password)
             password_match, new_hash = crypto_backend.hash_check_with_upgrade(
                 password_encoded, userobj.password or '')
 
             if password_match and new_hash:
                 log.debug('user %s properly authenticated, but '
                           'requires hash change to bcrypt', userobj)
                 # if password match, and we use OLD deprecated hash,
                 # we should migrate this user hash password to the new hash
                 # we store the new returned by hash_check_with_upgrade function
                 user_attrs['_hash_migrate'] = new_hash
 
             if userobj.username == User.DEFAULT_USER and userobj.active:
                 log.info(
-                    'user `%s` authenticated correctly as anonymous user', userobj)
+                    'user `%s` authenticated correctly as anonymous user', userobj.username)
                 return user_attrs
 
             elif userobj.username == username and password_match:
-                log.info('user `%s` authenticated correctly', userobj)
+                log.info('user `%s` authenticated correctly', userobj.username)
                 return user_attrs
-            log.info("user %s had a bad password when "
-                     "authenticating on this plugin", userobj)
+            log.warn("user `%s` used a wrong password when "
+                     "authenticating on this plugin", userobj.username)
             return None
         else:
             log.warning(
                 'user `%s` failed to authenticate via %s, reason: account not '
                 'active.', username, self.name)
             return None

rhodecode/authentication/plugins/auth_token.py

@@ -1,147 +1,147 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/
 
 """
 RhodeCode authentication token plugin for built in internal auth
 """
 
 import logging
 
 from rhodecode.translation import _
 from rhodecode.authentication.base import (
     RhodeCodeAuthPluginBase, VCS_TYPE, hybrid_property)
 from rhodecode.authentication.routes import AuthnPluginResourceBase
 from rhodecode.model.db import User, UserApiKeys, Repository
 
 
 log = logging.getLogger(__name__)
 
 
 def plugin_factory(plugin_id, *args, **kwds):
     plugin = RhodeCodeAuthPlugin(plugin_id)
     return plugin
 
 
 class RhodecodeAuthnResource(AuthnPluginResourceBase):
     pass
 
 
 class RhodeCodeAuthPlugin(RhodeCodeAuthPluginBase):
     """
     Enables usage of authentication tokens for vcs operations.
     """
 
     def includeme(self, config):
         config.add_authn_plugin(self)
         config.add_authn_resource(self.get_id(), RhodecodeAuthnResource(self))
         config.add_view(
             'rhodecode.authentication.views.AuthnPluginViewBase',
             attr='settings_get',
             renderer='rhodecode:templates/admin/auth/plugin_settings.mako',
             request_method='GET',
             route_name='auth_home',
             context=RhodecodeAuthnResource)
         config.add_view(
             'rhodecode.authentication.views.AuthnPluginViewBase',
             attr='settings_post',
             renderer='rhodecode:templates/admin/auth/plugin_settings.mako',
             request_method='POST',
             route_name='auth_home',
             context=RhodecodeAuthnResource)
 
     def get_display_name(self):
         return _('Rhodecode Token Auth')
 
     @hybrid_property
     def name(self):
         return "authtoken"
 
     def user_activation_state(self):
         def_user_perms = User.get_default_user().AuthUser().permissions['global']
         return 'hg.register.auto_activate' in def_user_perms
 
     def allows_authentication_from(
             self, user, allows_non_existing_user=True,
             allowed_auth_plugins=None, allowed_auth_sources=None):
         """
         Custom method for this auth that doesn't accept empty users. And also
         allows users from all other active plugins to use it and also
         authenticate against it. But only via vcs mode
         """
         from rhodecode.authentication.base import get_authn_registry
         authn_registry = get_authn_registry()
 
         active_plugins = set(
             [x.name for x in authn_registry.get_plugins_for_authentication()])
         active_plugins.discard(self.name)
 
         allowed_auth_plugins = [self.name] + list(active_plugins)
         # only for vcs operations
         allowed_auth_sources = [VCS_TYPE]
 
         return super(RhodeCodeAuthPlugin, self).allows_authentication_from(
             user, allows_non_existing_user=False,
             allowed_auth_plugins=allowed_auth_plugins,
             allowed_auth_sources=allowed_auth_sources)
 
     def auth(self, userobj, username, password, settings, **kwargs):
         if not userobj:
             log.debug('userobj was:%s skipping' % (userobj, ))
             return None
 
         user_attrs = {
             "username": userobj.username,
             "firstname": userobj.firstname,
             "lastname": userobj.lastname,
             "groups": [],
             'user_group_sync': False,
             "email": userobj.email,
             "admin": userobj.admin,
             "active": userobj.active,
             "active_from_extern": userobj.active,
             "extern_name": userobj.user_id,
             "extern_type": userobj.extern_type,
         }
 
         log.debug('Authenticating user with args %s', user_attrs)
         if userobj.active:
             # calling context repo for token scopes
             scope_repo_id = None
             if self.acl_repo_name:
                 repo = Repository.get_by_repo_name(self.acl_repo_name)
                 scope_repo_id = repo.repo_id if repo else None
 
             token_match = userobj.authenticate_by_token(
                 password, roles=[UserApiKeys.ROLE_VCS],
                 scope_repo_id=scope_repo_id)
 
             if userobj.username == username and token_match:
                 log.info(
                     'user `%s` successfully authenticated via %s',
                     user_attrs['username'], self.name)
                 return user_attrs
-            log.error(
+            log.warn(
                 'user `%s` failed to authenticate via %s, reason: bad or '
                 'inactive token.', username, self.name)
         else:
             log.warning(
                 'user `%s` failed to authenticate via %s, reason: account not '
                 'active.', username, self.name)
         return None