##// END OF EJS Templates
logging: use lazy parameter evaluation in log calls.
marcink -
r3061:a44afbe5 default
parent child Browse files
Show More
@@ -204,7 +204,7 b' def request_view(request):'
204 204 message='Request from IP:%s not allowed' % (
205 205 request.rpc_ip_addr,))
206 206 else:
207 log.info('Access for IP:%s allowed' % (request.rpc_ip_addr,))
207 log.info('Access for IP:%s allowed', request.rpc_ip_addr)
208 208
209 209 # register our auth-user
210 210 request.rpc_user = auth_u
@@ -352,8 +352,7 b' def setup_request(request):'
352 352 request.rpc_params = json_body['args'] \
353 353 if isinstance(json_body['args'], dict) else {}
354 354
355 log.debug(
356 'method: %s, params: %s' % (request.rpc_method, request.rpc_params))
355 log.debug('method: %s, params: %s', request.rpc_method, request.rpc_params)
357 356 except KeyError as e:
358 357 raise JSONRPCError('Incorrect JSON data. Missing %s' % e)
359 358
@@ -405,8 +405,8 b' class GistView(BaseAppView):'
405 405 revision = self.request.GET.get('revision')
406 406
407 407 if revision != last_rev.raw_id:
408 log.error('Last revision %s is different then submitted %s'
409 % (revision, last_rev))
408 log.error('Last revision %s is different then submitted %s',
409 revision, last_rev)
410 410 # our gist has newer version than we
411 411 success = False
412 412
@@ -93,16 +93,16 b' def get_came_from(request):'
93 93 allowed_schemes = ['http', 'https']
94 94 default_came_from = h.route_path('home')
95 95 if parsed.scheme and parsed.scheme not in allowed_schemes:
96 log.error('Suspicious URL scheme detected %s for url %s' %
97 (parsed.scheme, parsed))
96 log.error('Suspicious URL scheme detected %s for url %s',
97 parsed.scheme, parsed)
98 98 came_from = default_came_from
99 99 elif parsed.netloc and request.host != parsed.netloc:
100 100 log.error('Suspicious NETLOC detected %s for url %s server url '
101 'is: %s' % (parsed.netloc, parsed, request.host))
101 'is: %s', parsed.netloc, parsed, request.host)
102 102 came_from = default_came_from
103 103 elif any(bad_str in parsed.path for bad_str in ('\r', '\n')):
104 log.error('Header injection detected `%s` for url %s server url ' %
105 (parsed.path, parsed))
104 log.error('Header injection detected `%s` for url %s server url ',
105 parsed.path, parsed)
106 106 came_from = default_came_from
107 107
108 108 return came_from or default_came_from
@@ -256,8 +256,8 b' class RepoCompareView(RepoAppView):'
256 256 # case we want a simple diff without incoming commits,
257 257 # previewing what will be merged.
258 258 # Make the diff on target repo (which is known to have target_ref)
259 log.debug('Using ancestor %s as source_ref instead of %s'
260 % (c.ancestor, source_ref))
259 log.debug('Using ancestor %s as source_ref instead of %s',
260 c.ancestor, source_ref)
261 261 source_repo = target_repo
262 262 source_commit = target_repo.get_commit(commit_id=c.ancestor)
263 263
@@ -98,8 +98,8 b' class StripView(RepoAppView):'
98 98 ScmModel().strip(
99 99 repo=self.db_repo,
100 100 commit_id=commit['rev'], branch=commit['branch'])
101 log.info('Stripped commit %s from repo `%s` by %s' % (
102 commit['rev'], self.db_repo_name, user))
101 log.info('Stripped commit %s from repo `%s` by %s',
102 commit['rev'], self.db_repo_name, user)
103 103 data[commit['rev']] = True
104 104
105 105 audit_logger.store_web(
@@ -108,6 +108,6 b' class StripView(RepoAppView):'
108 108
109 109 except Exception as e:
110 110 data[commit['rev']] = False
111 log.debug('Stripped commit %s from repo `%s` failed by %s, exeption %s' % (
112 commit['rev'], self.db_repo_name, user, e.message))
111 log.debug('Stripped commit %s from repo `%s` failed by %s, exeption %s',
112 commit['rev'], self.db_repo_name, user, e.message)
113 113 return data
@@ -241,16 +241,16 b' class RhodeCodeAuthPlugin(RhodeCodeExter'
241 241 log.debug('Empty username or password skipping...')
242 242 return None
243 243
244 log.debug("Crowd settings: \n%s" % (formatted_json(settings)))
244 log.debug("Crowd settings: \n%s", formatted_json(settings))
245 245 server = CrowdServer(**settings)
246 246 server.set_credentials(settings["app_name"], settings["app_password"])
247 247 crowd_user = server.user_auth(username, password)
248 log.debug("Crowd returned: \n%s" % (formatted_json(crowd_user)))
248 log.debug("Crowd returned: \n%s", formatted_json(crowd_user))
249 249 if not crowd_user["status"]:
250 250 return None
251 251
252 252 res = server.user_groups(crowd_user["name"])
253 log.debug("Crowd groups: \n%s" % (formatted_json(res)))
253 log.debug("Crowd groups: \n%s", formatted_json(res))
254 254 crowd_user["groups"] = [x["name"] for x in res["groups"]]
255 255
256 256 # old attrs fetched from RhodeCode database
@@ -280,6 +280,6 b' class RhodeCodeAuthPlugin(RhodeCodeExter'
280 280 for group in settings["admin_groups"]:
281 281 if group in user_attrs["groups"]:
282 282 user_attrs["admin"] = True
283 log.debug("Final crowd user object: \n%s" % (formatted_json(user_attrs)))
284 log.info('user `%s` authenticated correctly' % user_attrs['username'])
283 log.debug("Final crowd user object: \n%s", formatted_json(user_attrs))
284 log.info('user `%s` authenticated correctly', user_attrs['username'])
285 285 return user_attrs
@@ -125,24 +125,24 b' class RhodeCodeAuthPlugin(RhodeCodeExter'
125 125 username = None
126 126 environ = environ or {}
127 127 if not environ:
128 log.debug('got empty environ: %s' % environ)
128 log.debug('got empty environ: %s', environ)
129 129
130 130 settings = settings or {}
131 131 if settings.get('header'):
132 132 header = settings.get('header')
133 133 username = environ.get(header)
134 log.debug('extracted %s:%s' % (header, username))
134 log.debug('extracted %s:%s', header, username)
135 135
136 136 # fallback mode
137 137 if not username and settings.get('fallback_header'):
138 138 header = settings.get('fallback_header')
139 139 username = environ.get(header)
140 log.debug('extracted %s:%s' % (header, username))
140 log.debug('extracted %s:%s', header, username)
141 141
142 142 if username and str2bool(settings.get('clean_username')):
143 log.debug('Received username `%s` from headers' % username)
143 log.debug('Received username `%s` from headers', username)
144 144 username = self._clean_username(username)
145 log.debug('New cleanup user is:%s' % username)
145 log.debug('New cleanup user is:%s', username)
146 146 return username
147 147
148 148 def get_user(self, username=None, **kwargs):
@@ -221,5 +221,5 b' class RhodeCodeAuthPlugin(RhodeCodeExter'
221 221 'extern_type': extern_type,
222 222 }
223 223
224 log.info('user `%s` authenticated correctly' % user_attrs['username'])
224 log.info('user `%s` authenticated correctly', user_attrs['username'])
225 225 return user_attrs
@@ -134,10 +134,10 b' class RhodeCodeAuthPlugin(RhodeCodeExter'
134 134 try:
135 135 response = urllib2.urlopen(request)
136 136 except urllib2.HTTPError as e:
137 log.debug("HTTPError when requesting Jasig CAS (status code: %d)" % e.code)
137 log.debug("HTTPError when requesting Jasig CAS (status code: %d)", e.code)
138 138 return None
139 139 except urllib2.URLError as e:
140 log.debug("URLError when requesting Jasig CAS url: %s " % url)
140 log.debug("URLError when requesting Jasig CAS url: %s ", url)
141 141 return None
142 142
143 143 # old attrs fetched from RhodeCode database
@@ -163,5 +163,5 b' class RhodeCodeAuthPlugin(RhodeCodeExter'
163 163 'extern_type': extern_type,
164 164 }
165 165
166 log.info('user `%s` authenticated correctly' % user_attrs['username'])
166 log.info('user `%s` authenticated correctly', user_attrs['username'])
167 167 return user_attrs
@@ -115,10 +115,10 b' class RhodeCodeAuthPlugin(RhodeCodeExter'
115 115 auth_result = _pam.authenticate(username, password, settings["service"])
116 116
117 117 if not auth_result:
118 log.error("PAM was unable to authenticate user: %s" % (username, ))
118 log.error("PAM was unable to authenticate user: %s", username)
119 119 return None
120 120
121 log.debug('Got PAM response %s' % (auth_result, ))
121 log.debug('Got PAM response %s', auth_result)
122 122
123 123 # old attrs fetched from RhodeCode database
124 124 default_email = "%s@%s" % (username, socket.gethostname())
@@ -157,5 +157,5 b' class RhodeCodeAuthPlugin(RhodeCodeExter'
157 157 pass
158 158
159 159 log.debug("pamuser: %s", user_attrs)
160 log.info('user `%s` authenticated correctly' % user_attrs['username'])
160 log.info('user `%s` authenticated correctly', user_attrs['username'])
161 161 return user_attrs
@@ -87,12 +87,12 b' class RhodeCodeAuthPlugin(RhodeCodeAuthP'
87 87
88 88 def auth(self, userobj, username, password, settings, **kwargs):
89 89 if not userobj:
90 log.debug('userobj was:%s skipping' % (userobj, ))
90 log.debug('userobj was:%s skipping', userobj)
91 91 return None
92 92 if userobj.extern_type != self.name:
93 93 log.warning(
94 "userobj:%s extern_type mismatch got:`%s` expected:`%s`" %
95 (userobj, userobj.extern_type, self.name))
94 "userobj:%s extern_type mismatch got:`%s` expected:`%s`",
95 userobj, userobj.extern_type, self.name)
96 96 return None
97 97
98 98 user_attrs = {
@@ -109,7 +109,7 b' class RhodeCodeAuthPlugin(RhodeCodeAuthP'
109 109 "extern_type": userobj.extern_type,
110 110 }
111 111
112 log.debug("User attributes:%s" % (user_attrs, ))
112 log.debug("User attributes:%s", user_attrs)
113 113 if userobj.active:
114 114 from rhodecode.lib import auth
115 115 crypto_backend = auth.crypto_backend()
@@ -103,7 +103,7 b' class RhodeCodeAuthPlugin(RhodeCodeAuthP'
103 103
104 104 def auth(self, userobj, username, password, settings, **kwargs):
105 105 if not userobj:
106 log.debug('userobj was:%s skipping' % (userobj, ))
106 log.debug('userobj was:%s skipping', userobj)
107 107 return None
108 108
109 109 user_attrs = {
@@ -133,7 +133,7 b' def _commits_as_dict(event, commit_ids, '
133 133 missing_commits = set(commit_ids) - set(c['raw_id'] for c in commits)
134 134 if missing_commits:
135 135 log.error('Inconsistent repository state. '
136 'Missing commits: %s' % ', '.join(missing_commits))
136 'Missing commits: %s', ', '.join(missing_commits))
137 137
138 138 return commits
139 139
@@ -66,8 +66,8 b' def integrations_event_handler(event):'
66 66 exc_info = sys.exc_info()
67 67 store_exception(id(exc_info), exc_info)
68 68 log.exception(
69 'failure occurred when sending event %s to integration %s' % (
70 event, integration))
69 'failure occurred when sending event %s to integration %s',
70 event, integration)
71 71
72 72
73 73 def includeme(config):
@@ -31,8 +31,7 b' class IntegrationTypeRegistry(collection'
31 31 key = IntegrationType.key
32 32 if key in self:
33 33 log.debug(
34 'Overriding existing integration type %s (%s) with %s' % (
35 self[key], key, IntegrationType))
34 'Overriding existing integration type %s (%s) with %s',
35 self[key], key, IntegrationType)
36 36
37 37 self[key] = IntegrationType
38
@@ -119,11 +119,11 b' class HipchatIntegrationType(Integration'
119 119
120 120 def send_event(self, event):
121 121 if event.__class__ not in self.valid_events:
122 log.debug('event not valid: %r' % event)
122 log.debug('event not valid: %r', event)
123 123 return
124 124
125 125 if event.name not in self.settings['events']:
126 log.debug('event ignored: %r' % event)
126 log.debug('event ignored: %r', event)
127 127 return
128 128
129 129 data = event.as_dict()
@@ -131,7 +131,7 b' class HipchatIntegrationType(Integration'
131 131 text = '<b>%s<b> caused a <b>%s</b> event' % (
132 132 data['actor']['username'], event.name)
133 133
134 log.debug('handling hipchat event for %s' % event.name)
134 log.debug('handling hipchat event for %s', event.name)
135 135
136 136 if isinstance(event, events.PullRequestCommentEvent):
137 137 text = self.format_pull_request_comment_event(event, data)
@@ -144,7 +144,7 b' class HipchatIntegrationType(Integration'
144 144 elif isinstance(event, events.RepoCreateEvent):
145 145 text = self.format_repo_create_event(data)
146 146 else:
147 log.error('unhandled event type: %r' % event)
147 log.error('unhandled event type: %r', event)
148 148
149 149 run_task(post_text_to_hipchat, self.settings, text)
150 150
@@ -242,7 +242,7 b' class HipchatIntegrationType(Integration'
242 242
243 243 @async_task(ignore_result=True, base=RequestContextTask)
244 244 def post_text_to_hipchat(settings, text):
245 log.debug('sending %s to hipchat %s' % (text, settings['server_url']))
245 log.debug('sending %s to hipchat %s', text, settings['server_url'])
246 246 json_message = {
247 247 "message": text,
248 248 "color": settings.get('color', 'yellow'),
@@ -110,11 +110,11 b' class SlackIntegrationType(IntegrationTy'
110 110
111 111 def send_event(self, event):
112 112 if event.__class__ not in self.valid_events:
113 log.debug('event not valid: %r' % event)
113 log.debug('event not valid: %r', event)
114 114 return
115 115
116 116 if event.name not in self.settings['events']:
117 log.debug('event ignored: %r' % event)
117 log.debug('event ignored: %r', event)
118 118 return
119 119
120 120 data = event.as_dict()
@@ -127,7 +127,7 b' class SlackIntegrationType(IntegrationTy'
127 127 fields = None
128 128 overrides = None
129 129
130 log.debug('handling slack event for %s' % event.name)
130 log.debug('handling slack event for %s', event.name)
131 131
132 132 if isinstance(event, events.PullRequestCommentEvent):
133 133 (title, text, fields, overrides) \
@@ -141,7 +141,7 b' class SlackIntegrationType(IntegrationTy'
141 141 elif isinstance(event, events.RepoCreateEvent):
142 142 title, text = self.format_repo_create_event(data)
143 143 else:
144 log.error('unhandled event type: %r' % event)
144 log.error('unhandled event type: %r', event)
145 145
146 146 run_task(post_text_to_slack, self.settings, title, text, fields, overrides)
147 147
@@ -314,8 +314,7 b' def html_to_slack_links(message):'
314 314
315 315 @async_task(ignore_result=True, base=RequestContextTask)
316 316 def post_text_to_slack(settings, title, text, fields=None, overrides=None):
317 log.debug('sending %s (%s) to slack %s' % (
318 title, text, settings['service']))
317 log.debug('sending %s (%s) to slack %s', title, text, settings['service'])
319 318
320 319 fields = fields or []
321 320 overrides = overrides or {}
@@ -171,11 +171,11 b' class WebhookIntegrationType(Integration'
171 171 'handling event %s with Webhook integration %s', event.name, self)
172 172
173 173 if event.__class__ not in self.valid_events:
174 log.debug('event not valid: %r' % event)
174 log.debug('event not valid: %r', event)
175 175 return
176 176
177 177 if event.name not in self.settings['events']:
178 log.debug('event ignored: %r' % event)
178 log.debug('event ignored: %r', event)
179 179 return
180 180
181 181 data = event.as_dict()
@@ -979,7 +979,7 b' def allowed_auth_token_access(view_name,'
979 979 }
980 980
981 981 log.debug(
982 'Allowed views for AUTH TOKEN access: %s' % (whitelist,))
982 'Allowed views for AUTH TOKEN access: %s', whitelist)
983 983 auth_token_access_valid = False
984 984
985 985 for entry in whitelist:
@@ -998,8 +998,9 b' def allowed_auth_token_access(view_name,'
998 998 break
999 999
1000 1000 if auth_token_access_valid:
1001 log.debug('view: `%s` matches entry in whitelist: %s'
1002 % (view_name, whitelist))
1001 log.debug('view: `%s` matches entry in whitelist: %s',
1002 view_name, whitelist)
1003
1003 1004 else:
1004 1005 msg = ('view: `%s` does *NOT* match any entry in whitelist: %s'
1005 1006 % (view_name, whitelist))
@@ -1190,7 +1191,7 b' class AuthUser(object):'
1190 1191
1191 1192 log.debug(
1192 1193 'Computing PERMISSION tree for user %s scope `%s` '
1193 'with caching: %s[TTL: %ss]' % (user, scope, cache_on, cache_seconds or 0))
1194 'with caching: %s[TTL: %ss]', user, scope, cache_on, cache_seconds or 0)
1194 1195
1195 1196 cache_namespace_uid = 'cache_user_auth.{}'.format(user_id)
1196 1197 region = rc_cache.get_or_create_region('cache_perms', cache_namespace_uid)
@@ -1214,8 +1215,8 b' class AuthUser(object):'
1214 1215 for k in result:
1215 1216 result_repr.append((k, len(result[k])))
1216 1217 total = time.time() - start
1217 log.debug('PERMISSION tree for user %s computed in %.3fs: %s' % (
1218 user, total, result_repr))
1218 log.debug('PERMISSION tree for user %s computed in %.3fs: %s',
1219 user, total, result_repr)
1219 1220
1220 1221 return result
1221 1222
@@ -1352,12 +1353,12 b' class AuthUser(object):'
1352 1353 allowed_ips = AuthUser.get_allowed_ips(
1353 1354 user_id, cache=True, inherit_from_default=inherit_from_default)
1354 1355 if check_ip_access(source_ip=ip_addr, allowed_ips=allowed_ips):
1355 log.debug('IP:%s for user %s is in range of %s' % (
1356 ip_addr, user_id, allowed_ips))
1356 log.debug('IP:%s for user %s is in range of %s',
1357 ip_addr, user_id, allowed_ips)
1357 1358 return True
1358 1359 else:
1359 1360 log.info('Access for IP:%s forbidden for user %s, '
1360 'not in %s' % (ip_addr, user_id, allowed_ips))
1361 'not in %s', ip_addr, user_id, allowed_ips)
1361 1362 return False
1362 1363
1363 1364 def get_branch_permissions(self, repo_name, perms=None):
@@ -1593,7 +1594,7 b' class LoginRequired(object):'
1593 1594 _ = request.translate
1594 1595
1595 1596 loc = "%s:%s" % (cls.__class__.__name__, func.__name__)
1596 log.debug('Starting login restriction checks for user: %s' % (user,))
1597 log.debug('Starting login restriction checks for user: %s', user)
1597 1598 # check if our IP is allowed
1598 1599 ip_access_valid = True
1599 1600 if not user.ip_allowed:
@@ -1610,7 +1611,7 b' class LoginRequired(object):'
1610 1611
1611 1612 # explicit controller is enabled or API is in our whitelist
1612 1613 if self.auth_token_access or auth_token_access_valid:
1613 log.debug('Checking AUTH TOKEN access for %s' % (cls,))
1614 log.debug('Checking AUTH TOKEN access for %s', cls)
1614 1615 db_user = user.get_instance()
1615 1616
1616 1617 if db_user:
@@ -1626,36 +1627,33 b' class LoginRequired(object):'
1626 1627
1627 1628 if _auth_token and token_match:
1628 1629 auth_token_access_valid = True
1629 log.debug('AUTH TOKEN ****%s is VALID' % (_auth_token[-4:],))
1630 log.debug('AUTH TOKEN ****%s is VALID', _auth_token[-4:])
1630 1631 else:
1631 1632 auth_token_access_valid = False
1632 1633 if not _auth_token:
1633 1634 log.debug("AUTH TOKEN *NOT* present in request")
1634 1635 else:
1635 log.warning(
1636 "AUTH TOKEN ****%s *NOT* valid" % _auth_token[-4:])
1637
1638 log.debug('Checking if %s is authenticated @ %s' % (user.username, loc))
1636 log.warning("AUTH TOKEN ****%s *NOT* valid", _auth_token[-4:])
1637
1638 log.debug('Checking if %s is authenticated @ %s', user.username, loc)
1639 1639 reason = 'RHODECODE_AUTH' if user.is_authenticated \
1640 1640 else 'AUTH_TOKEN_AUTH'
1641 1641
1642 1642 if ip_access_valid and (
1643 1643 user.is_authenticated or auth_token_access_valid):
1644 log.info(
1645 'user %s authenticating with:%s IS authenticated on func %s'
1646 % (user, reason, loc))
1644 log.info('user %s authenticating with:%s IS authenticated on func %s',
1645 user, reason, loc)
1647 1646
1648 1647 return func(*fargs, **fkwargs)
1649 1648 else:
1650 1649 log.warning(
1651 1650 'user %s authenticating with:%s NOT authenticated on '
1652 'func: %s: IP_ACCESS:%s AUTH_TOKEN_ACCESS:%s'
1653 % (user, reason, loc, ip_access_valid,
1654 auth_token_access_valid))
1651 'func: %s: IP_ACCESS:%s AUTH_TOKEN_ACCESS:%s',
1652 user, reason, loc, ip_access_valid, auth_token_access_valid)
1655 1653 # we preserve the get PARAM
1656 1654 came_from = get_came_from(request)
1657 1655
1658 log.debug('redirecting to login page with %s' % (came_from,))
1656 log.debug('redirecting to login page with %s', came_from)
1659 1657 raise HTTPFound(
1660 1658 h.route_path('login', _query={'came_from': came_from}))
1661 1659
@@ -1678,7 +1676,7 b' class NotAnonymous(object):'
1678 1676 self.user = cls._rhodecode_user
1679 1677 request = self._get_request()
1680 1678 _ = request.translate
1681 log.debug('Checking if user is not anonymous @%s' % cls)
1679 log.debug('Checking if user is not anonymous @%s', cls)
1682 1680
1683 1681 anonymous = self.user.username == User.DEFAULT_USER
1684 1682
@@ -1939,7 +1937,7 b' class PermsFunction(object):'
1939 1937 frame = inspect.currentframe()
1940 1938 stack_trace = traceback.format_stack(frame)
1941 1939 log.error('Checking bool value on a class instance of perm '
1942 'function is not allowed: %s' % ''.join(stack_trace))
1940 'function is not allowed: %s', ''.join(stack_trace))
1943 1941 # rather than throwing errors, here we always return False so if by
1944 1942 # accident someone checks truth for just an instance it will always end
1945 1943 # up in returning False
@@ -2182,9 +2180,8 b' class _BaseApiPerm(object):'
2182 2180 if user_group_name:
2183 2181 check_scope += ', user_group_name:%s' % (user_group_name,)
2184 2182
2185 log.debug(
2186 'checking cls:%s %s %s @ %s'
2187 % (cls_name, self.required_perms, check_scope, check_location))
2183 log.debug('checking cls:%s %s %s @ %s',
2184 cls_name, self.required_perms, check_scope, check_location)
2188 2185 if not user:
2189 2186 log.debug('Empty User passed into arguments')
2190 2187 return False
@@ -2305,7 +2302,7 b' def check_ip_access(source_ip, allowed_i'
2305 2302 :param source_ip:
2306 2303 :param allowed_ips: list of allowed ips together with mask
2307 2304 """
2308 log.debug('checking if ip:%s is subnet of %s' % (source_ip, allowed_ips))
2305 log.debug('checking if ip:%s is subnet of %s', source_ip, allowed_ips)
2309 2306 source_ip_address = ipaddress.ip_address(safe_unicode(source_ip))
2310 2307 if isinstance(allowed_ips, (tuple, list, set)):
2311 2308 for ip in allowed_ips:
@@ -2313,8 +2310,7 b' def check_ip_access(source_ip, allowed_i'
2313 2310 try:
2314 2311 network_address = ipaddress.ip_network(ip, strict=False)
2315 2312 if source_ip_address in network_address:
2316 log.debug('IP %s is network %s' %
2317 (source_ip_address, network_address))
2313 log.debug('IP %s is network %s', source_ip_address, network_address)
2318 2314 return True
2319 2315 # for any case we cannot determine the IP, don't crash just
2320 2316 # skip it and log as error, we want to say forbidden still when
@@ -216,7 +216,7 b' class BasicAuth(AuthBasicAuthenticator):'
216 216 try:
217 217 return get_exception(safe_int(http_code))
218 218 except Exception:
219 log.exception('Failed to fetch response for code %s' % http_code)
219 log.exception('Failed to fetch response for code %s', http_code)
220 220 return HTTPForbidden
221 221
222 222 def get_rc_realm(self):
@@ -442,7 +442,7 b' class DiffSet(object):'
442 442 return self._lexer_cache[filename]
443 443
444 444 def render_patch(self, patch):
445 log.debug('rendering diff for %r' % patch['filename'])
445 log.debug('rendering diff for %r', patch['filename'])
446 446
447 447 source_filename = patch['original_filename']
448 448 target_filename = patch['filename']
@@ -107,7 +107,7 b' class DbManage(object):'
107 107
108 108 checkfirst = not override
109 109 Base.metadata.create_all(checkfirst=checkfirst)
110 log.info('Created tables for %s' % self.dbname)
110 log.info('Created tables for %s', self.dbname)
111 111
112 112 def set_db_version(self):
113 113 ver = DbMigrateVersion()
@@ -115,7 +115,7 b' class DbManage(object):'
115 115 ver.repository_id = 'rhodecode_db_migrations'
116 116 ver.repository_path = 'versions'
117 117 self.sa.add(ver)
118 log.info('db version set to: %s' % __dbversion__)
118 log.info('db version set to: %s', __dbversion__)
119 119
120 120 def run_pre_migration_tasks(self):
121 121 """
@@ -402,7 +402,7 b' class DbManage(object):'
402 402 ('auth_rhodecode_enabled', 'True', 'bool')]:
403 403 if (skip_existing and
404 404 SettingsModel().get_setting_by_name(k) is not None):
405 log.debug('Skipping option %s' % k)
405 log.debug('Skipping option %s', k)
406 406 continue
407 407 setting = RhodeCodeSetting(k, v, t)
408 408 self.sa.add(setting)
@@ -419,7 +419,7 b' class DbManage(object):'
419 419
420 420 if (skip_existing and
421 421 SettingsModel().get_setting_by_name(k) is not None):
422 log.debug('Skipping option %s' % k)
422 log.debug('Skipping option %s', k)
423 423 continue
424 424 setting = RhodeCodeSetting(k, v, t)
425 425 self.sa.add(setting)
@@ -436,7 +436,7 b' class DbManage(object):'
436 436 .scalar()
437 437
438 438 if default is None:
439 log.debug('missing default permission for group %s adding' % g)
439 log.debug('missing default permission for group %s adding', g)
440 440 perm_obj = RepoGroupModel()._create_default_perms(g)
441 441 self.sa.add(perm_obj)
442 442
@@ -484,20 +484,20 b' class DbManage(object):'
484 484 # check proper dir
485 485 if not os.path.isdir(path):
486 486 path_ok = False
487 log.error('Given path %s is not a valid directory' % (path,))
487 log.error('Given path %s is not a valid directory', path)
488 488
489 489 elif not os.path.isabs(path):
490 490 path_ok = False
491 log.error('Given path %s is not an absolute path' % (path,))
491 log.error('Given path %s is not an absolute path', path)
492 492
493 493 # check if path is at least readable.
494 494 if not os.access(path, os.R_OK):
495 495 path_ok = False
496 log.error('Given path %s is not readable' % (path,))
496 log.error('Given path %s is not readable', path)
497 497
498 498 # check write access, warn user about non writeable paths
499 499 elif not os.access(path, os.W_OK) and path_ok:
500 log.warning('No write permission to given path %s' % (path,))
500 log.warning('No write permission to given path %s', path)
501 501
502 502 q = ('Given path %s is not writeable, do you want to '
503 503 'continue with read only mode ? [y/n]' % (path,))
@@ -573,7 +573,7 b' class DbManage(object):'
573 573
574 574 def create_user(self, username, password, email='', admin=False,
575 575 strict_creation_check=True, api_key=None):
576 log.info('creating user `%s`' % username)
576 log.info('creating user `%s`', username)
577 577 user = UserModel().create_or_update(
578 578 username, password, email, firstname=u'RhodeCode', lastname=u'Admin',
579 579 active=True, admin=admin, extern_type="rhodecode",
@@ -25,13 +25,13 b' def usage():'
25 25
26 26 def delete_file(filepath):
27 27 """Deletes a file and prints a message."""
28 log.info('Deleting file: %s' % filepath)
28 log.info('Deleting file: %s', filepath)
29 29 os.remove(filepath)
30 30
31 31
32 32 def move_file(src, tgt):
33 33 """Moves a file and prints a message."""
34 log.info('Moving file %s to %s' % (src, tgt))
34 log.info('Moving file %s to %s', src, tgt)
35 35 if os.path.exists(tgt):
36 36 raise Exception(
37 37 'Cannot move file %s because target %s already exists' % \
@@ -41,13 +41,13 b' def move_file(src, tgt):'
41 41
42 42 def delete_directory(dirpath):
43 43 """Delete a directory and print a message."""
44 log.info('Deleting directory: %s' % dirpath)
44 log.info('Deleting directory: %s', dirpath)
45 45 os.rmdir(dirpath)
46 46
47 47
48 48 def migrate_repository(repos):
49 49 """Does the actual migration to the new repository format."""
50 log.info('Migrating repository at: %s to new format' % repos)
50 log.info('Migrating repository at: %s to new format', repos)
51 51 versions = '%s/versions' % repos
52 52 dirs = os.listdir(versions)
53 53 # Only use int's in list.
@@ -55,7 +55,7 b' def migrate_repository(repos):'
55 55 numdirs.sort() # Sort list.
56 56 for dirname in numdirs:
57 57 origdir = '%s/%s' % (versions, dirname)
58 log.info('Working on directory: %s' % origdir)
58 log.info('Working on directory: %s', origdir)
59 59 files = os.listdir(origdir)
60 60 files.sort()
61 61 for filename in files:
@@ -35,7 +35,7 b' class Pathed(KeyedInstance):'
35 35 """Try to initialize this object's parent, if it has one"""
36 36 parent_path = self.__class__._parent_path(path)
37 37 self.parent = self.__class__.parent(parent_path)
38 log.debug("Getting parent %r:%r" % (self.__class__.parent, parent_path))
38 log.debug("Getting parent %r:%r", self.__class__.parent, parent_path)
39 39 self.parent._init_child(path, self)
40 40
41 41 def _init_child(self, child, path):
@@ -73,14 +73,14 b' class Repository(pathed.Pathed):'
73 73 _versions = 'versions'
74 74
75 75 def __init__(self, path):
76 log.debug('Loading repository %s...' % path)
76 log.debug('Loading repository %s...', path)
77 77 self.verify(path)
78 78 super(Repository, self).__init__(path)
79 79 self.config = cfgparse.Config(os.path.join(self.path, self._config))
80 80 self.versions = version.Collection(os.path.join(self.path,
81 81 self._versions))
82 log.debug('Repository %s loaded successfully' % path)
83 log.debug('Config: %r' % self.config.to_dict())
82 log.debug('Repository %s loaded successfully', path)
83 log.debug('Config: %r', self.config.to_dict())
84 84
85 85 @classmethod
86 86 def verify(cls, path):
@@ -24,10 +24,10 b' class BaseScript(pathed.Pathed):'
24 24 """ # TODO: sphinxfy this and implement it correctly
25 25
26 26 def __init__(self, path):
27 log.debug('Loading script %s...' % path)
27 log.debug('Loading script %s...', path)
28 28 self.verify(path)
29 29 super(BaseScript, self).__init__(path)
30 log.debug('Script %s loaded successfully' % path)
30 log.debug('Script %s loaded successfully', path)
31 31
32 32 @classmethod
33 33 def verify(cls, path):
@@ -311,7 +311,7 b' class User(Base, BaseModel):'
311 311 self.last_login = datetime.datetime.now()
312 312 Session.add(self)
313 313 Session.commit()
314 log.debug('updated user %s lastlogin' % self.username)
314 log.debug('updated user %s lastlogin', self.username)
315 315
316 316 @classmethod
317 317 def create(cls, form_data):
@@ -656,7 +656,7 b' class Repository(Base, BaseModel):'
656 656
657 657 try:
658 658 alias = get_scm(repo_full_path)[0]
659 log.debug('Creating instance of %s repository' % alias)
659 log.debug('Creating instance of %s repository', alias)
660 660 backend = get_backend(alias)
661 661 except VCSError:
662 662 log.error(traceback.format_exc())
@@ -731,7 +731,7 b' class Group(Base, BaseModel):'
731 731 break
732 732 if cnt == parents_recursion_limit:
733 733 # this will prevent accidental infinit loops
734 log.error('group nested more than %s' %
734 log.error('group nested more than %s',
735 735 parents_recursion_limit)
736 736 break
737 737
@@ -1006,7 +1006,7 b' class CacheInvalidation(Base, BaseModel)'
1006 1006 :param key:
1007 1007 """
1008 1008
1009 log.debug('marking %s for invalidation' % key)
1009 log.debug('marking %s for invalidation', key)
1010 1010 inv_obj = Session.query(cls)\
1011 1011 .filter(cls.cache_key == key).scalar()
1012 1012 if inv_obj:
@@ -379,7 +379,7 b' class User(Base, BaseModel):'
379 379 """Update user lastlogin"""
380 380 self.last_login = datetime.datetime.now()
381 381 Session.add(self)
382 log.debug('updated user %s lastlogin' % self.username)
382 log.debug('updated user %s lastlogin', self.username)
383 383
384 384 def __json__(self):
385 385 return dict(
@@ -676,7 +676,7 b' class Repository(Base, BaseModel):'
676 676 repo_full_path = self.repo_full_path
677 677 try:
678 678 alias = get_scm(repo_full_path)[0]
679 log.debug('Creating instance of %s repository' % alias)
679 log.debug('Creating instance of %s repository', alias)
680 680 backend = get_backend(alias)
681 681 except VCSError:
682 682 log.error(traceback.format_exc())
@@ -760,8 +760,7 b' class RepoGroup(Base, BaseModel):'
760 760 break
761 761 if cnt == parents_recursion_limit:
762 762 # this will prevent accidental infinit loops
763 log.error('group nested more than %s' %
764 parents_recursion_limit)
763 log.error('group nested more than %s', parents_recursion_limit)
765 764 break
766 765
767 766 groups.insert(0, gr)
@@ -1095,8 +1094,7 b' class CacheInvalidation(Base, BaseModel)'
1095 1094
1096 1095 key, _prefix, _org_key = cls._get_key(key)
1097 1096 inv_objs = Session.query(cls).filter(cls.cache_args == _org_key).all()
1098 log.debug('marking %s key[s] %s for invalidation' % (len(inv_objs),
1099 _org_key))
1097 log.debug('marking %s key[s] %s for invalidation', len(inv_objs), _org_key)
1100 1098 try:
1101 1099 for inv_obj in inv_objs:
1102 1100 if inv_obj:
@@ -614,15 +614,13 b' class Repository(Base, BaseModel):'
614 614 if (cs_cache != self.changeset_cache or not self.changeset_cache):
615 615 _default = datetime.datetime.fromtimestamp(0)
616 616 last_change = cs_cache.get('date') or _default
617 log.debug('updated repo %s with new cs cache %s'
618 % (self.repo_name, cs_cache))
617 log.debug('updated repo %s with new cs cache %s', self.repo_name, cs_cache)
619 618 self.updated_on = last_change
620 619 self.changeset_cache = cs_cache
621 620 Session().add(self)
622 621 Session().commit()
623 622 else:
624 log.debug('Skipping repo:%s already with latest changes'
625 % self.repo_name)
623 log.debug('Skipping repo:%s already with latest changes', self.repo_name)
626 624
627 625 class RepoGroup(Base, BaseModel):
628 626 __tablename__ = 'groups'
@@ -2415,8 +2415,8 b' class RepoGroup(Base, BaseModel):'
2415 2415 break
2416 2416 if cnt == parents_recursion_limit:
2417 2417 # this will prevent accidental infinit loops
2418 log.error(('more than %s parents found for group %s, stopping '
2419 'recursive parent fetching' % (parents_recursion_limit, self)))
2418 log.error('more than %s parents found for group %s, stopping '
2419 'recursive parent fetching', parents_recursion_limit, self)
2420 2420 break
2421 2421
2422 2422 groups.insert(0, gr)
@@ -2481,8 +2481,8 b' class RepoGroup(Base, BaseModel):'
2481 2481 break
2482 2482 if cnt == parents_recursion_limit:
2483 2483 # this will prevent accidental infinit loops
2484 log.error(('more than %s parents found for group %s, stopping '
2485 'recursive parent fetching' % (parents_recursion_limit, self)))
2484 log.error('more than %s parents found for group %s, stopping '
2485 'recursive parent fetching', parents_recursion_limit, self)
2486 2486 break
2487 2487
2488 2488 groups.insert(0, gr)
@@ -2108,8 +2108,8 b' class RepoGroup(Base, BaseModel):'
2108 2108 break
2109 2109 if cnt == parents_recursion_limit:
2110 2110 # this will prevent accidental infinit loops
2111 log.error(('more than %s parents found for group %s, stopping '
2112 'recursive parent fetching' % (parents_recursion_limit, self)))
2111 log.error('more than %s parents found for group %s, stopping '
2112 'recursive parent fetching', parents_recursion_limit, self)
2113 2113 break
2114 2114
2115 2115 groups.insert(0, gr)
@@ -2100,8 +2100,8 b' class RepoGroup(Base, BaseModel):'
2100 2100 break
2101 2101 if cnt == parents_recursion_limit:
2102 2102 # this will prevent accidental infinit loops
2103 log.error(('more than %s parents found for group %s, stopping '
2104 'recursive parent fetching' % (parents_recursion_limit, self)))
2103 log.error('more than %s parents found for group %s, stopping '
2104 'recursive parent fetching', parents_recursion_limit, self)
2105 2105 break
2106 2106
2107 2107 groups.insert(0, gr)
@@ -2100,8 +2100,8 b' class RepoGroup(Base, BaseModel):'
2100 2100 break
2101 2101 if cnt == parents_recursion_limit:
2102 2102 # this will prevent accidental infinit loops
2103 log.error(('more than %s parents found for group %s, stopping '
2104 'recursive parent fetching' % (parents_recursion_limit, self)))
2103 log.error('more than %s parents found for group %s, stopping '
2104 'recursive parent fetching', parents_recursion_limit, self)
2105 2105 break
2106 2106
2107 2107 groups.insert(0, gr)
@@ -2104,8 +2104,8 b' class RepoGroup(Base, BaseModel):'
2104 2104 break
2105 2105 if cnt == parents_recursion_limit:
2106 2106 # this will prevent accidental infinit loops
2107 log.error(('more than %s parents found for group %s, stopping '
2108 'recursive parent fetching' % (parents_recursion_limit, self)))
2107 log.error('more than %s parents found for group %s, stopping '
2108 'recursive parent fetching', parents_recursion_limit, self)
2109 2109 break
2110 2110
2111 2111 groups.insert(0, gr)
@@ -2104,8 +2104,8 b' class RepoGroup(Base, BaseModel):'
2104 2104 break
2105 2105 if cnt == parents_recursion_limit:
2106 2106 # this will prevent accidental infinit loops
2107 log.error(('more than %s parents found for group %s, stopping '
2108 'recursive parent fetching' % (parents_recursion_limit, self)))
2107 log.error('more than %s parents found for group %s, stopping '
2108 'recursive parent fetching', parents_recursion_limit, self)
2109 2109 break
2110 2110
2111 2111 groups.insert(0, gr)
@@ -2154,8 +2154,8 b' class RepoGroup(Base, BaseModel):'
2154 2154 break
2155 2155 if cnt == parents_recursion_limit:
2156 2156 # this will prevent accidental infinit loops
2157 log.error(('more than %s parents found for group %s, stopping '
2158 'recursive parent fetching' % (parents_recursion_limit, self)))
2157 log.error('more than %s parents found for group %s, stopping '
2158 'recursive parent fetching', parents_recursion_limit, self)
2159 2159 break
2160 2160
2161 2161 groups.insert(0, gr)
@@ -2155,8 +2155,8 b' class RepoGroup(Base, BaseModel):'
2155 2155 break
2156 2156 if cnt == parents_recursion_limit:
2157 2157 # this will prevent accidental infinit loops
2158 log.error(('more than %s parents found for group %s, stopping '
2159 'recursive parent fetching' % (parents_recursion_limit, self)))
2158 log.error('more than %s parents found for group %s, stopping '
2159 'recursive parent fetching', parents_recursion_limit, self)
2160 2160 break
2161 2161
2162 2162 groups.insert(0, gr)
@@ -2352,8 +2352,8 b' class RepoGroup(Base, BaseModel):'
2352 2352 break
2353 2353 if cnt == parents_recursion_limit:
2354 2354 # this will prevent accidental infinit loops
2355 log.error(('more than %s parents found for group %s, stopping '
2356 'recursive parent fetching' % (parents_recursion_limit, self)))
2355 log.error('more than %s parents found for group %s, stopping '
2356 'recursive parent fetching', parents_recursion_limit, self)
2357 2357 break
2358 2358
2359 2359 groups.insert(0, gr)
@@ -74,7 +74,7 b' class User(Base):'
74 74 self.last_login = datetime.datetime.now()
75 75 session.add(self)
76 76 session.commit()
77 log.debug('updated user %s lastlogin' % self.username)
77 log.debug('updated user %s lastlogin', self.username)
78 78 except (DatabaseError,):
79 79 session.rollback()
80 80
@@ -102,7 +102,7 b' def fixups(models, _SESSION):'
102 102 perms = models.UserToPerm.query().filter(models.UserToPerm.user == user).all()
103 103 defined_perms_groups = map(
104 104 _get_group, (x.permission.permission_name for x in perms))
105 log.debug('GOT ALREADY DEFINED:%s' % perms)
105 log.debug('GOT ALREADY DEFINED:%s', perms)
106 106 DEFAULT_PERMS = models.Permission.DEFAULT_USER_PERMISSIONS
107 107
108 108 # for every default permission that needs to be created, we check if
@@ -110,8 +110,7 b' def fixups(models, _SESSION):'
110 110 for perm_name in DEFAULT_PERMS:
111 111 gr = _get_group(perm_name)
112 112 if gr not in defined_perms_groups:
113 log.debug('GR:%s not found, creating permission %s'
114 % (gr, perm_name))
113 log.debug('GR:%s not found, creating permission %s', gr, perm_name)
115 114 new_perm = _make_perm(perm_name)
116 115 _SESSION().add(new_perm)
117 116 _SESSION().commit()
@@ -127,7 +126,7 b' def fixups(models, _SESSION):'
127 126 ('default_repo_type', 'hg')]:
128 127
129 128 if skip_existing and get_by_name(models.RhodeCodeSetting, k) is not None:
130 log.debug('Skipping option %s' % k)
129 log.debug('Skipping option %s', k)
131 130 continue
132 131 setting = models.RhodeCodeSetting(k, v)
133 132 _SESSION().add(setting)
@@ -99,7 +99,7 b' def fixups(models, _SESSION):'
99 99 perms = models.UserToPerm.query().filter(models.UserToPerm.user == user).all()
100 100 defined_perms_groups = map(_get_group,
101 101 (x.permission.permission_name for x in perms))
102 log.debug('GOT ALREADY DEFINED:%s' % perms)
102 log.debug('GOT ALREADY DEFINED:%s', perms)
103 103 DEFAULT_PERMS = models.Permission.DEFAULT_USER_PERMISSIONS
104 104
105 105 # for every default permission that needs to be created, we check if
@@ -107,8 +107,7 b' def fixups(models, _SESSION):'
107 107 for perm_name in DEFAULT_PERMS:
108 108 gr = _get_group(perm_name)
109 109 if gr not in defined_perms_groups:
110 log.debug('GR:%s not found, creating permission %s'
111 % (gr, perm_name))
110 log.debug('GR:%s not found, creating permission %s', gr, perm_name)
112 111 new_perm = _make_perm(perm_name)
113 112 _SESSION().add(new_perm)
114 113 _SESSION().commit()
@@ -446,7 +446,7 b' class DiffProcessor(object):'
446 446
447 447 for chunk in self._diff.chunks():
448 448 head = chunk.header
449 log.debug('parsing diff %r' % head)
449 log.debug('parsing diff %r', head)
450 450
451 451 raw_diff = chunk.raw
452 452 limited_diff = False
@@ -1712,14 +1712,14 b' def process_patterns(text_string, repo_n'
1712 1712 newtext = text_string
1713 1713
1714 1714 for uid, entry in active_entries.items():
1715 log.debug('found issue tracker entry with uid %s' % (uid,))
1715 log.debug('found issue tracker entry with uid %s', uid)
1716 1716
1717 1717 if not (entry['pat'] and entry['url']):
1718 1718 log.debug('skipping due to missing data')
1719 1719 continue
1720 1720
1721 log.debug('issue tracker entry: uid: `%s` PAT:%s URL:%s PREFIX:%s'
1722 % (uid, entry['pat'], entry['url'], entry['pref']))
1721 log.debug('issue tracker entry: uid: `%s` PAT:%s URL:%s PREFIX:%s',
1722 uid, entry['pat'], entry['url'], entry['pref'])
1723 1723
1724 1724 try:
1725 1725 pattern = re.compile(r'%s' % entry['pat'])
@@ -1741,7 +1741,7 b' def process_patterns(text_string, repo_n'
1741 1741 link_format=link_format)
1742 1742
1743 1743 newtext = pattern.sub(url_func, newtext)
1744 log.debug('processed prefix:uid `%s`' % (uid,))
1744 log.debug('processed prefix:uid `%s`', uid)
1745 1745
1746 1746 return newtext, issues_data
1747 1747
@@ -122,7 +122,7 b' class Search(BaseSearch):'
122 122 search_user, repo_name)
123 123 try:
124 124 query = qp.parse(safe_unicode(query))
125 log.debug('query: %s (%s)' % (query, repr(query)))
125 log.debug('query: %s (%s)', query, repr(query))
126 126
127 127 reverse, sortedby = False, None
128 128 if search_type == 'message':
@@ -217,8 +217,8 b' class Search(BaseSearch):'
217 217 'path': self.file_schema
218 218 }.get(cur_type, self.file_schema)
219 219
220 log.debug('IDX: %s' % index_name)
221 log.debug('SCHEMA: %s' % schema_defn)
220 log.debug('IDX: %s', index_name)
221 log.debug('SCHEMA: %s', schema_defn)
222 222 return search_type, index_name, schema_defn
223 223
224 224 def _init_searcher(self, index_name):
@@ -67,7 +67,7 b' class LRUDictDebug(LRUDict):'
67 67 fmt = '\n'
68 68 for cnt, elem in enumerate(self.keys()):
69 69 fmt += '%s - %s\n' % (cnt+1, safe_str(elem))
70 log.debug('current LRU keys (%s):%s' % (elems_cnt, fmt))
70 log.debug('current LRU keys (%s):%s', elems_cnt, fmt)
71 71
72 72 def __getitem__(self, key):
73 73 self._report_keys()
@@ -44,10 +44,11 b' class RequestWrapperTween(object):'
44 44 finally:
45 45 end = time.time()
46 46 total = end - start
47 log.info('IP: %s Request to %s time: %.3fs [%s]' % (
47 log.info(
48 'IP: %s Request to %s time: %.3fs [%s]',
48 49 get_ip_addr(request.environ),
49 50 safe_str(get_access_path(request.environ)), total,
50 get_user_agent(request. environ),)
51 get_user_agent(request. environ)
51 52 )
52 53
53 54 return response
@@ -111,7 +111,7 b' class SmtpMailer(object):'
111 111 smtp_serv.login(self.user, self.passwd)
112 112
113 113 smtp_serv.sendmail(msg.sender, msg.send_to, raw_msg.as_string())
114 log.info('email sent to: %s' % recipients)
114 log.info('email sent to: %s', recipients)
115 115
116 116 try:
117 117 smtp_serv.quit()
@@ -49,13 +49,13 b' def user_log_filter(user_log, search_ter'
49 49 :param user_log:
50 50 :param search_term:
51 51 """
52 log.debug('Initial search term: %r' % search_term)
52 log.debug('Initial search term: %r', search_term)
53 53 qry = None
54 54 if search_term:
55 55 qp = QueryParser('repository', schema=JOURNAL_SCHEMA)
56 56 qp.add_plugin(DateParserPlugin())
57 57 qry = qp.parse(safe_unicode(search_term))
58 log.debug('Filtering using parsed query %r' % qry)
58 log.debug('Filtering using parsed query %r', qry)
59 59
60 60 def wildcard_handler(col, wc_term):
61 61 if wc_term.startswith('*') and not wc_term.endswith('*'):
@@ -80,7 +80,7 b' def user_log_filter(user_log, search_ter'
80 80 field = getattr(UserLog, 'username')
81 81 else:
82 82 field = getattr(UserLog, field)
83 log.debug('filter field: %s val=>%s' % (field, val))
83 log.debug('filter field: %s val=>%s', field, val)
84 84
85 85 # sql filtering
86 86 if isinstance(term, query.Wildcard):
@@ -291,8 +291,7 b' def is_valid_repo_group(repo_group_name,'
291 291
292 292 # check if it's not a repo
293 293 if is_valid_repo(repo_group_name, base_path):
294 log.debug('Repo called %s exist, it is not a valid '
295 'repo group' % repo_group_name)
294 log.debug('Repo called %s exist, it is not a valid repo group', repo_group_name)
296 295 return False
297 296
298 297 try:
@@ -300,8 +299,7 b' def is_valid_repo_group(repo_group_name,'
300 299 # since we might match branches/hooks/info/objects or possible
301 300 # other things inside bare git repo
302 301 scm_ = get_scm(os.path.dirname(full_path))
303 log.debug('path: %s is a vcs object:%s, not valid '
304 'repo group' % (full_path, scm_))
302 log.debug('path: %s is a vcs object:%s, not valid repo group', full_path, scm_)
305 303 return False
306 304 except VCSError:
307 305 pass
@@ -774,5 +772,5 b' def generate_platform_uuid():'
774 772 uuid_list = [platform.platform()]
775 773 return hashlib.sha256(':'.join(uuid_list)).hexdigest()
776 774 except Exception as e:
777 log.error('Failed to generate host uuid: %s' % e)
775 log.error('Failed to generate host uuid: %s', e)
778 776 return 'UNDEFINED'
@@ -2539,8 +2539,8 b' class RepoGroup(Base, BaseModel):'
2539 2539 break
2540 2540 if cnt == parents_recursion_limit:
2541 2541 # this will prevent accidental infinit loops
2542 log.error(('more than %s parents found for group %s, stopping '
2543 'recursive parent fetching' % (parents_recursion_limit, self)))
2542 log.error('more than %s parents found for group %s, stopping '
2543 'recursive parent fetching', parents_recursion_limit, self)
2544 2544 break
2545 2545
2546 2546 groups.insert(0, gr)
@@ -241,8 +241,7 b' class SettingsModel(BaseModel):'
241 241 region.invalidate()
242 242
243 243 result = _get_all_settings('rhodecode_settings', key)
244 log.debug(
245 'Fetching app settings for key: %s took: %.3fs', key,
244 log.debug('Fetching app settings for key: %s took: %.3fs', key,
246 245 inv_context_manager.compute_time)
247 246
248 247 return result
@@ -300,11 +300,11 b' class UserModel(BaseModel):'
300 300
301 301 if updating_user_id:
302 302 log.debug('Checking for existing account in RhodeCode '
303 'database with user_id `%s` ' % (updating_user_id,))
303 'database with user_id `%s` ', updating_user_id)
304 304 user = User.get(updating_user_id)
305 305 else:
306 306 log.debug('Checking for existing account in RhodeCode '
307 'database with username `%s` ' % (username,))
307 'database with username `%s` ', username)
308 308 user = User.get_by_username(username, case_insensitive=True)
309 309
310 310 if user is None:
@@ -626,7 +626,7 b' class UserGroupModel(BaseModel):'
626 626 self.remove_user_from_group(gr, user)
627 627 else:
628 628 log.debug('Skipping removal from group %s since it is '
629 'not set to be automatically synchronized' % gr)
629 'not set to be automatically synchronized', gr)
630 630
631 631 # now we calculate in which groups user should be == groups params
632 632 owner = User.get_first_super_admin().username
@@ -647,7 +647,7 b' class UserGroupModel(BaseModel):'
647 647 UserGroupModel().add_user_to_group(existing_group, user)
648 648 else:
649 649 log.debug('Skipping addition to group %s since it is '
650 'not set to be automatically synchronized' % gr)
650 'not set to be automatically synchronized', gr)
651 651
652 652 def change_groups(self, user, groups):
653 653 """
@@ -99,8 +99,8 b' class RhodeCodeAuthPlugin(RhodeCodeExter'
99 99 'extern_type': extern_type,
100 100 }
101 101
102 log.debug('EXTERNAL user: \n%s' % formatted_json(user_attrs))
103 log.info('user `%s` authenticated correctly' % user_attrs['username'])
102 log.debug('EXTERNAL user: \n%s', formatted_json(user_attrs))
103 log.info('user `%s` authenticated correctly', user_attrs['username'])
104 104
105 105 return user_attrs
106 106
@@ -61,7 +61,7 b' class Command(object):'
61 61 """
62 62
63 63 command = cmd + ' ' + ' '.join(args)
64 log.debug('Executing %s' % command)
64 log.debug('Executing %s', command)
65 65 if DEBUG:
66 66 print(command)
67 67 p = Popen(command, shell=True, stdout=PIPE, stderr=PIPE, cwd=self.cwd)
@@ -57,7 +57,7 b' class Command(object):'
57 57
58 58 command = cmd + ' ' + ' '.join(args)
59 59 if DEBUG:
60 log.debug('*** CMD %s ***' % (command,))
60 log.debug('*** CMD %s ***', command)
61 61
62 62 env = dict(os.environ)
63 63 # Delete coverage variables, as they make the test fail for Mercurial
@@ -69,8 +69,8 b' class Command(object):'
69 69 cwd=self.cwd, env=env)
70 70 stdout, stderr = self.process.communicate()
71 71 if DEBUG:
72 log.debug('STDOUT:%s' % (stdout,))
73 log.debug('STDERR:%s' % (stderr,))
72 log.debug('STDOUT:%s', stdout)
73 log.debug('STDERR:%s', stderr)
74 74 return stdout, stderr
75 75
76 76 def assert_returncode_success(self):
General Comments 0
You need to be logged in to leave comments. Login now