I have hit a use-after-free in mod_dav_svn while running SVN's regression
tests on OpenBSD with httpd 2.4. This problem was apparently known to the
author; see the comment which is removed in the diff below.
In short, the request structure used as logging context can already be
freed before log_warning() runs. The repository structure is allocated
in the request's pool, which means the repository is closed when the
request pool gets freed. I am not sure which, if any, ordering guarantess
exist in this situation. But the patch below switches the logging context
to the connection instead of the request and I have been unable to reproduce
the issue since.
Is there a better solution?
Does my proposed solution lose too much logging context?
Below is a crash trace; On OpenBSD, freed memory gets overwritten with 0xdf.
$ egdb /home/stsp/svn/prefix/httpd/bin/httpd httpd.c> <
GNU gdb (GDB) 7.12.1
Copyright (C) 2017 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-unknown-openbsd6.4".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /home/stsp/svn/prefix/httpd/bin/httpd...done.
[New process 351753]
Core was generated by `httpd'.
Program terminated with signal SIGBUS, Bus error.
#0 0x000008baba525290 in ap_get_request_module_loglevel (r=0x8bcbc3b0400,
module_index=-1) at /home/stsp/svn/src/httpd-2.4.37/server/util_debug.c:200
200 return l->level;
(gdb) p l
$1 = (const struct ap_logconf *) 0xdfdfdfdfdfdfdfdf
(gdb) up
#1 0x000008baba50f45c in log_error_core (
file=0x8bd831429d6 "subversion/mod_dav_svn/repos.c", line=1246,
module_index=-1, level=3, status=20014, s=0xdfdfdfdfdfdfdfdf,
c=0xdfdfdfdfdfdfdfdf, r=0x8bcbc3b0400, pool=0x0, fmt=0x8bd83149264 "%s%s",
args=0x7f7ffffceb20) at /home/stsp/svn/src/httpd-2.4.37/server/log.c:1169
1169 int configured_level = r ? ap_get_request_module_loglevel(r, module_index) :
(gdb) up
#2 0x000008baba50fe9b in ap_log_rerror_ (
file=0x8bd831429d6 "subversion/mod_dav_svn/repos.c", line=1246,
module_index=-1, level=3, status=20014, r=0x8bcbc3b0400,
fmt=0x8bd83149264 "%s%s")
at /home/stsp/svn/src/httpd-2.4.37/server/log.c:1368
1368 log_error_core(file, line, module_index, level, status, r->server, NULL, r,
(gdb) p *r
$4 = {pool = 0xdfdfdfdfdfdfdfdf, connection = 0xdfdfdfdfdfdfdfdf,
server = 0xdfdfdfdfdfdfdfdf, next = 0xdfdfdfdfdfdfdfdf,
prev = 0xdfdfdfdfdfdfdfdf, main = 0xdfdfdfdfdfdfdfdf,
the_request = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>, assbackwards = -538976289, proxyreq = -538976289,
header_only = -538976289, proto_num = -538976289,
protocol = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
hostname = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>, request_time = -2314885530818453537,
status_line = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>, status = -538976289, method_number = -538976289,
method = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>, allowed = -2314885530818453537,
allowed_xmethods = 0xdfdfdfdfdfdfdfdf, allowed_methods = 0xdfdfdfdfdfdfdfdf,
sent_bodyct = -2314885530818453537, bytes_sent = -2314885530818453537,
mtime = -2314885530818453537,
range = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>, clength = -2314885530818453537, chunked = -538976289,
read_body = -538976289, read_chunked = -538976289,
expecting_100 = 3755991007, kept_body = 0xdfdfdfdfdfdfdfdf,
body_table = 0xdfdfdfdfdfdfdfdf, remaining = -2314885530818453537,
read_length = -2314885530818453537, headers_in = 0xdfdfdfdfdfdfdfdf,
headers_out = 0xdfdfdfdfdfdfdfdf, err_headers_out = 0xdfdfdfdfdfdfdfdf,
subprocess_env = 0xdfdfdfdfdfdfdfdf, notes = 0xdfdfdfdfdfdfdfdf,
content_type = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
handler = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
content_encoding = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>, content_languages = 0xdfdfdfdfdfdfdfdf,
vlist_validator = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
user = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
ap_auth_type = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
unparsed_uri = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
uri = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
filename = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
canonical_filename = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
path_info = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
args = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>, used_path_info = -538976289, eos_sent = -538976289,
per_dir_config = 0xdfdfdfdfdfdfdfdf, request_config = 0xdfdfdfdfdfdfdfdf,
log = 0xdfdfdfdfdfdfdfdf,
log_id = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>, htaccess = 0xdfdfdfdfdfdfdfdf, output_filters = 0xdfdfdfdfdfdfdfdf,
input_filters = 0xdfdfdfdfdfdfdfdf,
proto_output_filters = 0xdfdfdfdfdfdfdfdf,
proto_input_filters = 0xdfdfdfdfdfdfdfdf, no_cache = -538976289,
no_local_copy = -538976289, invoke_mtx = 0xdfdfdfdfdfdfdfdf, parsed_uri = {
scheme = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
hostinfo = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
user = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
password = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
hostname = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
port_str = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
path = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
query = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
fragment = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>, hostent = 0xdfdfdfdfdfdfdfdf, port = 57311, is_initialized = 1,
dns_looked_up = 1, dns_resolved = 1}, finfo = {pool = 0xdfdfdfdfdfdfdfdf,
valid = -538976289, protection = -538976289, filetype = 3755991007,
user = 3755991007, group = 3755991007, inode = 16131858542891098079,
device = -538976289, nlink = -538976289, size = -2314885530818453537,
csize = -2314885530818453537, atime = -2314885530818453537,
mtime = -2314885530818453537, ctime = -2314885530818453537,
fname = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>,
name = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>, filehand = 0xdfdfdfdfdfdfdfdf},
useragent_addr = 0xdfdfdfdfdfdfdfdf,
useragent_ip = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>, trailers_in = 0xdfdfdfdfdfdfdfdf,
trailers_out = 0xdfdfdfdfdfdfdfdf,
useragent_host = 0xdfdfdfdfdfdfdfdf <error: Cannot access memory at address 0xdfdfdfdfdfdfdfdf>, double_reverse = -538976289}
(gdb) bt
#0 0x000008baba525290 in ap_get_request_module_loglevel (r=0x8bcbc3b0400,
module_index=-1) at /home/stsp/svn/src/httpd-2.4.37/server/util_debug.c:200
#1 0x000008baba50f45c in log_error_core (
file=0x8bd831429d6 "subversion/mod_dav_svn/repos.c", line=1246,
module_index=-1, level=3, status=20014, s=0xdfdfdfdfdfdfdfdf,
c=0xdfdfdfdfdfdfdfdf, r=0x8bcbc3b0400, pool=0x0, fmt=0x8bd83149264 "%s%s",
args=0x7f7ffffceb20) at /home/stsp/svn/src/httpd-2.4.37/server/log.c:1169
#2 0x000008baba50fe9b in ap_log_rerror_ (
file=0x8bd831429d6 "subversion/mod_dav_svn/repos.c", line=1246,
module_index=-1, level=3, status=20014, r=0x8bcbc3b0400,
fmt=0x8bd83149264 "%s%s")
at /home/stsp/svn/src/httpd-2.4.37/server/log.c:1368
#3 0x000008bd831785a6 in log_warning (baton=0x8bcbc3b0400, err=0x8bcc9317100)
at subversion/mod_dav_svn/repos.c:1246
#4 0x000008bd83367cab in cleanup_fs_apr (data=0x8bd75fc3e00)
at subversion/libsvn_fs_base/fs.c:297
#5 0x000008bd1c71183f in run_cleanups (cref=0x8bdb2d12d20)
at /home/stsp/svn/src/apr-1.5.2/memory/unix/apr_pools.c:2352
#6 0x000008bd1c70fd24 in pool_clear_debug (pool=0x8bdb2d12d00,
file_line=0x8baba4a8c30 "/home/stsp/svn/src/httpd-2.4.37/server/mpm/prefork/prefork.c:507") at /home/stsp/svn/src/apr-1.5.2/memory/unix/apr_pools.c:1553
#7 0x000008bd1c70fc37 in apr_pool_clear_debug (pool=0x8bdb2d12d00,
file_line=0x8baba4a8c30 "/home/stsp/svn/src/httpd-2.4.37/server/mpm/prefork/prefork.c:507") at /home/stsp/svn/src/apr-1.5.2/memory/unix/apr_pools.c:1613
#8 0x000008baba575f08 in child_main (child_num_arg=9, child_bucket=0)
at /home/stsp/svn/src/httpd-2.4.37/server/mpm/prefork/prefork.c:507
#9 0x000008baba575151 in make_child (s=0x8bd737d6a00, slot=9, bucket=0)
at /home/stsp/svn/src/httpd-2.4.37/server/mpm/prefork/prefork.c:716
#10 0x000008baba575744 in perform_idle_server_maintenance (p=0x8bceead7500)
at /home/stsp/svn/src/httpd-2.4.37/server/mpm/prefork/prefork.c:824
#11 0x000008baba5745af in prefork_run (_pconf=0x8bceead7500,
plog=0x8bcdeb90400, s=0x8bd737d6a00)
at /home/stsp/svn/src/httpd-2.4.37/server/mpm/prefork/prefork.c:1019
#12 0x000008baba522abf in ap_run_mpm (pconf=0x8bceead7500, plog=0x8bcdeb90400,
s=0x8bd737d6a00) at /home/stsp/svn/src/httpd-2.4.37/server/mpm_common.c:94
#13 0x000008baba5032e0 in main (argc=5, argv=0x7f7ffffcf458)
at /home/stsp/svn/src/httpd-2.4.37/server/main.c:819
(gdb) quit
[[[
* subversion/mod_dav_svn/repos.c
(log_warning): Use a connection context instead of a request context.
The request may already have been freed when this function executes.
(get_resource): Pass connection context to log_warning().
]]]
Index: subversion/mod_dav_svn/repos.c
===================================================================
--- subversion/mod_dav_svn/repos.c (revision 1849066)
+++ subversion/mod_dav_svn/repos.c (working copy)
@@ -1228,22 +1228,14 @@ create_private_resource(const dav_resource *base,
static void log_warning(void *baton, svn_error_t *err)
{
- request_rec *r = baton;
+ conn_rec *c = baton;
const char *continuation = "";
- /* ### hmm. the FS is cleaned up at request cleanup time. "r" might
- ### not really be valid. we should probably put the FS into a
- ### subpool to ensure it gets cleaned before the request.
-
- ### is there a good way to create and use a subpool for all
- ### of our functions ... ??
- */
-
/* Not showing file/line so no point in tracing */
err = svn_error_purge_tracing(err);
while (err)
{
- ap_log_rerror(APLOG_MARK, APLOG_ERR, APR_EGENERAL, r, "%s%s",
+ ap_log_cerror(APLOG_MARK, APLOG_ERR, APR_EGENERAL, c, "%s%s",
continuation, err->message);
continuation = "-";
err = err->child;
@@ -2485,8 +2477,11 @@ get_resource(request_rec *r,
/* cache the filesystem object */
repos->fs = svn_repos_fs(repos->repos);
- /* capture warnings during cleanup of the FS */
- svn_fs_set_warning_func(repos->fs, log_warning, r);
+ /* Capture warnings during cleanup of the FS.
+ * The FS is cleaned up at request cleanup time, at which point "r" might
+ * no longer be valid, leading to a use after free. So we log warnings
+ * with a connection context instead of a request context. */
+ svn_fs_set_warning_func(repos->fs, log_warning, r->connection);
/* if an authenticated username is present, attach it to the FS */
if (r->user)
Received on 2018-12-17 10:44:52 CET