Make 403 errors easier to identify where and why they happen
It should be possible to find out where and why 403 errors (Permission denied) occur. The applied patch log the reasons and drop the makeForbidden403 general purpose function.
That should surely not be logging.info but if anything logging.debug. -- JohannesBerg 2008-07-06 11:37:45
I've checked the code to get a feeling what is logging.debug and logging.warning and decided against both. There are no design rules for which logging level should be used in which case. The current implementation have to investigated in hope to understand the concept. For me it looks like logging.debug is used to track program execution. logging.warning if an unexpected proplem occur. I've decided to use logging.info because it's a configuration issue if access is forbidden so the administrator is able to find the reason easy and quick. -- RaphaelBossek 2008-07-06 14:45:04
But the default log level is "INFO" which means that in the much more common case that the administrator actually did intend to block access to a file with ACLs, the log will be spammed with these messages making it essentially useless. -- JohannesBerg 2008-07-11 11:46:58
1 diff -r e4c4ee9e3abc MoinMoin/Page.py
2 --- a/MoinMoin/Page.py Sun Jul 06 08:07:40 2008 +0200
3 +++ b/MoinMoin/Page.py Sun Jul 06 08:28:15 2008 +0200
4 @@ -1079,6 +1079,7 @@
5 request.setHttpHeader("Content-Type: %s; charset=%s" % (self.output_mimetype, self.output_charset))
6 if page_exists:
7 if not request.user.may.read(self.page_name):
8 + logging.info(u'Error 403: User "%s" is not allowed to read the page "%s(page_name)s"' % {'user': request.user.name, 'page_name': self.page_name})
9 request.setHttpHeader('Status: 403 Permission Denied')
10 else:
11 request.setHttpHeader('Status: 200 OK')
12 @@ -1096,6 +1097,7 @@
13 #request.setHttpHeader("Last-Modified: %s" % util.timefuncs.formathttpdate(lastmod))
14 pass
15 else:
16 + logging.info(u'Error 404: Page "%(page_name)s" does not exists.' % {'page_name': self.page_name})
17 request.setHttpHeader('Status: 404 NOTFOUND')
18 request.emit_http_headers()
19
20 diff -r e4c4ee9e3abc MoinMoin/action/edit.py
21 --- a/MoinMoin/action/edit.py Sun Jul 06 08:07:40 2008 +0200
22 +++ b/MoinMoin/action/edit.py Sun Jul 06 08:28:15 2008 +0200
23 @@ -16,8 +16,7 @@
24 _ = request.getText
25
26 if 'button_preview' in request.form and 'button_spellcheck' in request.form:
27 - # multiple buttons pressed at once? must be some spammer/bot
28 - request.makeForbidden403()
29 + request.makeForbidden(403, u'Multiple buttons pressed at once. Maybe a spammer/bot!')
30 request.surge_protect(kick_him=True) # get rid of him
31 return
32
33 diff -r e4c4ee9e3abc MoinMoin/action/fullsearch.py
34 --- a/MoinMoin/action/fullsearch.py Sun Jul 06 08:07:40 2008 +0200
35 +++ b/MoinMoin/action/fullsearch.py Sun Jul 06 08:28:15 2008 +0200
36 @@ -60,7 +60,7 @@
37 _ = request.getText
38 titlesearch = checkTitleSearch(request)
39 if titlesearch < 0:
40 - request.makeForbidden403()
41 + request.makeForbidden(403, u'Spammer try to press text and title search at once!')
42 request.surge_protect(kick_him=True) # get rid of spammer
43 return
44
45 diff -r e4c4ee9e3abc MoinMoin/action/newaccount.py
46 --- a/MoinMoin/action/newaccount.py Sun Jul 06 08:07:40 2008 +0200
47 +++ b/MoinMoin/action/newaccount.py Sun Jul 06 08:28:15 2008 +0200
48 @@ -167,7 +167,7 @@
49
50 if not found:
51 # we will not have linked, so forbid access
52 - request.makeForbidden403()
53 + request.makeForbidden(403, u'Missconfiguration of authentication (HelpOnAuthentication)!')
54 return
55
56 page = Page(request, pagename)
57 diff -r e4c4ee9e3abc MoinMoin/action/recoverpass.py
58 --- a/MoinMoin/action/recoverpass.py Sun Jul 06 08:07:40 2008 +0200
59 +++ b/MoinMoin/action/recoverpass.py Sun Jul 06 08:28:15 2008 +0200
60 @@ -147,7 +147,7 @@
61
62 if not found:
63 # we will not have linked, so forbid access
64 - request.makeForbidden403()
65 + request.makeForbidden(403, u'Missconfiguration of authentication (HelpOnAuthentication)!')
66 return
67
68 page = Page(request, pagename)
69 diff -r e4c4ee9e3abc MoinMoin/action/serveopenid.py
70 --- a/MoinMoin/action/serveopenid.py Sun Jul 06 08:07:40 2008 +0200
71 +++ b/MoinMoin/action/serveopenid.py Sun Jul 06 08:28:15 2008 +0200
72 @@ -184,7 +184,7 @@
73 # since we didn't put any openid.server into
74 # the page to start with, this is someone trying
75 # to abuse us. No need to give a nice error
76 - request.makeForbidden403()
77 + request.makeForbidden(403, 'OpenID server support disabled!')
78 return
79
80 server_url = request.getQualifiedURL(
81 @@ -206,8 +206,7 @@
82 username = request.user.name
83 elif identity is not None:
84 if not self._verify_endpoint_identity(identity):
85 - request.makeForbidden403()
86 - request.write('verification failed')
87 + request.makeForbidden(403, 'OpenID verification failed!')
88 return
89
90 if 'openid.user' in request.page.pi:
91 @@ -236,8 +235,7 @@
92 return
93
94 if openidreq is None:
95 - request.makeForbidden403()
96 - request.write('no request')
97 + request.makeForbidden(403, 'There is no OpenID request!')
98 return
99
100 if request.user.valid and username != request.user.name:
101 @@ -268,14 +266,12 @@
102 # use empty string if nothing was sent
103 form_nonce = form.get('nonce', [''])[0]
104 if session_nonce != form_nonce:
105 - self.request.makeForbidden403()
106 - self.request.write('invalid nonce')
107 + self.request.makeForbidden(403, 'Invalid OpenID nonce!')
108 return None
109
110 openidreq = request.session.get('openidserver.request')
111 if not openidreq:
112 - request.makeForbidden403()
113 - request.write('no response request')
114 + request.makeForbidden(403, 'No OpenID response request!')
115 return None
116 del request.session['openidserver.request']
117
118 diff -r e4c4ee9e3abc MoinMoin/request/__init__.py
119 --- a/MoinMoin/request/__init__.py Sun Jul 06 08:07:40 2008 +0200
120 +++ b/MoinMoin/request/__init__.py Sun Jul 06 08:28:15 2008 +0200
121 @@ -152,7 +152,7 @@
122 # not on external non-Apache servers
123 self.forbidden = False
124 if self.request_uri.startswith('http://'):
125 - self.makeForbidden403()
126 + self.makeForbidden(403, u'Request URI %(request_uri)s starts with http://!' % {'request_uri': self.request_uri})
127
128 # Init
129 else:
130 @@ -165,7 +165,7 @@
131 try:
132 self._load_multi_cfg()
133 except error.NoConfigMatchedError:
134 - self.makeForbidden(404, 'No wiki configuration matching the URL found!\r\n')
135 + self.makeForbidden(404, u'No wiki configuration matching the URL found!')
136 return
137
138 self.isSpiderAgent = self.check_spider()
139 @@ -184,7 +184,7 @@
140 try:
141 self.args = self.form = self.setup_args()
142 except UnicodeError:
143 - self.makeForbidden(403, "The input you sent could not be understood.")
144 + self.makeForbidden(403, u'The input you sent could not be understood!')
145 return
146 self.action = self.form.get('action', ['show'])[0]
147 try:
148 @@ -233,7 +233,7 @@
149
150 if self.action != 'xmlrpc':
151 if not self.forbidden and self.isForbidden():
152 - self.makeForbidden403()
153 + self.makeForbidden(403, u'Remote request is forbidden by configuration or spider detected!')
154 if not self.forbidden and self.surge_protect():
155 self.makeUnavailable503()
156
157 @@ -1040,17 +1040,18 @@
158 action != 'sitemap'
159 ):
160 forbidden = self.isSpiderAgent
161 + logging.info("Query %(query_string)s with request method %(request_method)s and action %(action)s detected as spider which is forbidden." % {'query_string': qs, 'request_method': self.request_method, 'action': action})
162
163 if not forbidden and self.cfg.hosts_deny:
164 ip = self.remote_addr
165 for host in self.cfg.hosts_deny:
166 if host[-1] == '.' and ip.startswith(host):
167 forbidden = 1
168 - logging.debug("hosts_deny (net): %s" % str(forbidden))
169 + logging.info("Remote address %(remote_addr)s match %(host_deny) which is forbidden." % {'remote_addr': self.remote_addr, 'host_deny': host})
170 break
171 if ip == host:
172 forbidden = 1
173 - logging.debug("hosts_deny (ip): %s" % str(forbidden))
174 + logging.info("Remote address %(remote_addr)s match %(host_deny) which is forbidden." % {'remote_addr': self.remote_addr, 'host_deny': host})
175 break
176 return forbidden
177
178 @@ -1155,21 +1156,21 @@
179 'Status: %d %s' % (resultcode, statusmsg[resultcode]),
180 'Content-Type: text/plain; charset=utf-8'
181 ]
182 + if resultcode == 403 and msg == None:
183 + msg = u'You are not allowed to access this!'
184 + logging.info('Error %d: %s' % (resultcode, statusmsg[resultcode], msg,))
185 # when surge protection triggered, tell bots to come back later...
186 if resultcode == 503:
187 headers.append('Retry-After: %d' % self.cfg.surge_lockout_time)
188 self.emit_http_headers(headers)
189 - self.write(msg)
190 + self.write(msg + u'\r\n')
191 self.forbidden = True
192 -
193 - def makeForbidden403(self):
194 - self.makeForbidden(403, 'You are not allowed to access this!\r\n')
195
196 def makeUnavailable503(self):
197 self.makeForbidden(503, "Warning:\r\n"
198 "You triggered the wiki's surge protection by doing too many requests in a short time.\r\n"
199 "Please make a short break reading the stuff you already got.\r\n"
200 - "When you restart doing requests AFTER that, slow down or you might get locked out for a longer time!\r\n")
201 + "When you restart doing requests AFTER that, slow down or you might get locked out for a longer time!")
202
203 def initTheme(self):
204 """ Set theme - forced theme, user theme or wiki default """
RaphaelBossek-DetailedForbiddenReasons.patch