Project

General

Profile

Partial Cookies being written or read (FastCGI)

Added by eudlawil over 16 years ago

  • Issue:
    We write at least two, and sometimes three cookies to a user's browser for
    each request we get. We are running a Perl FastCGI application with ~1.5 million
    requests per day per server. We set and read the cookie with Perl's CGI methods -
    creating the cookie header string with the 'cookie' method and setting it with the
    'header' method.
    I've been tracking down problems with the cookies as read from users. Sometimes cookies
    contain parial data - othertimes they hold very odd data.

    This is a complete cookie example:
    488:2:63347047828:1:1:34:412:63347047828:1:2|

    They are 10 colon separated values followed by a pipe -
    so even if a value is undefined it would print a :: where the value should have been.

    We are seeing very odd cookie values that don't appear to be
    coming from a bug in our code such as:
    1031:
    367:1:63349336033:1:255:15:96:633493
    1123:1:63349302

    Here is a particularly odd one:
    , $Version=1

    I thought that this could be related to bug
    http://trac.lighttpd.net/trac/ticket/1628
    So I upgraded to 1.4.20, but the errors continue to happen. I can tell that they aren't
    pre-upgrade cookies by looking at the timestamp in the cookies.
    Furthermore, I simplified the code so we only set one cookie per request and find that
    the problem still exists.

  • Operating System (OS)
    openSUSE 10.3 (X86-64)
    VERSION = 10.3
  • Version of Lighttpd
    currently lighttpd/1.4.20
    but saw the same thing with lighttpd/1.4.19
  • What client you used (Browser, curl, etc.)
    I haven't been able to recreate on my own - these are user cookies I'm finding, I could track the browser but haven't done that yet... not sure if it's worth it.
  • Configuration you are using
# lighttpd configuration file
#
# use it as a base for lighttpd 1.0.0 and above
#
# $Id: lighttpd.conf,v 1.7 2004/11/03 22:26:05 weigon Exp $

############ Options you really have to take care of ####################

## modules to load
# at least mod_access and mod_accesslog should be loaded
# all other module should only be loaded if really neccesary
# - saves some time
# - saves memory
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" )

## a static document-root, for virtual-hosting take look at the
## server.virtual-* options
server.document-root        = "/srv/www/htdocs/" 

## where to send error-messages to
server.errorlog             = "/var/log/lighttpd/error.log" 

# files to check for if .../ is requested
index-file.names            = ( "index.html")

## set the event-handler (read the performance section in the manual)
# server.event-handler = "freebsd-kqueue" # needed on OS X

# mimetype mapping
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",
  # default mime type
  ""              =>      "application/octet-stream",
 )

# Use the "Content-Type" extended attribute to obtain mime type if possible
#mimetype.use-xattr        = "enable" 

## send a different Server: header
## be nice and keep it at lighttpd
# server.tag                 = "lighttpd" 

#### accesslog module
accesslog.filename          = "/var/log/lighttpd/access.log" 
accesslog.format = "%{Udm_Remote_Addr}i %V %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" 

## deny access the file-extensions
#
# ~    is for backupfiles from vi, emacs, joe, ...
# .inc is often used for code includes which should in general not be part
#      of the document-root
url.access-deny             = ( "~", ".inc" )

$HTTP["url"] =~ "\.pdf$" {
  server.range-requests = "disable" 
}

##
# which extensions should not be handle via static-file transfer
#
# .php, .pl, .fcgi are most often handled by mod_fastcgi or mod_cgi
static-file.exclude-extensions = ( ".php", ".pl", ".fcgi", ".fetch", ".cpx" )

######### Options that are good to be but not neccesary to be changed #######

## bind to port (default: 80)
server.port                = 80

## bind to localhost (default: all interfaces)
#server.bind                = "127.0.0.1" 

## error-handler for status 404
#server.error-handler-404   = "/error-handler.html" 
#server.error-handler-404   = "/error-handler.php" 

## to help the rc.scripts
server.pid-file            = "/var/run/lighttpd.pid" 

###### virtual hosts
##
##  If you want name-based virtual hosting add the next three settings and load
##  mod_simple_vhost
##
## document-root =
##   virtual-server-root + virtual-server-default-host + virtual-server-docroot
## or
##   virtual-server-root + http-host + virtual-server-docroot
##
#simple-vhost.server-root   = "/srv/www/vhosts/" 
#simple-vhost.default-host  = "www.example.org" 
#simple-vhost.document-root = "/htdocs/" 

##
## Format: <errorfile-prefix><status-code>.html
## -> ..../status-404.html for 'File not found'
#server.errorfile-prefix    = "/usr/share/lighttpd/errors/status-" 
#server.errorfile-prefix    = "/srv/www/errors/status-" 

## virtual directory listings
#dir-listing.activate       = "enable" 

## enable debugging
#debug.log-request-header   = "enable" 
#debug.log-response-header  = "enable" 
#debug.log-request-handling = "enable" 
#debug.log-file-not-found   = "enable" 

### only root can use these options
#
# chroot() to directory (default: no chroot() )
#server.chroot              = "/" 

## change uid to <uid> (default: don't care)
server.username            = "lighttpd" 

## change uid to <uid> (default: don't care)
server.groupname           = "lighttpd" 

fastcgi.debug = 0

fastcgi.server= (".fetch" =>

   ("udmfoo" =>
      (
         "socket" => "/tmp/lighttpd-fcgi.socket",
         "bin-path" => "/srv/www/cgi-bin/img.fetch",
         "max-load-per-proc" => 3,
         "min-procs" => 4,
         "max-procs" => 8,
         "idle-timeout" => 60
         )
   )
)

#### CGI module
cgi.assign                 = ( ".pl"  => "/usr/bin/perl",
                               ".cgi" => "/usr/bin/perl",
                               ".cpx" => "/usr/bin/perl")

$SERVER["socket"] == ":443" {
  ssl.engine                  = "enable" 
  ssl.pemfile                 = "/etc/cert/www_udmserve_net.pem" 
  ssl.ca-file                 = "/etc/cert/DigiCertCA.crt" 

  server.name                 = "udmserve.net" 

  server.document-root        = "/srv/www/htdocs/" 
}

                            )

#### url handling modules (rewrite, redirect, access)
#url.rewrite                = ( "^/$"             => "/server-status" )
# this line allows img.cpx calls to be pushed to the fcgi server, remove when we no longer need it
url.rewrite                = ( "^/udm/img.cpx(.*)$"  => "/udm/img.fetch$1" )

alias.url = ( "/udm/" => "/srv/www/cgi-bin/")

  • Thanks for any help you can provide. I'm not sure what else to try?!?

Replies (9)

RE: Partial Cookies being written or read (FastCGI) - Added by eudlawil over 16 years ago

One additional note:

I'm now capturing the browser agent where these messed up cookies reside - and it appears to be all Firefox at this time. Mostly version 2.0.0.17, but occasionally 1.5 and 3.0.

This appears to be a real issue... it surprises me there aren't other people seeing this.
Load isn't particularly high on our servers.

top - 10:30:53 up 6 days, 12:35,  2 users,  load average: 0.36, 0.40, 0.47
Tasks:  81 total,   1 running,  80 sleeping,   0 stopped,   0 zombie
Cpu(s):  8.1%us,  3.0%sy,  0.0%ni, 87.9%id,  1.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   4058028k total,  1709392k used,  2348636k free,   212096k buffers
Swap:  2104472k total,        0k used,  2104472k free,  1026676k cached

Any help here would be appreciated! Thanks.

RE: Partial Cookies being written or read (FastCGI) - Added by darix over 16 years ago

can you provide a simple app to illustrate the problem?

RE: Partial Cookies being written or read (FastCGI) - Added by eudlawil over 16 years ago

I'd love to... but I can't recreate the problem. It only happens occasionally. As I said we have about 1.5 million requests per server per day - and of those I only see about 40-55 of these bad cookies. Probably 70% of the traffic coming in is already cookied.
So it's a fairly rare event - and maybe I could just ignore it... but it is troubling.

We read and then re-write the cookies - and I've been careful to remove any bad cookie data so we don't re-write the bad data... but I'm not sure the rewrite takes - as the very odd cookie data containing ', $Version=1' was seem multiple times on that server - though it may have been from different end users.

I was looking for any other pieces of the puzzle that might be causing this -
I'm using perl CGI::Fast version 1.05 (latest is 1.07 - so I thought I might upgrade)
I'm using the latest perl FCGI.pm module - so no upgrade possible...
It is interesting that I haven't seen MSIE associated with this error - though they make up the majority of the traffic.

A simple overview of what the app looks like is this:

#!/usr/bin/perl -w
use strict;
use CGI::Fast qw(:standard escape);

# set some global variables for all instances
my $exit  = 0;
my $debug = 0;
my $ref;
my $dbh   = med_mod::connect();  #mysql handle

while (new CGI::Fast) {

  ## run sub routines

  read_cookie($ref);
  get_info($ref)    unless $exit;
  prep_cookie($ref) unless $exit;
  print_page($ref)  unless $exit;

  ## subroutines explanations...
  #  read_cookie {
  #    I use perl's 'cookie' method to read the cookie in
  #    I test the contents, and warn if something doesn't look right
  #  }
  #
  #  prep_cookie {
  #    I iterate through a hash that holds the cookie data - concatenating it into the correct format, and assigning it to $ref->{cookie}
  #    
  #  }
  #
  #  print_page {
  #    I create the cookie header using the 'cookie' method as follows:
  #        my $cookie = cookie(
  #                -name    => "$ref->{cook_name}",
  #                -value   => "$ref->{cookie}",
  #                -expires => '+1y',
  #                -path    => '/',
  #                -domain  => "$domain" 
  #                );
  #
  #   I unescape this cookie header b/c I'm not fond of url escaped cookies and our cookies are just numbers, :'s, and |'s
  #   
  #   we print the page using CGI's header method.
  #     print header(-p3p    => 'DSP ALL DEV PSA PSD HIS CUR ADM OUR BUS NAV COM INT UNI',
  #                  -type   => 'application/x-javascript',
  #                  -cookie => $ue_cookie,
  #                  -expires=> '-1d' ),
  #                  $content;
  #
  #  }
  #
}

I'm not sure what else to try... or how else to troubleshoot this. Thanks for your time!

RE: Partial Cookies being written or read (FastCGI) - Added by eudlawil over 16 years ago

Oh, hey... here's a curious example of bad cookie data that may provide a clue...

936:1:63346362176:1:68:68:263:63346362176:1:1|863:1:63345139426:1:68:39:234:63345139426:1:1|872:1:63347818153:2:68:62:238:63347818153:1:1|896:1:63347906423:3:68:15:252:63347906423:1:1|1065:1:63347906361:1:68:68:290:63347906361:1:1|897:1:63347906732:4set-cookie

agent: Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1)

as you can see this is a pipe separated list of cookie "slots" - and the last slot is the one with the bad data and it's value is:
897:1:63347906732:4set-cookie

Seems like the header is some how getting mangled or is not being parsed correctly... memory leak? just guessing here...

RE: Partial Cookies being written or read (FastCGI) - Added by eudlawil over 16 years ago

So... the upgrade of Perl's CGI (CGI::Fast) didn't help.

After many days of collecting data I find that MSIE never has this issue - this seems like an important clue. Almost all are Firefox.

If anyone has any idea what else I can try.... I'm kind of at a stand still here... ;)

RE: Partial Cookies being written or read (FastCGI) - Added by icy over 16 years ago

Couldn't it be a bug in Mozilla/FireFox then? Sounds to me like that is the case.

RE: Partial Cookies being written or read (FastCGI) - Added by eudlawil over 16 years ago

That is definitely a possibility - but I'm doubtful that this is the case.
It certainly is the easiest explanation in the context of this forum.

I would think that if there was a bug in the Firefox cookie setting mechanism, that given the number
of developers who interface with Firefox... I would have thought that this would be something you would
hear about. I also would have thought that it would probably not exist in the latest version of FF -
though I see this error on the following agents:

Firefox/0.10.1
Firefox/1.5.0.12
Firefox/2.0
Firefox/2.0.0.16
Firefox/2.0.0.16;MEGAUPLOAD 1
Firefox/2.0.0.17
Firefox/3.0.3

I will post on their support site - but my belief is that they will point blame to Lighttpd + FastCGI.

In effect FF and MSIE are the defacto standards out there and everyone (including Lighttpd) must endeavor work well with them.

Another interesting point is that this isn't a problem with every impression. It's happens only very very occasionally.

I can't help but think that it has something to do with the multi-process, hold info in memory, FastCGI model we are using.

I just don't have any ideas on how to track this further and am hoping someone on your team can give me some ideas.

If this were happening to you, what would you do?

Thanks!

RE: Partial Cookies being written or read (FastCGI) - Added by stbuehler over 16 years ago

You are testing many things, so it looks like you can easily reproduce the problem. So could you show us a trace of a broken connection, for example with wireshark?
Or perhaps you can verify the problem with curl -v?

So what I'd like to see is a complete request header which fails with firefox.

RE: Partial Cookies being written or read (FastCGI) - Added by eudlawil over 16 years ago

Sorry - I am not able to reproduce the problem in testing - though it still exists in production - I wish I could. It only happens approximately 1 / 50,000 served impressions. I've never been able to catch it in testing. I don't know if it's a failure in sending the cookie header or reading the cookie header. Perhaps the cookie is actually being set appropriately... but only a partial header is being read. I can only guess it has something to do with FastCGI - memory issues - and/or load. I would be surprised if I'm the only person seeing this... I understand that this doesn't give you much to work with. I really don't know how to further troubleshoot this issue. Perhaps tuning the servers would help. I am planning on playing around with the max-load-per-proc and seeing how that may or may not affect this issue.

It takes a while to test any changes though...

Thanks - any advice is apprecaited.

    (1-9/9)