Project

General

Profile

[UserError] Issues after migrating from lighttpd 1.45 to 1.50

Added by cfsmp3 over 5 years ago

Unsure 100% if this a bug or whether something has changed. The configuration file is identical, except that the one for 1.4.50 now includes mod_openssl has instructed by the warning that appears if it's not added. Anyway it's unrelated, just mentioning it not to leave important details behind.

I just upgraded from lighttpd 1.4.45 to 1.4.50. One of the URLs that used to work fine (well, nothing special about it, but it's this specific file) looks like this:

https://.../userpanel/index.php/js

(which is a Code Igniter application and "js" would be a view delivery by index.php).

Always worked fine, nothing special about it.

In 1.4.45 the request log looks like this:

2018-09-12 07:02:55: (response.c.562) -- logical -> physical
2018-09-12 07:02:55: (response.c.563) Doc-Root     : /var/www/dummy/
2018-09-12 07:02:55: (response.c.564) Basedir      : /var/www/dummy/
2018-09-12 07:02:55: (response.c.565) Rel-Path     : /userpanel/index.php/js
2018-09-12 07:02:55: (response.c.566) Path         :
/var/www/user2/userpanel/index.php/js
2018-09-12 07:02:55: (response.c.583) -- handling physical path
2018-09-12 07:02:55: (response.c.584) Path         :
/var/www/user2/userpanel/index.php/js
2018-09-12 07:02:55: (response.c.745) -- after pathinfo check
2018-09-12 07:02:55: (response.c.746) Path         :
/var/www/user2/userpanel/index.php
2018-09-12 07:02:55: (response.c.747) URI          : /userpanel/index.php
2018-09-12 07:02:55: (response.c.748) Pathinfo     : /js
2018-09-12 07:02:55: (response.c.753) -- handling subrequest
2018-09-12 07:02:55: (response.c.754) Path         :
/var/www/user2/userpanel/index.php
2018-09-12 07:02:55: (mod_access.c.148) -- mod_access_uri_handler called
2018-09-12 07:02:55: (mod_fastcgi.c.3500) handling it in mod_fastcgi

In 1.4.50 however
2018-09-12 05:01:37: (response.c.655) -- logical -> physical
2018-09-12 05:01:37: (response.c.656) Doc-Root     : /var/www/dummy/
2018-09-12 05:01:37: (response.c.657) Basedir      : /var/www/dummy/
2018-09-12 05:01:37: (response.c.658) Rel-Path     : /userpanel/index.php/js
2018-09-12 05:01:37: (response.c.659) Path         :
/var/www/user13/userpanel/index.php/js
2018-09-12 05:01:37: (response.c.671) -- handling physical path
2018-09-12 05:01:37: (response.c.672) Path         :
/var/www/user13/userpanel/index.php/js
2018-09-12 05:01:37: (response.c.198) file not found:
/userpanel/index.php/js -> /var/www/user13/userpanel/index.php/js


I've been looking at response.c and I see that part of code has been reorganized so maybe a bug was introduced here.

Also, it doesn't seem to happen every time. Or to be specific, sometimes I restart lighttpd and it works for a while (hours), then starts failing. However, just restarting lighttpd is not enough to get it working again. It might be needed several times. Or maybe something else is going on and this is just a coincidence.

The config file by the way is really small already - nothing really complex going on, and the issue seems to be in that "pathinfo" block which has been moved around.


Replies (10)

RE: Issues after migrating from lighttpd 1.45 to 1.50 - Added by gstrauss over 5 years ago

The config file by the way is really small already - nothing really complex going on, and the issue seems to be in that "pathinfo" block which has been moved around.

Well, you emailed me directly to bother me and I not so subtly told you to post your question to the forums along with your config, and you have failed to post your config. Maybe try reading more carefully?

RE: Issues after migrating from lighttpd 1.45 to 1.50 - Added by cfsmp3 over 5 years ago

Config file follows:

# 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_expire",
                                "mod_access",
                                "mod_scgi",
                                "mod_auth",
                                "mod_fastcgi",
                                "mod_proxy",
                                "mod_cgi",
                                "mod_compress",
                                "mod_mapped_userdir", # Slightly modified userdir
                                "mod_accesslog" )

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

mapped_userdir.directory_lookup_root="/var/user2dir_maps/" 
mapped_userdir.log = 1
mapped_userdir.cache_maps = 0

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

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

## 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",
  ".jar"          =>      "application/x-java-archive",
  ".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" 

## 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" )

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

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

# Allow more open files, the default (1024) is not always enough
server.max-fds = 16384

$SERVER["socket"] == "*:443" {
    ssl.engine    = "enable" 
    ssl.pemfile   = "/etc/lighttpd/certs/main_certificate.pem" 
    ssl.ca-file   = "/etc/lighttpd/certs/gd_bundle-g2-g1.crt" 
        ssl.use-sslv2 = "disable" 
        ssl.use-sslv3 = "disable" 
    ssl.cipher-list = "aRSA+HIGH !3DES +kEDH +kRSA !kSRP !kPSK" 

  $HTTP["url"] =~ "^/public/" {
        # mimetype mapping
  mimetype.assign             = (
        ""              =>      "application/octet-stream",
     )
  }

  $HTTP["url"] !~ "^/public/" {
  auth.backend = "htpasswd" 
  auth.debug = 1
  auth.backend.htpasswd.userfile = "/var/users.pwd" 

  auth.require = (
  "/" => (
     "method"  => "basic",
     "realm"   => "Who are you?",
     "require" => "valid-user" 
  )
  )
  }
}

## 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 directory listings
#dir-listing.activate       = "enable" 
## select encoding for directory listings
#dir-listing.encoding        = "utf-8" 

## 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            = "www-data" 

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

#### compress module
compress.cache-dir         = "/var/cache/lighttpd/compress/" 
compress.filetype          = ("text/plain", "text/html", "text/css", "text/xml", "text/javascript")

#### fastcgi module
## read fastcgi.txt for more info
## for PHP don't forget to set cgi.fix_pathinfo = 1 in the php.ini
$HTTP["url"] !~ "^/downloads($|/)" {
cgi.assign                 = ( ".pl"  => "/usr/bin/perl" )

fastcgi.server             = ( ".php" =>
                               ( "localhost" =>
                                 (
                                   "socket" => "/tmp/php-fastcgi.sock",
#                                   "bin-path" => "/usr/local/bin/php-cgi",
#                     "max-procs" => 1
                                 )
                               )
                            )
}

RE: Issues after migrating from lighttpd 1.45 to 1.50 - Added by gstrauss over 5 years ago

                                "mod_mapped_userdir", # Slightly modified userdir

...

mapped_userdir.directory_lookup_root="/var/user2dir_maps/" 
mapped_userdir.log = 1
mapped_userdir.cache_maps = 0

See if you still have an issue after you simplify your config and remove your customizations to mod_userdir, to auth (https://redmine.lighttpd.net/boards/3/topics/7537) and possibly elsewhere.

RE: Issues after migrating from lighttpd 1.45 to 1.50 - Added by cfsmp3 over 5 years ago

Removing mod_userdir is not an option for us - we just need that functionality. Without it we can't even test in a real environment.

What it does however is just lookup the user home in a file instead of just deriving it from the user name. For example, if the auth user is "cfsmp3" then the file

/var/user2dir_maps/cfsmp3

would contain a one line with the actual home, which could be

/var/www/1

It's a rather specific thing to us I think which is why I didn't send a PR for it, but I'll be happy to if it helps.

RE: Issues after migrating from lighttpd 1.45 to 1.50 - Added by gstrauss over 5 years ago

You're approaching this incorrectly. If you don't know how to test your own code, you shouldn't be writing any. If you can't set up a separate test environment without your customizations to try to isolate if the problem is related to your changes or not, then you also shouldn't be writing code and using customizations.

You didn't include that you were using customizations in your original problem report, and now you're implying that I need to prove to you that it is not a problem in lighttpd. Well, as I said, you're approach is incorrect. Try making an effort to show me that it is not a problem with your customizations. If your mod_userdir customization is not properly updating con->physical.basedir, then that might be your issue resulting in broken PATH_INFO calculation.

RE: Issues after migrating from lighttpd 1.45 to 1.50 - Added by cfsmp3 over 5 years ago

You're approaching this incorrectly. If you don't know how to test your own code, you shouldn't be writing any.

I'm asking for help the best way I know how, you can help or not, but honestly telling someone that he shouldn't write any code is ridiculous...hopefully you're just having a bad day or something.

This code has been working great for years. It has stopped working after upgrading from 1.4.45 to 1.4.50. Does this mean just because it worked and now it doesn't it's not buggy? Definitely not, but in general when something stop working I usually start considering the parts that have changed, not the parts that haven't.

You didn't include that you were using customizations in your original problem report, and now you're implying that I need to prove to you that it is not a problem in lighttpd.

I have not implied anything, no idea where you get this idea from.

If your mod_userdir customization is not properly updating con->physical.basedir, then that might be your issue resulting in broken PATH_INFO calculation.

That's possible. It's all I needed - a hint on where to look. Might be my code? Sure. But without really understanding what changes in the rest of the code might have triggered this bug, it's hard to figure it out.

mod_userdir.c hasn't changed at all between 1.4.45 and 1.4.50, and my code is based on mod_userdir.c. Doesn't do anything special (I think) or new. Anyway I'm attaching it, if you have time and feel like it please check it out. I'm fine with constructive criticism (but saying I shouldn't be coding...well).

RE: Issues after migrating from lighttpd 1.45 to 1.50 - Added by gstrauss over 5 years ago

If you don't know how to test your own code, you shouldn't be writing any.

Well, let me clarify: don't waste other people's time if you don't know how to test your own code.
Fact: you did not indicate that you have code customizations when you emailed me privately and in your initial posts above.
Fact: you repeatedly stated you think this is a bug in lighttpd when you haven't tried to simulate the issue without your code customizations.

If you read your posts above, it is easy for someone other than you to read that you are implying that there is a bug in lighttpd and you're unable/incapable/unwilling of doing more troubleshooting on your own.

You say above that mod_userdir did not change between 1.4.45 and 1.4.50. However, your mod_mapped_userdir is different from mod_userdir in relevant ways, and I do not mean your enhancements, I mean what mod_userdir is doing that your code is not doing. Your initial post includes trace suggesting a difference in PATH_INFO processing in response.c. Did you look to see what changed in response.c? See commit ec9e6abc

RE: [UserError] Issues after migrating from lighttpd 1.45 to 1.50 - Added by cfsmp3 over 5 years ago

Well, let me clarify: don't waste other people's time if you don't know how to test your own code.

Really, if you think helping a lighttpd user that has made some changes in code is a waste of your time then just ignore me. Maybe someone else will try to help, maybe not.

Fact: you repeatedly stated you think this is a bug in lighttpd when you haven't tried to simulate the issue without your code customizations.

Yes, so? Is it a big deal to point out that I think it could be a new bug in lighttpd since my own code hasn't changed?

I mean what mod_userdir is doing that your code is not doing.

I'll look for whatever I'm missing, thanks.

. Your initial post includes trace suggesting a difference in PATH_INFO processing in response.c.

Yes, but I was pointing at the fact that some code changes and reorganization had happened there, not what that code is doing which is not immediately clear by itself (i.e. you need to know a bit of what's going on).

See commit ec9e6abc

Thanks, this might help.

RE: [UserError] Issues after migrating from lighttpd 1.45 to 1.50 - Added by cfsmp3 over 5 years ago

I've spent some hours trying to figure this out - no luck. The "fundamental" issue is that I just can't reproduce (happens when it happens) and in my module logs everything seems identical.

(Note: I couldn't find anything in userdir that I'm missing in usermapped_dir except for the stuff intentionally left out out as checking for ~):

For example, this works fine:

2018-09-23 18:19:51: (response.c.422) -- splitting Request-URI 
2018-09-23 18:19:51: (response.c.423) Request-URI     :  /userpanel/index.php/js 
2018-09-23 18:19:51: (response.c.424) URI-scheme      :  https 
2018-09-23 18:19:51: (response.c.425) URI-authority   :  ...
2018-09-23 18:19:51: (response.c.426) URI-path (raw)  :  /userpanel/index.php/js 
2018-09-23 18:19:51: (response.c.427) URI-path (clean):  /userpanel/index.php/js 
2018-09-23 18:19:51: (response.c.428) URI-query       :   
2018-09-23 18:19:51: (mod_access.c.159) -- mod_access_uri_handler called 
2018-09-23 18:19:51: (mod_auth.c.741) require_valid_user 2 
2018-09-23 18:19:51: (response.c.573) -- before doc_root 
2018-09-23 18:19:51: (response.c.574) Doc-Root     : /var/www/dummy/ 
2018-09-23 18:19:51: (response.c.575) Rel-Path     : /userpanel/index.php/js 
2018-09-23 18:19:51: (response.c.576) Path         :  
2018-09-23 18:19:51: (response.c.628) -- after doc_root 
2018-09-23 18:19:51: (response.c.629) Doc-Root     : /var/www/dummy/ 
2018-09-23 18:19:51: (response.c.630) Rel-Path     : /userpanel/index.php/js 
2018-09-23 18:19:51: (response.c.631) Path         : /var/www/dummy/userpanel/index.php/js 
2018-09-23 18:19:51: (mod_mapped_userdir.c.223) authed_user= cfs 
2018-09-23 18:19:51: (mod_mapped_userdir.c.224) con->uri.path->ptr= /userpanel/index.php/js 
2018-09-23 18:19:51: (mod_mapped_userdir.c.225) directory_lookup_root= /var/user2dir_maps/ 
2018-09-23 18:19:51: (mod_mapped_userdir.c.255) p->username=  
2018-09-23 18:19:51: (mod_mapped_userdir.c.343) map not cached, no lookup done for user [ cfs ] 
2018-09-23 18:19:51: (mod_mapped_userdir.c.395) UserDirPath= /var/www/user1/ 
2018-09-23 18:19:51: (mod_mapped_userdir.c.406) rel_url= serpanel/index.php/js 
2018-09-23 18:19:51: (mod_mapped_userdir.c.412) rel_url= /userpanel/index.php/js 
2018-09-23 18:19:51: (mod_mapped_userdir.c.413) con->physical.path= /var/www/user1/userpanel/index.php/js 
2018-09-23 18:19:51: (response.c.655) -- logical -> physical 
2018-09-23 18:19:51: (response.c.656) Doc-Root     : /var/www/dummy/ 
2018-09-23 18:19:51: (response.c.657) Basedir      : /var/www/dummy/ 
2018-09-23 18:19:51: (response.c.658) Rel-Path     : /userpanel/index.php/js 
2018-09-23 18:19:51: (response.c.659) Path         : /var/www/user1/userpanel/index.php/js 
2018-09-23 18:19:51: (response.c.671) -- handling physical path 
2018-09-23 18:19:51: (response.c.672) Path         : /var/www/user1/userpanel/index.php/js 
2018-09-23 18:19:51: (response.c.679) -- handling subrequest 
2018-09-23 18:19:51: (response.c.680) Path         : /var/www/user1/userpanel/index.php 
2018-09-23 18:19:51: (response.c.681) URI          : /userpanel/index.php 
2018-09-23 18:19:51: (response.c.682) Pathinfo     : /js 

While this one fails. Everything is identical until response:672... where there is no "handling subrequest"...

2018-09-24 12:14:08: (response.c.422) -- splitting Request-URI 
2018-09-24 12:14:08: (response.c.423) Request-URI     :  /userpanel/index.php/js 
2018-09-24 12:14:08: (response.c.424) URI-scheme      :  https 
2018-09-24 12:14:08: (response.c.425) URI-authority   :  ... 
2018-09-24 12:14:08: (response.c.426) URI-path (raw)  :  /userpanel/index.php/js 
2018-09-24 12:14:08: (response.c.427) URI-path (clean):  /userpanel/index.php/js 
2018-09-24 12:14:08: (response.c.428) URI-query       :   
2018-09-24 12:14:08: (mod_access.c.159) -- mod_access_uri_handler called 
2018-09-24 12:14:08: (mod_auth.c.741) require_valid_user 2 
2018-09-24 12:14:08: (response.c.573) -- before doc_root 
2018-09-24 12:14:08: (response.c.574) Doc-Root     : /var/www/dummy/ 
2018-09-24 12:14:08: (response.c.575) Rel-Path     : /userpanel/index.php/js 
2018-09-24 12:14:08: (response.c.576) Path         :  
2018-09-24 12:14:08: (response.c.628) -- after doc_root 
2018-09-24 12:14:08: (response.c.629) Doc-Root     : /var/www/dummy/ 
2018-09-24 12:14:08: (response.c.630) Rel-Path     : /userpanel/index.php/js 
2018-09-24 12:14:08: (response.c.631) Path         : /var/www/dummy/userpanel/index.php/js 
2018-09-24 12:14:08: (mod_mapped_userdir.c.223) authed_user= testuser17
2018-09-24 12:14:08: (mod_mapped_userdir.c.224) con->uri.path->ptr= /userpanel/index.php/js 
2018-09-24 12:14:08: (mod_mapped_userdir.c.225) directory_lookup_root= /var/user2dir_maps/ 
2018-09-24 12:14:08: (mod_mapped_userdir.c.255) p->username=  
2018-09-24 12:14:08: (mod_mapped_userdir.c.343) map not cached, no lookup done for user [ testuser17 ] 
2018-09-24 12:14:08: (mod_mapped_userdir.c.395) UserDirPath= /var/www/user17/ 
2018-09-24 12:14:08: (mod_mapped_userdir.c.406) rel_url= serpanel/index.php/js 
2018-09-24 12:14:08: (mod_mapped_userdir.c.412) rel_url= /userpanel/index.php/js 
2018-09-24 12:14:08: (mod_mapped_userdir.c.413) con->physical.path= /var/www/user17/userpanel/index.php/js 
2018-09-24 12:14:08: (response.c.655) -- logical -> physical 
2018-09-24 12:14:08: (response.c.656) Doc-Root     : /var/www/dummy/ 
2018-09-24 12:14:08: (response.c.657) Basedir      : /var/www/dummy/ 
2018-09-24 12:14:08: (response.c.658) Rel-Path     : /userpanel/index.php/js 
2018-09-24 12:14:08: (response.c.659) Path         : /var/www/user17/userpanel/index.php/js 
2018-09-24 12:14:08: (response.c.671) -- handling physical path 
2018-09-24 12:14:08: (response.c.672) Path         : /var/www/user17/userpanel/index.php/js 
2018-09-24 12:14:08: (response.c.198) file not found: /userpanel/index.php/js -> /var/www/user17/userpanel/index.php/js 

I've added some more debug lines to response.c so see if I can catch the difference...

RE: [UserError] Issues after migrating from lighttpd 1.45 to 1.50 - Added by cfsmp3 over 5 years ago

                        if (len > 0 && '/' == con->physical.basedir->ptr[len-1]) --len;
                        pathinfo = con->physical.path->ptr + len;

Wonder why len uses con->physical.basedir but then pathinfo uses con->physical.path?

    (1-10/10)