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