Project

General

Profile

[Abandonded] 400 Bad request when using mod_proxy

Added by mfsoup about 1 month ago

When using ShareX to upload files to my Chibisafe instance, the first file upload will work but every subsequent file upload returns "missing CR before LF in header -> 400" and "unknown protocol -> 400". Bypassing lighttpd by using the application's port directly works fine.
Running lighttpd/1.4.73 on Fedora 39.

lighttpd error.log: 
2024-01-17 21:35:44: (server.c.1933) server started (lighttpd/1.4.73)
2024-01-17 21:35:49: (response.c.295) -- parsed Request-URI
2024-01-17 21:35:49: (response.c.297) Request-URI     : /api/upload
2024-01-17 21:35:49: (response.c.299) URI-scheme      : https
2024-01-17 21:35:49: (response.c.301) URI-authority   : chibisafe.domain.com
2024-01-17 21:35:49: (response.c.303) URI-path (clean): /api/upload
2024-01-17 21:35:49: (response.c.305) URI-query       :
2024-01-17 21:35:49: (gw_backend.c.2767) handling the request using proxy
2024-01-17 21:35:49: (response.c.384) -- logical -> physical
2024-01-17 21:35:49: (response.c.386) Doc-Root     : /var/www/domain
2024-01-17 21:35:49: (response.c.388) Basedir      : /var/www/domain
2024-01-17 21:35:49: (response.c.390) Rel-Path     : /api/upload
2024-01-17 21:35:49: (response.c.392) Path         : /var/www/domain/api/upload
2024-01-17 21:35:56: (h1.c.881) connection closed - keep-alive timeout: 11
2024-01-17 21:35:59: (request.c.317) unknown protocol -> 400
2024-01-17 21:35:59: (request.c.1366) rqst: \xfcr\x92:\x07\xff\x96\xde\xa8\xda\xc2v!\xdb`L\xc1C\xd4Q\xc48|\x83j\xf8\xf8\xc8\xe5\x16\x0b\xb4S\x95\xbam\xb7\x93\xae\xa6\x92x\xc6\x19h\xdb\x8d\xac\xfa\xbf\xf8\xc0\xb5\xae\xe1\xedn~@\xad"\xb7)\x9fL\xddL\x13bs\x81&\x183\x81\x84\xacxLbU\xa8\x8d.\xb1\xb4u\xa5"\x85\xc9\x06 \x1d\x87\x8a\x05\xcd\x08\xf7\xcf\xb1\x80\xb6\>
2024-01-17 21:35:59: (request.c.1366) rqst: Content-Disposition: form-data; name="files[]"; filename="1553718777075.jpg" 
2024-01-17 21:35:59: (request.c.1366) rqst: Content-Type: image/jpeg
2024-01-17 21:35:59: (request.c.1366) rqst:
2024-01-17 21:36:00: (request.c.317) missing CR before LF in header -> 400
2024-01-17 21:36:00: (request.c.1366) rqst: \x9c}\xfd\x0bS\xd6\x00|1\xbb~\xb7\x916\xc43\xc7\x10j[B\xd43\x1d\x9c\x14\x98\x8cfk\xf2\xfc!\r\x13\xcc\x18\xb6\xd3l\xe0A\x0e]\xab\x0f^\xfd\xcf\xfdE\xc6\xc2\x8a\x97\xab\x0b\x9dD'\xb4\x02\x84\xb2\xd0\xae\xe2\xbc\x12r\x15\xaf\x9a\xe0\xb2B6\x08,+\xaf:"\x8ec\x08\xefE\xc0\\xdf\xc6\x1f\xc0\x8b\xd8\x98\x9a\x01{\x11B\xf8\xfc>
2024-01-17 21:36:02: (request.c.317) unknown protocol -> 400
2024-01-17 21:36:02: (request.c.1366) rqst: KS\x05\x9d\xfe\xd7er\x88\xab\x1dc\x1c\r\x9ej\xb5N\xf3O\xf9i\xd3H\x8d\xef1\xd2\xff\x0e\xf8S\xb7\xdf\xfeb\x89\x9e\x03\x01\x81\x81z\x8f\x18=\xab\xb7N\x8f\x13cH\xd7\x80\xc0%\xfb.\x04\x81\xda\xd8\x05^\x17\x19a_\x8f\x0c\xc7\xfe\xce\xe0\xfc*\xdf\xe5\xf2\xd2\xc4?\x9b\xd4 r\x0b\x96p\x97\x04\x02\xe1\xaesw\xd3\x93\x8e=l]\xdb>
2024-01-17 21:36:03: (request.c.317) missing CR before LF in header -> 400
2024-01-17 21:36:03: (request.c.1366) rqst: \xd5X\x1cC\xc21K\xd0\xd8\xc0\xde\x9cTj\xf9\xb5>\x1aw@\xfc\x04.\xcc\x9a\x95\x18q\xb7`R\xec7\x0e\xf7\xa4\xb3\x13"\xc6\x95\xc6-\x14E\xdc\xe09\x03\x8b\xb4Q\xcb\xc3\xa2F\x0bJ\x07u\xf3\x03\x03\xf2\x84\xb3x[\x8a\xdex\x14\x01Q2\x15\xdb=v\xfb\xb6=m\x0e\x8d\x92&\x81nD\xcf\xd2o\xc5\xe2\x88\xd6\xfd:&\xd48u\xc3\xb5\xff\x1d\x9a>2024-01-17 21:36:03: (request.c.1366) rqst: \roh\xbb@wm\xd4Zx\x9bD\xb3B\x8f\x89\xb9j\x1a\xc4.Q\x996mZP\xbf\x9b\xef:\xcdG\xae\x04-T\xa7\x8d\xff%\x91\xa2\x9c\xe91\xe0\xcb&\xf5\xcb=\xb1^1\xc1K\xbb;\x02\xc8\x83C\xc5\x8d\x8f\x87\xfc'\x7f\x90Uj\xe9\xeeU\x98\xa9\xe7\xcfyo\xf9L\x8c\xb3\x9f\x01\xfb)\xf4\xe6\x9d\xa0\xf9\xd4\x18\tV|\x91\x98\xcb\xe5\xbc\xb8\x1c\xf9\xed>

sharex error log:
Error message:
Unable to write data to the transport connection: An existing connection was forcibly closed by the remote host.

Request URL:
https://chibisafe.domain.com/api/upload

Stack trace:
   at System.Net.Sockets.NetworkStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   at System.Net.Security._SslStream.StartWriting(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   at System.Net.Security._SslStream.ProcessWrite(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   at System.Net.TlsStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   at System.Net.PooledStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   at System.Net.ConnectStream.InternalWrite(Boolean async, Byte[] buffer, Int32 offset, Int32 size, AsyncCallback callback, Object state)
   at System.Net.ConnectStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   at ShareX.UploadersLib.Uploader.TransferData(Stream dataStream, Stream requestStream, Int64 dataPosition, Int64 dataLength)
   at ShareX.UploadersLib.Uploader.SendRequestFile(String url, Stream data, String fileName, String fileFormName, Dictionary`2 args, NameValueCollection headers, CookieCollection cookies, HttpMethod method, String contentType, String relatedData)@

lighttpd config: 
var.log_root    = "/var/log/lighttpd" 
var.server_root = "/var/www" 
var.state_dir   = "/run/lighttpd" 
var.home_dir    = "/var/lib/lighttpd" 
var.conf_dir    = "/etc/lighttpd" 

var.vhosts_dir  = server_root + "/vhosts" 
var.cache_dir   = "/var/cache/lighttpd" 
var.socket_dir  = state_dir + "/sockets" 

include "modules.conf" 

server.port = 80
server.username  = "lighttpd" 
server.groupname = "lighttpd" 

server.document-root = server_root + "/domain" 

server.pid-file = state_dir + "/lighttpd.pid" 

server.errorlog = log_root + "/error.log" 
include "conf.d/access_log.conf" 
include "conf.d/debug.conf" 

server.event-handler = "linux-sysepoll" 
server.network-backend = "sendfile" 
server.max-fds = 2048
server.stat-cache-engine = "simple" 
server.max-connections = 1024

index-file.names += (
  "index.xhtml", "index.html", "index.htm", "default.htm", "index.php", "/pita/_h5ai/public/index.php" 
)
url.access-deny             = ( "~", ".inc" )
$HTTP["url"] =~ "\.pdf$" {
  server.range-requests = "disable" 
}
include "conf.d/mime.conf" 
include "conf.d/dirlisting.conf" 
server.follow-symlink = "enable" 
server.upload-dirs = ( "/var/tmp" )

server.modules += ("mod_openssl")
$SERVER["socket"] == "0.0.0.0:443" {
    ssl.engine = "enable" 
    ssl.privkey= "/etc/letsencrypt/live/domain.com-0001/privkey.pem" 
    ssl.pemfile= "/etc/letsencrypt/live/domain.com-0001/fullchain.pem" 
    ssl.openssl.ssl-conf-cmd = ("MinProtocol" => "TLSv1.2") # (recommended to accept only TLSv1.2 and TLSv1.3)

$HTTP["host"] == "chibisafe.domain.com" {
  proxy.server = ( "" => (
    ( "host" => "127.0.0.1", "port" => 5000 )
  ) )
}


Replies (1)

RE: 400 Bad request when using mod_proxy - Added by gstrauss about 1 month ago

It seems like the connection timed out after serving the request and while waiting for the next request
2024-01-17 21:35:56: (h1.c.881) connection closed - keep-alive timeout: 11
(However, you did not enabled debug.log-response-header, so you are not seeing that in the log)
...and then your client reconnected? and incorrectly continued sending what looks like it could be pieces of a multipart request body.
2024-01-17 21:35:59: (request.c.317) unknown protocol -> 400
2024-01-17 21:35:59: (request.c.1366) rqst: \xfcr\x92:\x07\xff\x96 [...]
That is invalid. I do not see anything wrong with what lighttpd is doing.

You probably should enable some additional debugging flags to see when your client is making connections and capture lighttpd request and response headers. DebugVariables

    (1-1/1)