Bug 66539 - Crash in mod_log_config when using the new mod_http2 in httpd-2.4.56
Summary: Crash in mod_log_config when using the new mod_http2 in httpd-2.4.56
Status: RESOLVED FIXED
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: mod_http2 (show other bugs)
Version: 2.4.56
Hardware: PC Linux
: P2 normal (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2023-03-22 10:21 UTC by Teodor Milkov
Modified: 2023-04-12 07:34 UTC (History)
0 users



Attachments
h2 request headers clone instead of copy (878 bytes, patch)
2023-03-22 11:09 UTC, Stefan Eissing
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Teodor Milkov 2023-03-22 10:21:25 UTC
After upgrading to httpd 2.4.56 I strted seeing occasional segmentation faults like this:

[Sun Mar 19 14:22:28 2023] [notice] [pid 2179] mpm_unix.c(433): AH00052: child pid 60058 exit signal Segmentation fault (11)

I compiled httpd with debug symbols and managed to get code dump. Here's a backtrace:

#0  __strcasecmp_l_avx () at ../sysdeps/x86_64/multiarch/strcmp-sse42.S:199
#1  0x000071c2dd48f5f1 in apr_table_get () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#2  0x000011f829ca9a53 in log_header_in (r=0x71c1b15550a0, a=0x71c2d212cc08 "Referer") at mod_log_config.c:441
#3  0x000011f829cab245 in process_item (r=0x71c1b15550a0, orig=0x71c1b15550a0, item=0x71c2d212ce80) at mod_log_config.c:1095
#4  0x000011f829cab50f in config_log_transaction (r=0x71c1b15550a0, cls=0x71c2dad4baf0, default_format=0x71c2dd06b0c0) at mod_log_config.c:1168
#5  0x000011f829cab745 in multi_log_transaction (r=0x71c1b15550a0) at mod_log_config.c:1206
#6  0x000011f829c368ed in ap_run_log_transaction (r=0x71c1b15550a0) at protocol.c:2586
#7  0x000011f829c4bd3f in eor_bucket_cleanup (data=0x71c2481af390) at eor_bucket.c:40
#8  0x000071c2dd49780e in apr_pool_destroy () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#9  0x000071c2dd49782d in apr_pool_destroy () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#10 0x000071c2dd49782d in apr_pool_destroy () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#11 0x000071c2dd49782d in apr_pool_destroy () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#12 0x000071c2dd49782d in apr_pool_destroy () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#13 0x000071c2dd02a605 in ?? () from /apache/modules/mod_http2.so
#14 0x000071c2dd014e85 in ?? () from /apache/modules/mod_http2.so
#15 0x000011f829c626ac in ap_run_pre_close_connection (c=0x71c292e33360) at connection.c:44
#16 0x000011f829c62840 in ap_prep_lingering_close (c=0x71c292e33360) at connection.c:101
#17 0x000011f829c628b5 in ap_start_lingering_close (c=0x71c292e33360) at connection.c:127
#18 0x000011f829d0b34e in process_lingering_close (cs=0x71c292e332b0) at event.c:1500
#19 0x000011f829d0a997 in process_socket (thd=0x71c2c4c3b068, p=0x71c292e33028, sock=0x71c292e330b0, cs=0x71c292e332b0, my_child_num=2, my_thread_num=949) at event.c:1238
#20 0x000011f829d0d7b8 in worker_thread (thd=0x71c2c4c3b068, dummy=0x71c2c80564b0) at event.c:2199
#21 0x000011f829c26a78 in thread_start (thread=0x71c2c4c3b068, data=0x71c2c4c3b058) at util.c:3208
#22 0x000071c2dd45aea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#23 0x000071c2dd37aa2f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

I've also tried to see what's inside r->headers_in (thanks to https://github.com/omnigroup/Apache/blob/master/httpd/.gdbinit making my life easier), but got:

(gdb) dump_table  r->headers_in
[0] 'Cannot access memory at address 0x71c268dde410

On the other hand r->headers_out is ok.

Because mod_http2 is the biggest change, we build http-2.4.56 with the older mod_h2 and it is not crashing anymore.
Comment 1 Stefan Eissing 2023-03-22 11:09:39 UTC
Created attachment 38527 [details]
h2 request headers clone instead of copy
Comment 2 Stefan Eissing 2023-03-22 11:10:11 UTC
Thanks for the detailed report! Could you test if the attached patch resolve the issue? Thanks!
Comment 3 Teodor Milkov 2023-03-24 15:43:39 UTC
I no longer see segmentation faults with the provided patch. Thank you for your swift reaction!
Comment 4 Stefan Eissing 2023-03-24 16:20:28 UTC
Excellent. Thank you!

Add to trunk as r1908691 and proposed for backport.
Comment 5 Teodor Milkov 2023-04-11 11:08:15 UTC
Hello,

I see there's 2.4.57 incorporating this fix, so naturally I tried it and for my big surprise it crashed in the same way as 2.4.56 without the patch.

I looked into httpd-2.4.57/modules/http2/h2_request.c and the apr_table_copy() -> apr_table_clone() fix seems to be there as expected.

Here's a backtrace, which looks very much the same as in 2.4.56:

#0  __strcasecmp_l_avx () at ../sysdeps/x86_64/multiarch/strcmp-sse42.S:199
#1  0x000072c28fc655f1 in apr_table_get () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#2  0x00001d2d6f31cafb in log_header_in (r=0x72c20813c0a0, a=0x72c28475fc08 "Referer") at mod_log_config.c:441
#3  0x00001d2d6f31e2ed in process_item (r=0x72c20813c0a0, orig=0x72c20813c0a0, item=0x72c28475fe80) at mod_log_config.c:1095
#4  0x00001d2d6f31e5b7 in config_log_transaction (r=0x72c20813c0a0, cls=0x72c28f838b00, default_format=0x72c28f8410c0) at mod_log_config.c:1168
#5  0x00001d2d6f31e7ed in multi_log_transaction (r=0x72c20813c0a0) at mod_log_config.c:1206
#6  0x00001d2d6f2a98ed in ap_run_log_transaction (r=0x72c20813c0a0) at protocol.c:2586
#7  0x00001d2d6f2bed3f in eor_bucket_cleanup (data=0x72c2081db390) at eor_bucket.c:40
#8  0x000072c28fc6d80e in apr_pool_destroy () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#9  0x000072c28fc6d82d in apr_pool_destroy () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#10 0x000072c28fc6d82d in apr_pool_destroy () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#11 0x000072c28fc6d82d in apr_pool_destroy () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#12 0x000072c28fc6d82d in apr_pool_destroy () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#13 0x000072c28f800605 in ?? () from /apache/modules/mod_http2.so
#14 0x000072c28f7eae85 in ?? () from /apache/modules/mod_http2.so
#15 0x00001d2d6f2d56ac in ap_run_pre_close_connection (c=0x72c26c11f360) at connection.c:44
#16 0x00001d2d6f2d5840 in ap_prep_lingering_close (c=0x72c26c11f360) at connection.c:101
#17 0x00001d2d6f2d58b5 in ap_start_lingering_close (c=0x72c26c11f360) at connection.c:127
#18 0x00001d2d6f37e56e in process_lingering_close (cs=0x72c26c11f2b0) at event.c:1500
#19 0x00001d2d6f37dbb7 in process_socket (thd=0x72c27f1387a8, p=0x72c26c11f028, sock=0x72c26c11f0b0, cs=0x72c26c11f2b0, my_child_num=0, my_thread_num=25)
    at event.c:1238
#20 0x00001d2d6f380920 in worker_thread (thd=0x72c27f1387a8, dummy=0x72c278002f50) at event.c:2179
#21 0x00001d2d6f299a78 in thread_start (thread=0x72c27f1387a8, data=0x72c27f138798) at util.c:3208
#22 0x000072c28fc30ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#23 0x000072c28fb50a2f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95


(gdb) dump_table  r->headers_out
[0] 'Last-Modified'='Wed, 28 Nov 2018 20:17:41 GMT'
…

(gdb) dump_table  r->headers_in
[0] 'Cannot access memory at address 0x72c26c0ea428


Please let me know if I can collect and provide any other useful information.
Comment 6 Stefan Eissing 2023-04-11 12:02:45 UTC
Can't wrap my head around that. As you noted, the patch that resolved the issue for you is part of the 2.5.57 release.

Excuse me double verifying: are you sure you look at a core from 2.5.57?
Comment 7 Stefan Eissing 2023-04-11 12:03:08 UTC
2.4.57, I meant.
Comment 8 Ruediger Pluem 2023-04-11 12:08:18 UTC
What looks strange to me is that in your latest stacktrace the debug information for mod_http2.so is missing whereas it is available for the remainder of httpd. Are you sure you use the mod_http2.so from 2.4.57?
Comment 9 Teodor Milkov 2023-04-12 07:25:10 UTC
Hello,

I apologize - it seems that during my build process, I accidentally used the external https://github.com/icing/mod_h2 instead of the built-in mod_http2. I believe this is a remnant of a past occurrence where certain bugs were only fixed in mod_h2.

Moving forward, I would like to confirm if it is recommended to use the built-in mod_http2 instead of the external mod_h2?

I am sorry for any time wasted on this matter.
Comment 10 Stefan Eissing 2023-04-12 07:34:06 UTC
Ah, sorry for the confusion. You hit the first time that the github version lagged behind the Apache one.

The github version is meant to be the experimental cousin of the one released by apache. I will update it.