Project

General

Profile

Bug #756

transfer-encoding chunked broken (OSX)

Added by Anonymous over 12 years ago. Updated about 3 years ago.

Status:
Fixed
Priority:
Normal
Assignee:
-
Category:
mod_cgi
Target version:
Start date:
Due date:
% Done:

0%

Estimated time:
Missing in 1.5.x:

Description

Config: OSX/freebsd-kqueue/CGI/setenv

Test script:


#!/usr/bin/perl

print "Content-Type: text/plain\r\n\r\n";

for $key (keys %ENV) {
        print "$key = $ENV{$key}\n";
}

This is a piece of tcpdump -X -s 1500:


14:46:51.965153 IP localhost.49704 > localhost.8081: P 1:249(248) ack 1 win 65535 <nop,nop,timestamp 605649161 605649161>
        0x0000:  4500 012c c15d 4000 4006 0000 7f00 0001  E..,.]@.@.......
        0x0010:  7f00 0001 c228 1f91 9b8d c590 0de0 d5b0  .....(..........
        0x0020:  8018 ffff ff20 0000 0101 080a 2419 7909  ............$.y.
        0x0030:  2419 7909 4745 5420 2f74 6573 742e 706c  $.y.GET./test.pl
        0x0040:  2048 5454 502f 312e 310d 0a41 6363 6570  .HTTP/1.1..Accep
        0x0050:  743a 202a 2f2a 0d0a 4163 6365 7074 2d4c  t:.*/*..Accept-L
        0x0060:  616e 6775 6167 653a 2065 6e0d 0a41 6363  anguage:.en..Acc
        0x0070:  6570 742d 456e 636f 6469 6e67 3a20 677a  ept-Encoding:.gz
        0x0080:  6970 2c20 6465 666c 6174 650d 0a55 7365  ip,.deflate..Use
        0x0090:  722d 4167 656e 743a 204d 6f7a 696c 6c61  r-Agent:.Mozilla
        0x00a0:  2f35 2e30 2028 4d61 6369 6e74 6f73 683b  /5.0.(Macintosh;
        0x00b0:  2055 3b20 496e 7465 6c20 4d61 6320 4f53  .U;.Intel.Mac.OS
        0x00c0:  2058 3b20 656e 2920 4170 706c 6557 6562  .X;.en).AppleWeb
        0x00d0:  4b69 742f 3431 382e 3820 284b 4854 4d4c  Kit/418.8.(KHTML
        0x00e0:  2c20 6c69 6b65 2047 6563 6b6f 2920 5361  ,.like.Gecko).Sa
        0x00f0:  6661 7269 2f34 3139 2e33 0d0a 436f 6e6e  fari/419.3..Conn
        0x0100:  6563 7469 6f6e 3a20 6b65 6570 2d61 6c69  ection:.keep-ali
        0x0110:  7665 0d0a 486f 7374 3a20 6c6f 6361 6c68  ve..Host:.localh
        0x0120:  6f73 743a 3830 3831 0d0a 0d0a            ost:8081....
14:46:51.965185 IP localhost.8081 > localhost.49704: . ack 249 win 65535 <nop,nop,timestamp 605649161 605649161>
        0x0000:  4500 0034 c15e 4000 4006 0000 7f00 0001  E..4.^@.@.......
        0x0010:  7f00 0001 1f91 c228 0de0 d5b0 9b8d c688  .......(........
        0x0020:  8010 ffff fe28 0000 0101 080a 2419 7909  .....(......$.y.
        0x0030:  2419 7909                                $.y.
14:46:51.971822 IP localhost.8081 > localhost.49704: P 1:864(863) ack 249 win 65535 <nop,nop,timestamp 605649161 605649161>
        0x0000:  4500 0393 c15f 4000 4006 0000 7f00 0001  E...._@.@.......
        0x0010:  7f00 0001 1f91 c228 0de0 d5b0 9b8d c688  .......(........
        0x0020:  8018 ffff 0188 0000 0101 080a 2419 7909  ............$.y.
        0x0030:  2419 7909 4854 5450 2f31 2e31 2032 3030  $.y.HTTP/1.1.200
        0x0040:  204f 4b0d 0a54 7261 6e73 6665 722d 456e  .OK..Transfer-En
        0x0050:  636f 6469 6e67 3a20 6368 756e 6b65 640d  coding:.chunked.
        0x0060:  0a43 6f6e 7465 6e74 2d54 7970 653a 2074  .Content-Type:.t
        0x0070:  6578 742f 706c 6169 6e0d 0a44 6174 653a  ext/plain..Date:
        0x0080:  204d 6f6e 2c20 3137 204a 756c 2032 3030  .Mon,.17.Jul.200
        0x0090:  3620 3132 3a34 363a 3531 2047 4d54 0d0a  6.12:46:51.GMT..
        0x00a0:  5365 7276 6572 3a20 6c69 6768 7474 7064  Server:.lighttpd
        0x00b0:  0d0a 0d0a 3264 380d 0a53 4352 4950 545f  ....2d8..SCRIPT_
        0x00c0:  4e41 4d45 203d 202f 7465 7374 2e70 6c0a  NAME.=./test.pl.
        0x00d0:  5345 5256 4552 5f4e 414d 4520 3d20 6c6f  SERVER_NAME.=.lo
        0x00e0:  6361 6c68 6f73 743a 3830 3831 0a48 5454  calhost:8081.HTT
        0x00f0:  505f 4143 4345 5054 5f45 4e43 4f44 494e  P_ACCEPT_ENCODIN
        0x0100:  4720 3d20 677a 6970 2c20 6465 666c 6174  G.=.gzip,.deflat
        0x0110:  650a 4854 5450 5f43 4f4e 4e45 4354 494f  e.HTTP_CONNECTIO
        0x0120:  4e20 3d20 6b65 6570 2d61 6c69 7665 0a48  N.=.keep-alive.H
        0x0130:  5454 505f 4143 4345 5054 203d 202a 2f2a  TTP_ACCEPT.=.*/*
        0x0140:  0a43 4f4e 5445 4e54 5f4c 454e 4754 4820  .CONTENT_LENGTH.
        0x0150:  3d20 300a 5245 5155 4553 545f 4d45 5448  =.0.REQUEST_METH
        0x0160:  4f44 203d 2047 4554 0a53 4352 4950 545f  OD.=.GET.SCRIPT_
        0x0170:  4649 4c45 4e41 4d45 203d 202f 5573 6572  FILENAME.=./User
        0x0180:  732f 6a69 6d6d 792f 576f 726b 2f64 6576  s/jimmy/Work/dev
        0x0190:  626f 782d 7777 772d 6261 636b 7570 2f74  box-www-backup/t
        0x01a0:  6573 742e 706c 0a53 4552 5645 525f 534f  est.pl.SERVER_SO
        0x01b0:  4654 5741 5245 203d 206c 6967 6874 7470  FTWARE.=.lighttp
        0x01c0:  642f 312e 342e 3131 0a48 5454 505f 5553  d/1.4.11.HTTP_US
        0x01d0:  4552 5f41 4745 4e54 203d 204d 6f7a 696c  ER_AGENT.=.Mozil
        0x01e0:  6c61 2f35 2e30 2028 4d61 6369 6e74 6f73  la/5.0.(Macintos
        0x01f0:  683b 2055 3b20 496e 7465 6c20 4d61 6320  h;.U;.Intel.Mac.
        0x0200:  4f53 2058 3b20 656e 2920 4170 706c 6557  OS.X;.en).AppleW
        0x0210:  6562 4b69 742f 3431 382e 3820 284b 4854  ebKit/418.8.(KHT
        0x0220:  4d4c 2c20 6c69 6b65 2047 6563 6b6f 2920  ML,.like.Gecko).
        0x0230:  5361 6661 7269 2f34 3139 2e33 0a52 454d  Safari/419.3.REM
        0x0240:  4f54 455f 504f 5254 203d 2034 3937 3034  OTE_PORT.=.49704
        0x0250:  0a53 4552 5645 525f 504f 5254 203d 2038  .SERVER_PORT.=.8
        0x0260:  3038 310a 5245 4449 5245 4354 5f53 5441  081.REDIRECT_STA
        0x0270:  5455 5320 3d20 3230 300a 4854 5450 5f41  TUS.=.200.HTTP_A
        0x0280:  4343 4550 545f 4c41 4e47 5541 4745 203d  CCEPT_LANGUAGE.=
        0x0290:  2065 6e0a 5245 4d4f 5445 5f41 4444 5220  .en.REMOTE_ADDR.
        0x02a0:  3d20 3132 372e 302e 302e 310a 5345 5256  =.127.0.0.1.SERV
        0x02b0:  4552 5f50 524f 544f 434f 4c20 3d20 4854  ER_PROTOCOL.=.HT
        0x02c0:  5450 2f31 2e31 0a47 4154 4557 4159 5f49  TP/1.1.GATEWAY_I
        0x02d0:  4e54 4552 4641 4345 203d 2043 4749 2f31  NTERFACE.=.CGI/1
        0x02e0:  2e31 0a52 4551 5545 5354 5f55 5249 203d  .1.REQUEST_URI.=
        0x02f0:  202f 7465 7374 2e70 6c0a 5345 5256 4552  ./test.pl.SERVER
        0x0300:  5f41 4444 5220 3d20 3132 372e 302e 302e  _ADDR.=.127.0.0.
        0x0310:  310a 444f 4355 4d45 4e54 5f52 4f4f 5420  1.DOCUMENT_ROOT.
        0x0320:  3d20 2f55 7365 7273 2f6a 696d 6d79 2f57  =./Users/jimmy/W
        0x0330:  6f72 6b2f 6465 7662 6f78 2d77 7777 2d62  ork/devbox-www-b
        0x0340:  6163 6b75 700a 5045 524c 4c49 4220 3d20  ackup.PERLLIB.=.
        0x0350:  2f55 7365 7273 2f6a 696d 6d79 2f55 4e49  /Users/jimmy/UNI
        0x0360:  582f 6c69 622f 7065 726c 352f 7369 7465  X/lib/perl5/site
        0x0370:  5f70 6572 6c0a 4854 5450 5f48 4f53 5420  _perl.HTTP_HOST.
        0x0380:  3d20 6c6f 6361 6c68 6f73 743a 3830 3831  =.localhost:8081
        0x0390:  0a0d 0a                                  ...
14:46:51.971852 IP localhost.49704 > localhost.8081: . ack 864 win 65535 <nop,nop,timestamp 605649161 605649161>
        0x0000:  4500 0034 c160 4000 4006 0000 7f00 0001  E..4.`@.@.......
        0x0010:  7f00 0001 c228 1f91 9b8d c688 0de0 d90f  .....(..........
        0x0020:  8010 ffff fe28 0000 0101 080a 2419 7909  .....(......$.y.
        0x0030:  2419 7909                                $.y.


Related issues

Related to Bug #2542: Race leads to incorrect output in some circumstancesFixed2013-12-26

Actions

History

#1

Updated by Anonymous over 12 years ago

The problem persists after several restarts and config changes.
My config:


# lighttpd configuration file
#

## modules to load
# at least mod_access and mod_accesslog should be loaded
server.modules = (
#       "mod_rewrite",
#       "mod_redirect",
#       "mod_alias",
        "mod_access",
#       "mod_cml",
#       "mod_trigger_b4_dl",
#       "mod_auth",
#       "mod_status",
        "mod_setenv",
#       "mod_fastcgi",
#       "mod_proxy",
#       "mod_simple_vhost",
#       "mod_evhost",
#       "mod_userdir",
        "mod_cgi",
#       "mod_compress",
#       "mod_ssi",
#       "mod_usertrack",
#       "mod_expire",
#       "mod_secdownload",
#       "mod_rrdtool",
        "mod_accesslog" )

server.tag              = "lighttpd" 
server.port             = 8081
server.bind             = "localhost" 

server.document-root    = "/Users/jimmy/Work/devbox-www-backup" 
server.pid-file         = "/Users/jimmy/UNIX/var/run/lighttpd.pid" 
server.errorlog         = "/Users/jimmy/UNIX/var/log/lighttpd.error.log" 
accesslog.filename      = "/Users/jimmy/UNIX/var/log/lighttpd.access.log" 

server.event-handler    = "freebsd-kqueue" 

index-file.names        = ( "index.pl", "index.cgi",
                            "index.html", "index.htm" )

url.access-deny         = ( "~", ".pm" )
static-file.exclude-extensions  = ( ".pl", ".cgi" )

cgi.assign              = ( ".pl"  => "",
                            ".cgi" => "" )

setenv.add-environment  = (
        "PERLLIB" => "/Users/jimmy/UNIX/lib/perl5/site_perl" 
)

#dir-listing.activate   = "enable" 

mimetype.assign = (
        ".pdf"          =>      "application/pdf",
        ".sig"          =>      "application/pgp-signature",
        ".spl"          =>      "application/futuresplash",
        ".class"        =>      "application/octet-stream",
        ".ps"           =>      "application/postscript",
        ".torrent"      =>      "application/x-bittorrent",
        ".dvi"          =>      "application/x-dvi",
        ".gz"           =>      "application/x-gzip",
        ".pac"          =>      "application/x-ns-proxy-autoconfig",
        ".swf"          =>      "application/x-shockwave-flash",
        ".tar.gz"       =>      "application/x-tgz",
        ".tgz"          =>      "application/x-tgz",
        ".tar"          =>      "application/x-tar",
        ".zip"          =>      "application/zip",
        ".mp3"          =>      "audio/mpeg",
        ".m3u"          =>      "audio/x-mpegurl",
        ".wma"          =>      "audio/x-ms-wma",
        ".wax"          =>      "audio/x-ms-wax",
        ".ogg"          =>      "application/ogg",
        ".wav"          =>      "audio/x-wav",
        ".gif"          =>      "image/gif",
        ".jpg"          =>      "image/jpeg",
        ".jpeg"         =>      "image/jpeg",
        ".png"          =>      "image/png",
        ".xbm"          =>      "image/x-xbitmap",
        ".xpm"          =>      "image/x-xpixmap",
        ".xwd"          =>      "image/x-xwindowdump",
        ".css"          =>      "text/css",
        ".html"         =>      "text/html",
        ".htm"          =>      "text/html",
        ".js"           =>      "text/javascript",
        ".asc"          =>      "text/plain",
        ".c"            =>      "text/plain",
        ".cpp"          =>      "text/plain",
        ".log"          =>      "text/plain",
        ".conf"         =>      "text/plain",
        ".text"         =>      "text/plain",
        ".txt"          =>      "text/plain",
        ".dtd"          =>      "text/xml",
        ".xml"          =>      "text/xml",
        ".mpeg"         =>      "video/mpeg",
        ".mpg"          =>      "video/mpeg",
        ".mov"          =>      "video/quicktime",
        ".qt"           =>      "video/quicktime",
        ".avi"          =>      "video/x-msvideo",
        ".asf"          =>      "video/x-ms-asf",
        ".asx"          =>      "video/x-ms-asf",
        ".wmv"          =>      "video/x-ms-wmv",
        ".bz2"          =>      "application/x-bzip",
        ".tbz"          =>      "application/x-bzip-compressed-tar",
        ".tar.bz2"      =>      "application/x-bzip-compressed-tar" 
)

-- jimmy

#2

Updated by Anonymous over 12 years ago

after a few minutes, i also get this in the log:


2006-07-17 15:29:12: (server.c.1126) NOTE: a request for /test.pl timed out after writing 863 bytes. We waited 360 seconds. If this a problem increase server.max-write-idle 

-- jimmy

#3

Updated by Anonymous over 12 years ago

I tried the version from DarwinPorts also without success, other event handlers, even compiled an older C compiler without success. I'm trying to find out why it stays in CON_STATE_WRITE .. if I use a very simple request using telnet and waiting a few seconds before I finish the headers, it sometimes works, but that makes no sense at all, but it should be related to the at least one other issue i reported using lighttpd on OSX.

-- jimmy

#4

Updated by Anonymous over 12 years ago

I came to the point that HTTP/1.0 events also hang and not finish.

The times it works, is with concurrent tests imho, because it seems that, WHEN it works, there is an EAGAIN after reading all bytes, an FDEVENT_IN afterwards, and then 0 bytes are read.

When it doesn't work, there is no FDEVENT_IN after reading ALL bytes returned by the CGI.

If I disable the piece of code to close stdout, and put any printf statement in fdevent_select_event_get_revent(), it works (i'm testing now with the select handler instead of freebsd-kqueue). But this is not a solution, and know it's getting to complicated for me.

-- jimmy

#5

Updated by Anonymous over 12 years ago

now i'm to the point, that adding any printf() statement to the main polling loop in server.c "fixes" the problem, BUT I also found that removing the fcntl call in mod_cgi.c also fixes the issue, so it has got something to do with it!

I really could use some help over here, but I have a feeling that sometimes (most of the time), using any event handler, an event isn't detected when the cgi dies (SIGPIPE related?!). If you have any clues, or short C program just to test the fcntl/o_nonblock/sigpipe behaviour like it happens here, it would be really appreciated, because my C is quite poor and solving this issue is taking a LOT of time from me, but i will continue trying...

-- jimmy

#6

Updated by Anonymous over 12 years ago

I could not reproduce the problem with a small C program, but I am on a completely wrong track there. I was looking for a bug in OSX's handling of events, while the problem seems to be somewhere else, it seems that the printf() statement previously mentioned, somehow resulted that read() from the CGI's filedescriptor, not returing EAGAIN, while otherwise it would after the first read (with my test CGI). If EAGAIN happens, the problem occurs (always?), otherwise it doesn't (duh). BUT, it seems that somehow, the CGI's filedescriptor is gone from the fd_set being polled...

-- jimmy

#7

Updated by Anonymous over 12 years ago

Now it's very clear, if EAGAIN happens while reading from the CGI's fd (which does never happen on my OpenBSD test machine), the file descriptor is still removed from the fd_set, and thus, there will never be polled for an event on it again.

-- jimmy

#8

Updated by Anonymous over 12 years ago

it get closed in SUBREQUEST_FUNC(mod_cgi_handle_subrequest), because of :


if (!con->file_started) return HANDLER_WAIT_FOR_EVENT;

this will remove the event and close the fd because the response started, and thus the return is skipped, and the code below removes it from the event list, and closes the cgi's fd because it thinks it exited after sending all data, but this does not imply that the response to the client was finished, because read() still has to return 0 before the request is marked as handled!

if this is put right below it, the problem is fixed:


if (!con->file_finished) return HANDLER_FINISHED;

I am not sure, if the file_started line still has to be there or not as i do not fully understand the internals yet, and I'm also not sure that everything in that block based on file_started is correctly assumed! (also do not slap me if HANDLER_FINISHED is not the approprate return response, but this is the one that makes it work here)

-- jimmy

#9

Updated by stbuehler about 3 years ago

  • Related to Bug #2542: Race leads to incorrect output in some circumstances added
#11

Updated by stbuehler about 3 years ago

  • Description updated (diff)
  • Category changed from core to mod_cgi
  • Status changed from New to Fixed
  • Assignee deleted (jan)
  • Target version set to 1.4.40

Should be fixed in r3091

Also available in: Atom