Bug 66601 - coredump at apr_pool_destroy in mod
Summary: coredump at apr_pool_destroy in mod
Status: NEW
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: mod_cache_disk / mod_disk_cache (show other bugs)
Version: 2.5-HEAD
Hardware: PC Linux
: P2 normal (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2023-05-16 02:24 UTC by chengyechun1
Modified: 2023-05-16 10:52 UTC (History)
0 users



Attachments
debug info (64.58 KB, text/plain)
2023-05-16 09:45 UTC, chengyechun1
Details

Note You need to log in before you can comment on or make changes to this bug.
Description chengyechun1 2023-05-16 02:24:21 UTC
A core dump occurs in the apr_pool_destroy function (line 1373) of mod_cache_disk.c. After analysis, it is found that the input pool is 0x0. I wonder whether judgment can be added here or in apr_pool_destroy. Or you don't think that's possible here;
The following is my coredump screenshot and the printed content. Ignore the specific line number due to the version. The positions are the same.

(gdb) bt
#0  run_cleanups (cref=0x70) at memory/unix/apr_pools.c:2660
#1  apr_pool_destroy (pool=0x0) at memory/unix/apr_pools.c:993
#2  0x0000ffff82b32b08 in commit_entity (h=0xffff68015b50, r=0xffff68012c70) at mod_cache_disk.c:1366
#3  0x0000ffff82b53ffc in cache_save_store (f=0xffff68014a28, in=0xffff68015b10, conf=0xaaaaffe6d278, cache=0xffff680146d0) at mod_cache.c:736
#4  0x0000ffff82b56af0 in cache_save_filter (f=0xffff68014a28, in=0xffff68015b10) at mod_cache.c:1606
#5  0x0000aaaad8e48064 in default_handler (r=0xffff68012c70) at core.c:4979
#6  0x0000aaaad8e5ce80 in ap_run_handler (r=r@entry=0xffff68012c70) at config.c:169
#7  0x0000aaaad8e5d588 in ap_invoke_handler (r=r@entry=0xffff68012c70) at config.c:443
#8  0x0000aaaad8e74540 in ap_process_async_request (r=r@entry=0xffff68012c70) at http_request.c:452
#9  0x0000aaaad8e7076c in ap_process_http_async_connection (c=0xfffef4000fa0) at http_core.c:155
#10 ap_process_http_connection (c=0xfffef4000fa0) at http_core.c:246
#11 0x0000aaaad8e66b20 in ap_run_process_connection (c=c@entry=0xfffef4000fa0) at connection.c:42
#12 0x0000ffff824a1b68 in process_socket (thd=thd@entry=0xaaaafffa9610, p=<optimized out>, sock=<optimized out>, cs=<optimized out>, my_child_num=my_child_num@entry=1,
    my_thread_num=my_thread_num@entry=24) at event.c:1052
#13 0x0000ffff824a2394 in worker_thread (thd=0xaaaafffa9610, dummy=<optimized out>) at event.c:2141
#14 0x0000ffff8321b280 in start_thread (arg=0x0) at pthread_create.c:443
#15 0x0000ffff8328179c in thread_start () at ../sysdeps/unix/sysv/linux/aarch64/clone.S:79


(gdb) f 2
(gdb) p *(disk_cache_object_t *)((((cache_request_rec *)r->output_filters->ctx)->handle)->cache_obj)->vobj
$40 = {root = 0xffff68015d38 "/var/cache/httpd/proxy", root_len = 22, prefix = 0x0, data = {pool = 0x0, file = 0xffff68015d70 "/var/cache/httpd/proxy/NP/ZG/fBHmUYzRXQL9t8q4Qw.data", fd = 0x0,
    tempfile = 0x0, tempfd = 0x0}, hdrs = {pool = 0x0, file = 0xffff68015da8 "/var/cache/httpd/proxy/NP/ZG/fBHmUYzRXQL9t8q4Qw.header", fd = 0x0, tempfile = 0x0, tempfd = 0x0}, vary = {pool = 0x0,
    file = 0xffff68015de0 "/var/cache/httpd/proxy/NP/ZG/fBHmUYzRXQL9t8q4Qw.header", fd = 0x0, tempfile = 0x0, tempfd = 0x0}, hashfile = 0xffff68015d50 "NP/ZG/fBHmUYzRXQL9t8q4Qw",
  name = 0xffff68015d20 "https://sinon:443/?", key = 0x0, file_size = 13, disk_info = {format = 0, status = 0, name_len = 0, entity_version = 1, date = 0, expire = 0, request_time = 0,
    response_time = 0, inode = 3019152, device = 64768, has_body = 1, header_only = 0, control = {parsed = 0, cache_control = 0, pragma = 0, no_cache = 0, no_cache_header = 0, no_store = 0,
      max_age = 0, max_stale = 0, min_fresh = 0, no_transform = 0, only_if_cached = 0, public = 0, private = 0, private_header = 0, must_revalidate = 0, proxy_revalidate = 0, s_maxage = 0,
      invalidated = 0, max_age_value = 0, max_stale_value = 0, min_fresh_value = 0, s_maxage_value = 0}}, headers_in = 0xffff68016258, headers_out = 0xffff68016070, offset = 0, timeout = 0, done = 1}
(gdb)
Comment 1 Ruediger Pluem 2023-05-16 06:40:17 UTC
Can you reproduce the issue? Can you provide the error logfile at best at level debug?
Comment 2 Ruediger Pluem 2023-05-16 06:42:24 UTC
The pool should not be NULL here and just checking for NULL would probably hide the underlying bug. It looks like that the pool was already destroyed before.
Comment 3 chengyechun1 2023-05-16 06:51:23 UTC
(In reply to Ruediger Pluem from comment #2)
> The pool should not be NULL here and just checking for NULL would probably
> hide the underlying bug. It looks like that the pool was already destroyed
> before.

thank you for reply
This problem seems to occur occasionally and has not recurred yet. In addition, there is no debug log when the core dump occurs, and only the core dump file can be viewed. But maybe because of the version, this file is not available to you;

When I analyze the call stack step by step, I find that the pool is still 0x0 at layer 9 and that an address cannot be accessed at layer 10. As a result, the analysis cannot continue.

(gdb) f 9
#9  0x0000aaaad8e7076c in ap_process_http_async_connection (c=0xfffef4000fa0) at http_core.c:155
155                     ap_process_async_request(r);

(gdb) p *(disk_cache_object_t *)((((cache_request_rec *)r->output_filters->ctx)->handle)->cache_obj)->vobj
$41 = {root = 0xffff68015d38 "/var/cache/httpd/proxy", root_len = 22, prefix = 0x0, data = {pool = 0x0, file = 0xffff68015d70 "/var/cache/httpd/proxy/NP/ZG/fBHmUYzRXQL9t8q4Qw.data", fd = 0x0,
    tempfile = 0x0, tempfd = 0x0}, hdrs = {pool = 0x0, file = 0xffff68015da8 "/var/cache/httpd/proxy/NP/ZG/fBHmUYzRXQL9t8q4Qw.header", fd = 0x0, tempfile = 0x0, tempfd = 0x0}, vary = {pool = 0x0,
    file = 0xffff68015de0 "/var/cache/httpd/proxy/NP/ZG/fBHmUYzRXQL9t8q4Qw.header", fd = 0x0, tempfile = 0x0, tempfd = 0x0}, hashfile = 0xffff68015d50 "NP/ZG/fBHmUYzRXQL9t8q4Qw",
  name = 0xffff68015d20 "https://sinon:443/?", key = 0x0, file_size = 13, disk_info = {format = 0, status = 0, name_len = 0, entity_version = 1, date = 0, expire = 0, request_time = 0,
    response_time = 0, inode = 3019152, device = 64768, has_body = 1, header_only = 0, control = {parsed = 0, cache_control = 0, pragma = 0, no_cache = 0, no_cache_header = 0, no_store = 0,
      max_age = 0, max_stale = 0, min_fresh = 0, no_transform = 0, only_if_cached = 0, public = 0, private = 0, private_header = 0, must_revalidate = 0, proxy_revalidate = 0, s_maxage = 0,
      invalidated = 0, max_age_value = 0, max_stale_value = 0, min_fresh_value = 0, s_maxage_value = 0}}, headers_in = 0xffff68016258, headers_out = 0xffff68016070, offset = 0, timeout = 0, done = 1}


(gdb) f 10
#10 ap_process_http_connection (c=0xfffef4000fa0) at http_core.c:246
246             return ap_process_http_async_connection(c);

(gdb) p *(cache_request_rec *)c->output_filters->ctx
$43 = {providers = 0x0, provider = 0x0, provider_name = 0x14 <error: Cannot access memory at address 0x14>, fresh = 0, handle = 0x7d0, stale_handle = 0x0, stale_headers = 0xffff82811048,
  in_checked = -201323280, block_response = 65534, saved_brigade = 0x0, saved_size = 187651414588256, exp = 281472426703872, lastmod = 281470480422544, info = 0x0, save_filter = 0xfffef4000fa0,
  remove_url_filter = 0xaaaaffe87788, key = 0xffff6801fc00 "", size = 281470480422320, out = 0x0, control_in = {parsed = 0, cache_control = 0, pragma = 0, no_cache = 0, no_cache_header = 0,
    no_store = 1, max_age = 0, max_stale = 1, min_fresh = 1, no_transform = 1, only_if_cached = 1, public = 1, private = 0, private_header = 0, must_revalidate = 0, proxy_revalidate = 0,
    s_maxage = 0, invalidated = 0, max_age_value = 281470480419944, max_stale_value = 281472426704032, min_fresh_value = 281472426704032, s_maxage_value = 281472426576792}}

(gdb) p *((cache_request_rec *)c->output_filters->ctx)->handle
Cannot access memory at address 0x7d0
Comment 4 Yann Ylavic 2023-05-16 09:38:24 UTC
Could you please post the content of:
(gdb) thread apply all bt
?
Comment 5 chengyechun1 2023-05-16 09:45:24 UTC
Created attachment 38558 [details]
debug info
Comment 6 Ruediger Pluem 2023-05-16 10:52:19 UTC
(In reply to chengyechun1 from comment #3)
> (In reply to Ruediger Pluem from comment #2)
> > The pool should not be NULL here and just checking for NULL would probably
> > hide the underlying bug. It looks like that the pool was already destroyed
> > before.
> 
> thank you for reply
> This problem seems to occur occasionally and has not recurred yet. In
> addition, there is no debug log when the core dump occurs, and only the core
> dump file can be viewed. But maybe because of the version, this file is not
> available to you;

Even if there is no error log on loglevel debug can you please attach the error log at around the point of time where the crash happened?