@@ -204,7 +204,7 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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 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) | |