subrequest triggered on request with WSGIScriptAlias

45 views

Skip to first unread message

Romain A.

unread,

Aug 13, 2019, 4:19:01 AM8/13/19

to modwsgi

Hello,

I'm currently facing a behavior from mod_wsgi/apache that is puzzling me.
With a WSGIScriptAlias /myapp, a request url '/myapp/subpath' seems to triggers a subrequest on '/subpath', which in my case, triggers an error log :

AH01630: client denied by server configuration: <DocumentRoot>/path1

Nonetheless, the request is then served correctly by the wsgi handler.
Is this behavior expected ?

At first i thought it might have been caused by our rather specific apache conf or django app, but I wrote the following test configuration, and the subrequest still happens.

.
├── conf/
│   └── httpd.conf
├── logs/
└── www/
    ├── myapp/
    │   └── wsgi.py
    └── static/

wsgi.py:

import sys
def application(environ, start_response):
    status = '200 OK'
    output = u'Hello World !\n'
    response_headers = [('Content-type', 'text/plain'),
                        ('Content-Length', str(len(output)))]
    start_response(status, response_headers)
    return [output.encode('UTF-8')]

httpd.conf:

Define EXAMPLE_ROOT ${PWD}
#Define MODULES_DIRECTORY /usr/lib/apache2/modules/
Define MODULES_DIRECTORY /usr/lib/httpd/modules/
Listen 0.0.0.0:8001

#LogLevel trace5
LogLevel warn

LoadModule wsgi_module '${MODULES_DIRECTORY}/mod_wsgi.so'

#User www-data
#Group www-data

########################################################################

ServerName _default_
PidFile logs/httpd.pid

<IfModule !authz_core_module>
LoadModule authz_core_module '${MODULES_DIRECTORY}/mod_authz_core.so'
</IfModule>

<IfModule !alias_module>
LoadModule alias_module '${MODULES_DIRECTORY}/mod_alias.so'
</IfModule>

<IfModule !mpm_event_module>
LoadModule mpm_event_module '${MODULES_DIRECTORY}/mod_mpm_event.so'
</IfModule>

<IfModule !unixd_module>
LoadModule unixd_module '${MODULES_DIRECTORY}/mod_unixd.so'
</IfModule>

###########################################################################

DocumentRoot 'www/static'

<Directory />
    Require all denied
</Directory>

<Directory '${EXAMPLE_ROOT}/www/myapp/'>
    <Files wsgi.py>
        Require all granted
    </Files>
</Directory>

WSGIScriptAlias /myapp '${EXAMPLE_ROOT}/www/myapp/wsgi.py'

###########################################################################
#Note: RewriteEngine not required, it only emphasis the subrequest in the trace logs
#
<IfModule !rewrite>
LoadModule rewrite_module '${MODULES_DIRECTORY}/mod_rewrite.so'
RewriteEngine On
</IfModule>

The request and response

$ curl "http://127.0.0.1:8001/myapp/path1/path2/" -o - --dump-header -
HTTP/1.1 200 OK
Date: Mon, 12 Aug 2019 20:24:38 GMT
Server: Apache/2.4.39 (Unix) mod_wsgi/4.5.24 Python/3.7
Content-Length: 14
Content-Type: text/plain


Hello World !

error_log (LogLevel: warn) :

[authz_core:error] [pid 11296:tid 139736255874816] [client 127.0.0.1:44190] AH01630: client denied by server configuration: /tmp/test2/www/static/path1

error_log (LogLevel: trace5) :

[core:trace5] [pid 11392:tid 139736255874816] protocol.c(710): [client 127.0.0.1:44192] Request received from client: GET /myapp/path1/path2/ HTTP/1.1
[http:trace4] [pid 11392:tid 139736255874816] http_request.c(437): [client 127.0.0.1:44192] Headers received from client:
[http:trace4] [pid 11392:tid 139736255874816] http_request.c(441): [client 127.0.0.1:44192]   Host: 127.0.0.1:8001
[http:trace4] [pid 11392:tid 139736255874816] http_request.c(441): [client 127.0.0.1:44192]   User-Agent: curl/7.65.3
[http:trace4] [pid 11392:tid 139736255874816] http_request.c(441): [client 127.0.0.1:44192]   Accept: */*
[rewrite:trace2] [pid 11392:tid 139736255874816] mod_rewrite.c(483): [client 127.0.0.1:44192] 127.0.0.1 - - [127.0.0.1/sid#561d64379630][rid#7f16d8002bd0/initial] init rewrite engine with requested uri /myapp/path1/path2/
[rewrite:trace1] [pid 11392:tid 139736255874816] mod_rewrite.c(483): [client 127.0.0.1:44192] 127.0.0.1 - - [127.0.0.1/sid#561d64379630][rid#7f16d8002bd0/initial] pass through /myapp/path1/path2/
[authz_core:debug] [pid 11392:tid 139736255874816] mod_authz_core.c(820): [client 127.0.0.1:44192] AH01626: authorization result of Require all granted: granted
[authz_core:debug] [pid 11392:tid 139736255874816] mod_authz_core.c(820): [client 127.0.0.1:44192] AH01626: authorization result of <RequireAny>: granted
[core:trace3] [pid 11392:tid 139736255874816] request.c(312): [client 127.0.0.1:44192] request authorized without authentication by access_checker_ex hook: /myapp/path1/path2/
[rewrite:trace2] [pid 11392:tid 139736255874816] mod_rewrite.c(483): [client 127.0.0.1:44192] 127.0.0.1 - - [127.0.0.1/sid#561d64379630][rid#7f16d8008c00/subreq] init rewrite engine with requested uri /path1/path2/
[rewrite:trace1] [pid 11392:tid 139736255874816] mod_rewrite.c(483): [client 127.0.0.1:44192] 127.0.0.1 - - [127.0.0.1/sid#561d64379630][rid#7f16d8008c00/subreq] pass through /path1/path2/
[authz_core:debug] [pid 11392:tid 139736255874816] mod_authz_core.c(820): [client 127.0.0.1:44192] AH01626: authorization result of Require all denied: denied
[authz_core:debug] [pid 11392:tid 139736255874816] mod_authz_core.c(820): [client 127.0.0.1:44192] AH01626: authorization result of <RequireAny>: denied
[authz_core:error] [pid 11392:tid 139736255874816] [client 127.0.0.1:44192] AH01630: client denied by server configuration: /tmp/test2/www/static/path1
[core:trace3] [pid 11392:tid 139736255874816] request.c(119): [client 127.0.0.1:44192] auth phase 'check access' gave status 403: /path1/path2/
[wsgi:info] [pid 11392:tid 139736255874816] mod_wsgi (pid=11392): Create interpreter '_default_:8001|/myapp'.
[wsgi:info] [pid 11392:tid 139736255874816] [client 127.0.0.1:44192] mod_wsgi (pid=11392, process='', application='_default_:8001|/myapp'): Loading WSGI script '/tmp/test2/www/myapp/wsgi.py'.
[http:trace3] [pid 11392:tid 139736255874816] http_filters.c(1128): [client 127.0.0.1:44192] Response sent with status 200, headers:
[http:trace5] [pid 11392:tid 139736255874816] http_filters.c(1135): [client 127.0.0.1:44192]   Date: Mon, 12 Aug 2019 20:46:07 GMT
[http:trace5] [pid 11392:tid 139736255874816] http_filters.c(1138): [client 127.0.0.1:44192]   Server: Apache/2.4.39 (Unix) mod_wsgi/4.5.24 Python/3.7
[http:trace4] [pid 11392:tid 139736255874816] http_filters.c(957): [client 127.0.0.1:44192]   Content-Length: 14
[http:trace4] [pid 11392:tid 139736255874816] http_filters.c(957): [client 127.0.0.1:44192]   Content-Type: text/plain

I tested this with :

Apache/2.4.39 (Archlinux) mod_wsgi/4.5.24 Python/3.7
Apache/2.4.25 (Debian Stretch) mod_wsgi/4.6.8 (develop) Python/3.5

Has someone encoutered this behavior ?

Maybe I'm missing an obvious configuration, but for now I'm clueless.

Thanks,

Romain

Romain A.

unread,

Dec 15, 2019, 8:22:17 PM12/15/19

to modwsgi

Hello mod_wsgi,

i've finally had time to set up a debug environment to dig into this behavior.

The subrequest is made by the apache function ap_add_cgi_vars() (httpd/server/util_script.c:381), computing PATH_TRANSLATED environ from r->path_info.

With this information, i uncovered the ticket https://bz.apache.org/bugzilla/show_bug.cgi?id=43666, which in fact describes the same behavior I encountered, but with the handler cgi-script.

Note that in both cases, the behavior is noticable due to the confusing error log, caused by the fact that a default "denied" rule is set on '/'.

Concerning mod-wsgi,

ap_add_cgi_vars() is directly called directly by wsgi_build_environment().

I noted that the resulting value of PATH_TRANSLATED seems wrong, at least in my test case :

DocumentRoot 'www/static'

<Directory />
    Require all denied
</Directory>

<Directory '${EXAMPLE_ROOT}/www/myapp/'>
    <Files wsgi.py>
        Require all granted
    </Files>
</Directory>

WSGIScriptAlias /myapp '${EXAMPLE_ROOT}/www/myapp/wsgi.py'

=> The value of environ["PATH_TRANSLATED"] in wsgi.py is "${EXAMPLE_ROOT}/www/static/path1/path2/"

(instead of "${EXAMPLE_ROOT}/www/myapp/wsgi.py/path1/path2/" as i think it should be)

If this is accurate, i think that wsgi_build_environment() should not use ap_add_cgi_vars(), but compute the needed variables directly.

In fact, i've found that mod_fastcgi did exactly that, providing it's own function, to avoid the subrequest

(see add_auth_cgi_vars() in https://opensource.apple.com/source/apache_mod_fastcgi/apache_mod_fastcgi-3/mod_fastcgi/fcgi_protocol.c.auto.html)

Thanks,

Romain

On Tuesday, August 13, 2019 at 10:19:01 AM UTC+2, Romain A. wrote:

Hello,

I'm currently facing a behavior from mod_wsgi/apache that is puzzling me.
With a WSGIScriptAlias /myapp, a request url '/myapp/subpath' seems to triggers a subrequest on '/subpath', which in my case, triggers an error log :
AH01630: client denied by server configuration: <DocumentRoot>/path1
Nonetheless, the request is then served correctly by the wsgi handler.
Is this behavior expected ?