httpd-bugs mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From bugzi...@apache.org
Subject DO NOT REPLY [Bug 18719] New: - TCP_NOPUSH dependency causes requests to fail
Date Fri, 04 Apr 2003 17:59:59 GMT
DO NOT REPLY TO THIS EMAIL, BUT PLEASE POST YOUR BUG 
RELATED COMMENTS THROUGH THE WEB INTERFACE AVAILABLE AT
<http://nagoya.apache.org/bugzilla/show_bug.cgi?id=18719>.
ANY REPLY MADE TO THIS MESSAGE WILL NOT BE COLLECTED AND 
INSERTED IN THE BUG DATABASE.

http://nagoya.apache.org/bugzilla/show_bug.cgi?id=18719

TCP_NOPUSH dependency causes requests to fail

           Summary: TCP_NOPUSH dependency causes requests to fail
           Product: Apache httpd-2.0
           Version: 2.0.45
          Platform: All
        OS/Version: Linux
            Status: NEW
          Severity: Major
          Priority: Other
         Component: Core
        AssignedTo: bugs@httpd.apache.org
        ReportedBy: edelkind-apache-dev@episec.com


Below is a full train-of-debugging log of my research into this problem.  At
the end of this log is my conclusion, with recommendations and a workaround.
I have not submitted a patch because there are multiple methods of
correction, and the decision of which to implement may be debatable.

---------------------------------------------------------------

Indications:

  - when requesting many static files, the server does not output any data.

  - many png and jpg icons fall prey to this, in addition to many html files
    and random data, though it seems the stock gif icons do not.  I have not
    researched this further.

  - httpd aborts the connection with no output (not even headers).

  - informational messages in logs (log level INFO):
    [Tue Apr 01 11:34:43 2003] [info] (70023)This function has not been
implemented on this platform: core_output_filter: writing data to the network

	

Investigation:

  - core.c (4029): ap_log_error().

**** backtrace ****
Breakpoint 1, 0x40176509 in apr_strerror ()
   from /usr/pkg/apache/lib/libapr-0.so.0
(gdb) bt
#0  0x40176509 in apr_strerror () from /usr/pkg/apache/lib/libapr-0.so.0
#1  0x808f65a in log_error_core (file=0x80be6ca "core.c", line=4029, level=6,
    status=70023, s=0x8152828, r=0x0, pool=0x0,
    fmt=0x80c0be0 "core_output_filter: writing data to the network",
    args=0xbfffec28) at log.c:519
#2  0x808f86c in ap_log_error (file=0x80be6ca "core.c", line=4029, level=6,
    status=70023, s=0x8152828,
    fmt=0x80c0be0 "core_output_filter: writing data to the network")
    at log.c:561
#3  0x80a5847 in core_output_filter (f=0x815a230, b=0x81665f0) at core.c:4029
#4  0x809ac57 in ap_pass_brigade (next=0x815a230, bb=0x815f9c0)
    at util_filter.c:540
#5  0x80730a2 in ap_http_header_filter (f=0x815ecc8, b=0x815f9c0)
    at http_protocol.c:1716
#6  0x809ac57 in ap_pass_brigade (next=0x815ecc8, bb=0x815f9c0)
    at util_filter.c:540 
#7  0x809dd17 in ap_content_length_filter (f=0x815ecb0, b=0x815f9c0)
    at protocol.c:1299
#8  0x809ac57 in ap_pass_brigade (next=0x815ecb0, bb=0x815f9c0)
    at util_filter.c:540
#9  0x8074c7e in ap_byterange_filter (f=0x815ec98, bb=0x815f9c0)
    at http_protocol.c:2881
#10 0x809ac57 in ap_pass_brigade (next=0x815ec98, bb=0x815f9c0)
    at util_filter.c:540
---Type <return> to continue, or q <return> to quit---
#11 0x80a422c in default_handler (r=0x815e058) at core.c:3384
#12 0x808b2c1 in ap_run_handler (r=0x815e058) at config.c:194
#13 0x808bb0e in ap_invoke_handler (r=0x815e058) at config.c:401
#14 0x8075adc in ap_process_request (r=0x815e058) at http_request.c:288
#15 0x806fb6f in ap_process_http_connection (c=0x8159ee0) at http_core.c:293
#16 0x8098151 in ap_run_process_connection (c=0x8159ee0) at connection.c:85
#17 0x8098540 in ap_process_connection (c=0x8159ee0, csd=0x8159e18)
    at connection.c:207
#18 0x8089a67 in child_main (child_num_arg=2) at prefork.c:696
#19 0x8089c09 in make_child (s=0x80d1f48, slot=2) at prefork.c:790
#20 0x8089c84 in startup_children (number_to_start=3) at prefork.c:808
#21 0x808a0b6 in ap_mpm_run (_pconf=0x80cf840, plog=0x8107920, s=0x80d1f48)
    at prefork.c:1024
#22 0x8091183 in main (argc=3, argv=0xbffff2c4) at main.c:651
#23 0x4021a543 in __libc_start_main () from /lib/libc.so.6


**** relevant code (core.c:4029) ****
        if (rv != APR_SUCCESS) {
            ap_log_error(APLOG_MARK, APLOG_INFO, rv, c->base_server,
                         "core_output_filter: writing data to the network");


**** last definition of rv ****
                rv = sendfile_it_all(net,      /* the network information   */
                                     fd,       /* the file to send          */
                                     &hdtr,    /* header and trailer iovecs */
                                     foffset,  /* offset in the file to begin
                                                  sending from              */
                                     flen,     /* length of file            */
                                     nbytes + flen, /* total length including
                                                       headers              */
                                     &bytes_sent,   /* how many bytes were
                                                       sent                 */
                                     flags);   /* apr_sendfile flags        */



*** debugging ***

--- in core.c/sendfile_it_all() ---
(gdb) print file_bytes_left
$3 = 484
(gdb) step
2760            rv = apr_sendfile(c->client_socket, fd, hdtr, &file_offset,
&tmplen,
(gdb) step
2762            *bytes_sent += tmplen;
(gdb) print rv
$4 = 70023

--------------------
./srclib/apr/include/apr_errno.h:#define APR_ENOTIMPL       (APR_OS_START_STATUS
+ 23)
./srclib/apr/include/apr_errno.h:#define APR_OS_START_STATUS   
(APR_OS_START_ERROR + APR_OS_ERRSPACE_SIZE)
./srclib/apr/include/apr_errno.h:#define APR_OS_START_ERROR     20000
./srclib/apr/include/apr_errno.h:#define APR_OS_ERRSPACE_SIZE 50000

APR_ENOTIMPL == 70023
---------------------

... after stepping through debugging data ...

./srclib/apr/network_io/unix/sockopt.c/apr_socket_opt_set()
	returns APR_ENOTIMPL

(gdb) step
157             one = 1;
(gdb)  
160         if (opt & APR_SO_KEEPALIVE) {
(gdb) 
172         if (opt & APR_SO_DEBUG) {
(gdb) 
180         if (opt & APR_SO_REUSEADDR) {
(gdb) 
188         if (opt & APR_SO_SNDBUF) {
(gdb) 
200         if (opt & APR_SO_NONBLOCK) {
(gdb) 
213         if (opt & APR_SO_LINGER) {
(gdb) 
228         if (opt & APR_SO_TIMEOUT) { 
(gdb) 
232         if (opt & APR_TCP_NODELAY) {
(gdb) 
262         if (opt & APR_TCP_NOPUSH) {
(gdb) 
307             return APR_ENOTIMPL;
(gdb) bt
#0  apr_socket_opt_set (sock=0x815a338, opt=1024, on=1) at sockopt.c:307
#1  0x4017bbb9 in apr_socket_sendfile (sock=0x815a338, file=0x815fdb0, 
    hdtr=0xbfffec3c, offset=0xbfffec1c, len=0xbfffec00, flags=0)
    at sendrecv.c:299
#2  0x4017c036 in apr_sendfile (sock=0x815a338, file=0x815fdb0, 
    hdtr=0xbfffec3c, offset=0xbfffec1c, len=0xbfffec00, flags=1)
    at sendrecv.c:1052
#3  0x80a3658 in sendfile_it_all (c=0x815a728, fd=0x815fdb0, hdtr=0xbfffec3c, 
    file_offset=0, file_bytes_left=484, total_bytes_left=737, 
    bytes_sent=0xbfffec4c, flags=1) at core.c:2760
#4  0x80a5699 in core_output_filter (f=0x815a750, b=0x8166580) at core.c:3964
#5  0x809ac57 in ap_pass_brigade (next=0x815a750, bb=0x815fec8)
    at util_filter.c:540
#6  0x80730a2 in ap_http_header_filter (f=0x815f1d0, b=0x815fec8)
    at http_protocol.c:1716
#7  0x809ac57 in ap_pass_brigade (next=0x815f1d0, bb=0x815fec8)
    at util_filter.c:540
#8  0x809dd17 in ap_content_length_filter (f=0x815f1b8, b=0x815fec8)
    at protocol.c:1299
#9  0x809ac57 in ap_pass_brigade (next=0x815f1b8, bb=0x815fec8)
    at util_filter.c:540
#10 0x8074c7e in ap_byterange_filter (f=0x815f1a0, bb=0x815fec8)
    at http_protocol.c:2881
#11 0x809ac57 in ap_pass_brigade (next=0x815f1a0, bb=0x815fec8)
    at util_filter.c:540
#12 0x80a422c in default_handler (r=0x815e560) at core.c:3384
#13 0x808b2c1 in ap_run_handler (r=0x815e560) at config.c:194
#14 0x808bb0e in ap_invoke_handler (r=0x815e560) at config.c:401
#15 0x8075adc in ap_process_request (r=0x815e560) at http_request.c:288
#16 0x806fb6f in ap_process_http_connection (c=0x815a400) at http_core.c:293
#17 0x8098151 in ap_run_process_connection (c=0x815a400) at connection.c:85
#18 0x8098540 in ap_process_connection (c=0x815a400, csd=0x815a338)
    at connection.c:207
#19 0x8089a67 in child_main (child_num_arg=1) at prefork.c:696
#20 0x8089c09 in make_child (s=0x80d1f48, slot=1) at prefork.c:790
#21 0x8089c84 in startup_children (number_to_start=4) at prefork.c:808
#22 0x808a0b6 in ap_mpm_run (_pconf=0x80cf840, plog=0x8107920, s=0x80d1f48)
    at prefork.c:1024
#23 0x8091183 in main (argc=3, argv=0xbffff2c4) at main.c:651
#24 0x40227543 in __libc_start_main () from /lib/libc.so.6

---------------
APR_TCP_NOPUSH == 1024
APR_TCP_NODELAY == 512
APR_INCOMPLETE_READ == 4096
---------------

APR_TCP_NODELAY is set upon connection

Problematic files set APR_TCP_NOPUSH and exit before output
Acceptable files set APR_INCOMPLETE_READ after complete output

*** acceptable files ***
(gdb) bt
#0  apr_socket_opt_set (sock=0x815a338, opt=4096, on=1) at sockopt.c:156
#1  0x8098474 in ap_lingering_close (c=0x815a400) at connection.c:183
#2  0x8089a76 in child_main (child_num_arg=1) at prefork.c:697
#3  0x8089c09 in make_child (s=0x80d1f48, slot=1) at prefork.c:790
#4  0x8089c84 in startup_children (number_to_start=4) at prefork.c:808
#5  0x808a0b6 in ap_mpm_run (_pconf=0x80cf840, plog=0x8107920, s=0x80d1f48)
    at prefork.c:1024
#6  0x8091183 in main (argc=3, argv=0xbffff2c4) at main.c:651
#7  0x40227543 in __libc_start_main () from /lib/libc.so.6
(gdb) 


-----------
  - Acceptable files do not call sendfile_it_all() from
    core_output_filter().
  - Use the --without-sendfile option as a workaround for this problem
    (emulate_sendfile() will be called instead).

  - APR_TCP_NOPUSH_FLAG == 0 in this configuration
  - APR_TCP_NOPUSH_FLAG == TCP_CORK on a working linux system
  - APR_TCP_NOPUSH_FLAG == TCP_NOPUSH on a working freebsd system



Conclusion:

  Just because sendfile() exists on the system doesn't necessarily mean that
  a TCP_NOPUSH variant will be available (or detected).  Ways to alleviate
  this problem include:

	- better checking for TCP_CORK (the tested system _does_ support it,
	  but the apr configure checks for TCP_CORK in netinet/tcp.h,
	  whereas it was only in linux/tcp.h, due to old libc header files)
	- make TCP_NOPUSH functionality dependent on APR_TCP_NOPUSH_FLAG
	  (and just live with any extra packets that are generated)
	- make the use of sendfile(2) dependent on APR_TCP_NOPUSH_FLAG
	  (i.e. #if APR_HAS_SENDFILE && APR_TCP_NOPUSH_FLAG), in which case
	  emulate_sendfile() will be used in its stead.

  Workaround: configure apache with the --without-sendfile option.

---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


Mime
View raw message