Bug 58307 - Segmentation fault in child in "read(__nbytes, __buf, __fd) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44"
Summary: Segmentation fault in child in "read(__nbytes, __buf, __fd) at /usr/include/x...
Status: RESOLVED FIXED
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: Core (show other bugs)
Version: 2.4.10
Hardware: PC Linux
: P2 normal (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2015-08-31 07:58 UTC by Matthias Nagel
Modified: 2019-06-14 18:08 UTC (History)
1 user (show)



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Matthias Nagel 2015-08-31 07:58:46 UTC
I am running Apache 2.4.10 (Debian Jessie) with dav and davfs module. My client program tries to PUT a series of files and at some point Apache crashes during a read-syscall.

More precisely, the client tries to put 32768 files each with 4k bytes of random binary data. The files are enumerated from 00/00.bin through 07/ff.bin, this means the PUT requests are "PUT /webdav/00/00.bin" up to "PUT /webdav/07/ff.bin" whereby "/webdav" is the directory that is managed by the davfs module. The directory and all subdirectories (00 to 7f) already exist.

The back trace of the Apache process from a core dump is:


#0  0x00007f28f0fcdadd in read () at ../sysdeps/unix/syscall-template.S:81
#1  0x000056342357a9b7 in read (__nbytes=1, __buf=0x7ffef51cfd83, __fd=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44
#2  ap_mpm_podx_check (pod=<optimized out>) at mpm_unix.c:535
#3  0x00007f28edcb3524 in child_main (child_num_arg=0) at event.c:2262
#4  0x00007f28edcb7cbd in make_child (s=0x7f28f1a9ede0, slot=0) at event.c:2349
#5  0x00007f28edcb7d45 in startup_children (number_to_start=1) at event.c:2375
#6  0x00007f28edcb877e in event_run (_pconf=0x5, plog=0x7f28f1a9a028, s=0x7f28f1a9ede0) at event.c:2715
#7  0x0000563423553e7e in ap_run_mpm (pconf=0x7f28f1ac6028, plog=0x7f28f1a9a028, s=0x7f28f1a9ede0) at mpm_common.c:94
#8  0x000056342354d3c3 in main (argc=3, argv=0x7ffef51d01b8) at main.c:777
Comment 1 Yann Ylavic 2015-08-31 08:44:24 UTC
This thread is probably not the one which is segfaulting.

Could you provide the ouput of gdb's "thread apply all bt"?
Comment 2 Matthias Nagel 2015-08-31 08:53:01 UTC
Sure:

Thread 7 (Thread 0x7f28e7fff700 (LWP 881)):
#0  0x00007f28f0fcda7d in write () at ../sysdeps/unix/syscall-template.S:81
#1  0x00007f28f11f8a1e in apr_file_write () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#2  0x000056342358a6b6 in ap_default_log_writer (r=<optimized out>, handle=0x7f28f1a9b2c0, strs=0x7f28f19c3ec0, strl=0x7f28f19c3f58, nelts=<optimized out>, len=95) at mod_log_config.c:1581
#3  0x000056342358aa0b in config_log_transaction (r=0x7f28f19c70a0, cls=0x7f28f19c4030, cls@entry=0x7f28f1a1d510, default_format=0x7f28f19c3ec0) at mod_log_config.c:1162
#4  0x000056342358ac16 in multi_log_transaction (r=0x7f28f19c70a0) at mod_log_config.c:1190
#5  0x0000563423559e50 in ap_run_log_transaction (r=r@entry=0x7f28f19c70a0) at protocol.c:1793
#6  0x00005634235687bf in eor_bucket_cleanup (data=<optimized out>) at eor_bucket.c:35
#7  0x00007f28f11fb976 in apr_pool_destroy () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#8  0x00005634235688f6 in remove_empty_buckets (bb=0x7f28f19cb8b0) at core_filters.c:721
#9  0x0000563423568c88 in send_brigade_nonblocking (s=0x8, bb=0x7f28f19cb8b0, bytes_written=0x5f, c=0x7f28f0fcda7d <write+45>) at core_filters.c:711
#10 0x0000563423569c49 in ap_core_output_filter (f=0x8, new_bb=0x0) at core_filters.c:469
#11 0x00007f28edcb5a1f in process_socket (my_thread_num=<optimized out>, my_child_num=<optimized out>, cs=<optimized out>, sock=<optimized out>, p=<optimized out>, thd=<optimized out>) at event.c:1048
#12 worker_thread (thd=0x8, dummy=0x7f28f19c4030) at event.c:1865
#13 0x00007f28f0fc70a4 in start_thread (arg=0x7f28e7fff700) at pthread_create.c:309
#14 0x00007f28f0cf504d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 6 (Thread 0x7f28e67fc700 (LWP 884)):
#0  __lll_unlock_wake () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:371
#1  0x00007f28f0fca609 in _L_unlock_554 () from /lib/x86_64-linux-gnu/libpthread.so.0
#2  0x00007f28f0fca546 in __pthread_mutex_unlock_usercnt (mutex=0x7f28f1a6a7e0, decr=<optimized out>) at pthread_mutex_unlock.c:57
#3  0x00007f28edcb5f2c in process_socket (my_thread_num=<optimized out>, my_child_num=<optimized out>, cs=<optimized out>, sock=<optimized out>, p=<optimized out>, thd=<optimized out>) at event.c:1107
#4  worker_thread (thd=0x7f28f1a6a7e0, dummy=0x0) at event.c:1865
#5  0x00007f28f0fc70a4 in start_thread (arg=0x7f28e67fc700) at pthread_create.c:309
#6  0x00007f28f0cf504d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 5 (Thread 0x7f28e77fe700 (LWP 882)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007f28edcb9205 in ap_queue_pop_something (queue=0x7f28f1a6a560, sd=0x7f28e77fde70, ecs=0x7f28e77fde78, p=0x7f28e77fde80, te_out=0x7f28e77fde88) at fdqueue.c:438
#2  0x00007f28edcb578f in worker_thread (thd=0x7f28f1a6a5fc, dummy=0x80) at event.c:1823
#3  0x00007f28f0fc70a4 in start_thread (arg=0x7f28e77fe700) at pthread_create.c:309
#4  0x00007f28f0cf504d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 4 (Thread 0x7f28e6ffd700 (LWP 883)):
#0  0x00007f28f0cec50d in poll () at ../sysdeps/unix/syscall-template.S:81
#1  0x00007f28f12054db in apr_wait_for_io_or_timeout () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#2  0x00007f28f11ff23a in apr_socket_recv () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#3  0x00007f28f1422fc1 in ?? () from /usr/lib/x86_64-linux-gnu/libaprutil-1.so.0
#4  0x0000563423569331 in ap_core_input_filter (f=0x7f28f19bb770, b=0x7f28f19b3840, mode=<optimized out>, block=APR_BLOCK_READ, readbytes=2048) at core_filters.c:236
#5  0x000056342358d07a in logio_in_filter (f=<optimized out>, bb=0x7f28f19b3840, mode=<optimized out>, block=<optimized out>, readbytes=<optimized out>) at mod_logio.c:140
#6  0x0000563423585fc7 in ap_http_filter (f=0x7f28f19b8750, b=0x7f28f19b3840, mode=300000, block=(APR_NONBLOCK_READ | unknown: 4040082700), readbytes=2048) at http_filters.c:566
#7  0x00007f28eed245d7 in dav_method_put (r=0x7f28f19b70a0) at mod_dav.c:991
#8  0x00007f28eed27a58 in dav_handler (r=0x7f28f19b70a0) at mod_dav.c:4697
#9  0x000056342356e290 in ap_run_handler (r=r@entry=0x7f28f19b70a0) at config.c:169
#10 0x000056342356e7d9 in ap_invoke_handler (r=0x7f28f19b70a0) at config.c:433
#11 0x0000563423584672 in ap_process_async_request (r=0x7f28f19b70a0) at http_request.c:317
#12 0x00005634235811e0 in ap_process_http_async_connection (c=0x7f28f19bb330) at http_core.c:143
#13 ap_process_http_connection (c=0x7f28f19bb330) at http_core.c:228
#14 0x0000563423577b00 in ap_run_process_connection (c=0x7f28f19bb330) at connection.c:41
#15 0x00007f28edcb5d3b in process_socket (my_thread_num=<optimized out>, my_child_num=<optimized out>, cs=<optimized out>, sock=<optimized out>, p=<optimized out>, thd=<optimized out>) at event.c:1029
#16 worker_thread (thd=0x7f28e6ffc900, dummy=0x1) at event.c:1865
#17 0x00007f28f0fc70a4 in start_thread (arg=0x7f28e6ffd700) at pthread_create.c:309
#18 0x00007f28f0cf504d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 3 (Thread 0x7f28e5ffb700 (LWP 885)):
#0  0x00007f28f0c443d7 in kill () at ../sysdeps/unix/syscall-template.S:81
#1  <signal handler called>
#2  0x00007f28edcb5ab2 in notify_suspend (cs=<optimized out>) at event.c:887
#3  process_socket (my_thread_num=<optimized out>, my_child_num=<optimized out>, cs=<optimized out>, sock=<optimized out>, p=<optimized out>, thd=<optimized out>) at event.c:1118
#4  worker_thread (thd=0x7f28f1a6a7e0, dummy=0x0) at event.c:1865
#5  0x00007f28f0fc70a4 in start_thread (arg=0x7f28e5ffb700) at pthread_create.c:309
#6  0x00007f28f0cf504d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 2 (Thread 0x7f28e57fa700 (LWP 886)):
#0  0x00007f28f0cf5623 in epoll_wait () at ../sysdeps/unix/syscall-template.S:81
#1  0x00007f28f1201fc3 in ?? () from /usr/lib/x86_64-linux-gnu/libapr-1.so.0
#2  0x00007f28edcb642c in listener_thread (thd=0x9, dummy=0x186a0) at event.c:1512
#3  0x00007f28f0fc70a4 in start_thread (arg=0x7f28e57fa700) at pthread_create.c:309
#4  0x00007f28f0cf504d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 1 (Thread 0x7f28f1aca780 (LWP 878)):
---Type <return> to continue, or q <return> to quit---
#0  0x00007f28f0fcdadd in read () at ../sysdeps/unix/syscall-template.S:81
#1  0x000056342357a9b7 in read (__nbytes=1, __buf=0x7ffef51cfd83, __fd=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/unistd.h:44
#2  ap_mpm_podx_check (pod=<optimized out>) at mpm_unix.c:535
#3  0x00007f28edcb3524 in child_main (child_num_arg=0) at event.c:2262
#4  0x00007f28edcb7cbd in make_child (s=0x7f28f1a9ede0, slot=0) at event.c:2349
#5  0x00007f28edcb7d45 in startup_children (number_to_start=1) at event.c:2375
#6  0x00007f28edcb877e in event_run (_pconf=0x5, plog=0x7f28f1a9a028, s=0x7f28f1a9ede0) at event.c:2715
#7  0x0000563423553e7e in ap_run_mpm (pconf=0x7f28f1ac6028, plog=0x7f28f1a9a028, s=0x7f28f1a9ede0) at mpm_common.c:94
#8  0x000056342354d3c3 in main (argc=3, argv=0x7ffef51d01b8) at main.c:777
Comment 3 Yann Ylavic 2015-08-31 10:23:48 UTC
It seems that Debian Jessie does not include these fixes to MPM event: r1642858, r1645936, r1651656 and r1664365.

The trace from Thread 3 suggests that it may be using an invalid connection state, which was addressed by the commits above.

Can you still reproduce with these patches applied?
Comment 4 Matthias Nagel 2015-08-31 10:50:54 UTC
Give me some time. In order to test this I guess I need to install vanilla Apache and compile it from source. Then I first have to find out how to do it. I will come back to this, but do not expect an answer before tomorrow.
Comment 5 Christophe JAILLET 2019-06-14 18:08:15 UTC
Closing.

4 years old without any feedback.