413 error in apache even though my POST is much smaller than the max limit

Question

I have asked this question on stack overflow as well. I have an apache server and a fastcgi script. When I try to send POST request to my script, it fails giving me the 413 error. If I send in no parameters, my script actually runs giving me error in json (as expected).

I am using curl to send data to my script:

curl --data -v 'name=test&address=abc&phoneNumber=0987654321&password=test123' http://localhost/cgi-bin/add-user.fcg

It gives this output:

*   Trying ::1...
* TCP_NODELAY set
* Connected to localhost (::1) port 80 (#0)
> POST /cgi-bin/add-user.fcg HTTP/1.1
> Host: localhost
> User-Agent: curl/7.61.1
> Accept: */*
> Content-Length: 61
> Content-Type: application/x-www-form-urlencoded
> 
* upload completely sent off: 61 out of 61 bytes
< HTTP/1.1 413 Request Entity Too Large
< Date: Tue, 26 Mar 2019 03:43:48 GMT
< Server: Apache/2.4.38 (Fedora) mod_fcgid/2.3.9
< Connection: close
< Transfer-Encoding: chunked
< Content-Type: text/html; charset=utf-8
< 
* Closing connection 0
<!DOCTYPE html><html lang='en'><head><title>413 Request Entity Too Large</title></head><body><h1>413 Request Entity Too Large</h1></body></html>

I am sending 61 bytes! I feel that is too low for this error. This is what I have done till now:

I did not have LimitRequestBody in my httpd.conf, so it should have been defaulted to 0 (aka unlimited). But still, I added LimitRequestBody 1024000 and restarted the server
Then I read somewhere that mod_security might have interfered. So I added <IfModule secruity2_module> SecRequestBody Off </IfModule> but to no avail

This is my httpd.conf: ServerRoot "/etc/httpd"

Listen 80

Include conf.modules.d/*.conf

User apache
Group apache

ServerAdmin root@localhost

<Directory />
    AllowOverride none
    Require all denied
</Directory>

DocumentRoot "/var/www/html"

<Directory "/var/www">
    AllowOverride None
    # Allow open access:
    Require all granted
</Directory>

<Directory "/var/www/html">
    Options Indexes FollowSymLinks

    AllowOverride None

    Require all granted
</Directory>

<IfModule dir_module>
    DirectoryIndex index.html
</IfModule>

<Files ".ht*">
    Require all denied
</Files>

ErrorLog "logs/error_log"

LogLevel warn

<IfModule log_config_module>
    LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" combined
    LogFormat "%h %l %u %t \"%r\" %>s %b" common

    <IfModule logio_module>
      LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\" %I %O" combinedio
    </IfModule>


    CustomLog "logs/access_log" combined
</IfModule>

<IfModule alias_module>
    ScriptAlias /cgi-bin/ "/var/www/cgi-bin/"
</IfModule>

<Directory "/var/www/cgi-bin">
    AllowOverride None
    Options +ExecCGI
    Require all granted
    SetHandler fcgid-script
</Directory>

<IfModule mime_module>
    TypesConfig /etc/mime.types

    AddType application/x-compress .Z
    AddType application/x-gzip .gz .tgz

    AddType text/html .shtml
    AddOutputFilter INCLUDES .shtml
</IfModule>

AddDefaultCharset UTF-8

<IfModule mime_magic_module>
    MIMEMagicFile conf/magic
</IfModule>

EnableSendfile on

IncludeOptional conf.d/*.conf

#I added the line below
LimitRequestBody 1024000 

<IfModule secruity2_module>
    SecRequestBody Off
</IfModule>

I then changed the log level to debug. This is the error_log:

[Tue Mar 26 09:04:40.196028 2019] [core:notice] [pid 2881:tid 140595868158208] SELinux policy enabled; httpd running as context system_u:system_r:httpd_t:s0
[Tue Mar 26 09:04:40.196893 2019] [suexec:notice] [pid 2881:tid 140595868158208] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Tue Mar 26 09:04:40.196926 2019] [:notice] [pid 2881:tid 140595868158208] ModSecurity for Apache/2.9.2 (http://www.modsecurity.org/) configured.
[Tue Mar 26 09:04:40.196931 2019] [:notice] [pid 2881:tid 140595868158208] ModSecurity: APR compiled version="1.6.3"; loaded version="1.6.5"
[Tue Mar 26 09:04:40.196935 2019] [:warn] [pid 2881:tid 140595868158208] ModSecurity: Loaded APR do not match with compiled!
[Tue Mar 26 09:04:40.196939 2019] [:notice] [pid 2881:tid 140595868158208] ModSecurity: PCRE compiled version="8.42 "; loaded version="8.43 2019-02-23"
[Tue Mar 26 09:04:40.196946 2019] [:warn] [pid 2881:tid 140595868158208] ModSecurity: Loaded PCRE do not match with compiled!
[Tue Mar 26 09:04:40.196949 2019] [:notice] [pid 2881:tid 140595868158208] ModSecurity: LUA compiled version="Lua 5.3"
[Tue Mar 26 09:04:40.196952 2019] [:notice] [pid 2881:tid 140595868158208] ModSecurity: YAJL compiled version="2.1.0"
[Tue Mar 26 09:04:40.196956 2019] [:notice] [pid 2881:tid 140595868158208] ModSecurity: LIBXML compiled version="2.9.8"
[Tue Mar 26 09:04:40.196959 2019] [:notice] [pid 2881:tid 140595868158208] ModSecurity: Status engine is currently disabled, enable it by set SecStatusEngine to On.
[Tue Mar 26 09:04:40.196968 2019] [http2:debug] [pid 2881:tid 140595868158208] mod_http2.c(112): AH03089: initializing post config dry run
[Tue Mar 26 09:04:40.218065 2019] [so:warn] [pid 2881:tid 140595868158208] AH01574: module security2_module is already loaded, skipping
AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using localhost.localdomain. Set the 'ServerName' directive globally to suppress this message
[Tue Mar 26 09:04:40.221248 2019] [slotmem_shm:debug] [pid 2881:tid 140595868158208] mod_slotmem_shm.c(496): AH02301: attach looking for /run/httpd/slotmem-shm-mod_heartmonitor_0.shm
[Tue Mar 26 09:04:40.221287 2019] [lbmethod_heartbeat:notice] [pid 2881:tid 140595868158208] AH02282: No slotmem from mod_heartmonitor
[Tue Mar 26 09:04:40.224000 2019] [http2:info] [pid 2881:tid 140595868158208] AH03090: mod_http2 (v1.14.1-git, feats=CHPRIO+SHA256+INVHD+DWINS, nghttp2 1.34.0), initializing...
[Tue Mar 26 09:04:40.224058 2019] [http2:warn] [pid 2881:tid 140595868158208] AH02951: mod_ssl does not seem to be enabled
[Tue Mar 26 09:04:40.224046 2019] [fcgid:info] [pid 2883:tid 140595868158208] mod_fcgid: Process manager 2883 started
[Tue Mar 26 09:04:40.224180 2019] [proxy_http2:info] [pid 2881:tid 140595868158208] AH03349: mod_proxy_http2 (v1.14.1-git, nghttp2 1.34.0), initializing...
[Tue Mar 26 09:04:40.224211 2019] [proxy_hcheck:debug] [pid 2881:tid 140595868158208] mod_proxy_hcheck.c(1050): AH03265: watchdog callback registered (_proxy_hcheck_ for localhost.localdomain)
[Tue Mar 26 09:04:40.224234 2019] [watchdog:debug] [pid 2881:tid 140595868158208] mod_watchdog.c(454): AH010033: Watchdog: Running with WatchdogInterval 1000ms
[Tue Mar 26 09:04:40.224241 2019] [watchdog:debug] [pid 2881:tid 140595868158208] mod_watchdog.c(462): AH02974: Watchdog: found parent providers.
[Tue Mar 26 09:04:40.224247 2019] [watchdog:debug] [pid 2881:tid 140595868158208] mod_watchdog.c(508): AH02977: Watchdog: found child providers.
[Tue Mar 26 09:04:40.224252 2019] [watchdog:debug] [pid 2881:tid 140595868158208] mod_watchdog.c(516): AH02978: Watchdog: Looking for child (_singleton_).
[Tue Mar 26 09:04:40.224256 2019] [watchdog:debug] [pid 2881:tid 140595868158208] mod_watchdog.c(516): AH02978: Watchdog: Looking for child (_default_).
[Tue Mar 26 09:04:40.224261 2019] [watchdog:debug] [pid 2881:tid 140595868158208] mod_watchdog.c(516): AH02978: Watchdog: Looking for child (_proxy_hcheck_).
[Tue Mar 26 09:04:40.224275 2019] [watchdog:debug] [pid 2881:tid 140595868158208] mod_watchdog.c(542): AH02979: Watchdog: Created singleton mutex (_proxy_hcheck_).
[Tue Mar 26 09:04:40.229631 2019] [mpm_event:notice] [pid 2881:tid 140595868158208] AH00489: Apache/2.4.38 (Fedora) mod_fcgid/2.3.9 configured -- resuming normal operations
[Tue Mar 26 09:04:40.229659 2019] [mpm_event:info] [pid 2881:tid 140595868158208] AH00490: Server built: Jan 23 2019 12:39:31
[Tue Mar 26 09:04:40.229669 2019] [core:notice] [pid 2881:tid 140595868158208] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND'
[Tue Mar 26 09:04:40.229674 2019] [core:debug] [pid 2881:tid 140595868158208] log.c(1571): AH02639: Using SO_REUSEPORT: yes (1)
[Tue Mar 26 09:04:40.232979 2019] [watchdog:debug] [pid 2885:tid 140595820508928] mod_watchdog.c(158): AH02972: Singleton Watchdog (_proxy_hcheck_) running
[Tue Mar 26 09:04:40.232987 2019] [watchdog:debug] [pid 2885:tid 140595868158208] mod_watchdog.c(590): AH02981: Watchdog: Created child worker thread (_proxy_hcheck_).
[Tue Mar 26 09:04:40.233085 2019] [proxy_hcheck:debug] [pid 2885:tid 140595820508928] mod_proxy_hcheck.c(893): AH03258: _proxy_hcheck_ watchdog started.
[Tue Mar 26 09:04:40.233333 2019] [proxy:debug] [pid 2885:tid 140595868158208] proxy_util.c(1927): AH00925: initializing worker proxy:reverse shared
[Tue Mar 26 09:04:40.233365 2019] [proxy:debug] [pid 2885:tid 140595868158208] proxy_util.c(1984): AH00927: initializing worker proxy:reverse local
[Tue Mar 26 09:04:40.233409 2019] [proxy:debug] [pid 2885:tid 140595868158208] proxy_util.c(2019): AH00930: initialized pool in child 2885 for (*) min=0 max=61 smax=61
[Tue Mar 26 09:04:40.234163 2019] [proxy_hcheck:debug] [pid 2885:tid 140595820508928] mod_proxy_hcheck.c(907): AH03313: apr_thread_pool_create() with 16 threads succeeded
[Tue Mar 26 09:04:40.235043 2019] [mpm_event:debug] [pid 2885:tid 140595292866304] event.c(2314): AH02471: start_threads: Using epoll (wakeable)
[Tue Mar 26 09:04:40.236319 2019] [watchdog:debug] [pid 2886:tid 140595868158208] mod_watchdog.c(590): AH02981: Watchdog: Created child worker thread (_proxy_hcheck_).
[Tue Mar 26 09:04:40.236395 2019] [proxy:debug] [pid 2886:tid 140595868158208] proxy_util.c(1927): AH00925: initializing worker proxy:reverse shared
[Tue Mar 26 09:04:40.236456 2019] [proxy:debug] [pid 2886:tid 140595868158208] proxy_util.c(1984): AH00927: initializing worker proxy:reverse local
[Tue Mar 26 09:04:40.236488 2019] [proxy:debug] [pid 2886:tid 140595868158208] proxy_util.c(2019): AH00930: initialized pool in child 2886 for (*) min=0 max=61 smax=61
[Tue Mar 26 09:04:40.237535 2019] [:warn] [pid 2884:tid 140595868158208] ./mod_dnssd.c: No services found to register
[Tue Mar 26 09:04:40.237654 2019] [watchdog:debug] [pid 2887:tid 140595868158208] mod_watchdog.c(590): AH02981: Watchdog: Created child worker thread (_proxy_hcheck_).
[Tue Mar 26 09:04:40.237715 2019] [proxy:debug] [pid 2887:tid 140595868158208] proxy_util.c(1927): AH00925: initializing worker proxy:reverse shared
[Tue Mar 26 09:04:40.237739 2019] [proxy:debug] [pid 2887:tid 140595868158208] proxy_util.c(1984): AH00927: initializing worker proxy:reverse local
[Tue Mar 26 09:04:40.237766 2019] [proxy:debug] [pid 2887:tid 140595868158208] proxy_util.c(2019): AH00930: initialized pool in child 2887 for (*) min=0 max=61 smax=61
[Tue Mar 26 09:04:40.239266 2019] [mpm_event:debug] [pid 2886:tid 140595501586176] event.c(2314): AH02471: start_threads: Using epoll (wakeable)
[Tue Mar 26 09:04:40.239529 2019] [mpm_event:debug] [pid 2887:tid 140595501586176] event.c(2314): AH02471: start_threads: Using epoll (wakeable)
[Tue Mar 26 09:05:42.487165 2019] [authz_core:debug] [pid 2885:tid 140595284473600] mod_authz_core.c(820): [client ::1:34770] AH01626: authorization result of Require all granted: granted
[Tue Mar 26 09:05:42.487347 2019] [authz_core:debug] [pid 2885:tid 140595284473600] mod_authz_core.c(820): [client ::1:34770] AH01626: authorization result of <RequireAny>: granted
[Tue Mar 26 09:05:42.496956 2019] [fcgid:info] [pid 2883:tid 140595868158208] mod_fcgid: server localhost.localdomain:/var/www/cgi-bin/add-user.fcg(3148) started
[Tue Mar 26 09:13:48.452071 2019] [authz_core:debug] [pid 2886:tid 140595418887936] mod_authz_core.c(820): [client ::1:34974] AH01626: authorization result of Require all granted: granted
[Tue Mar 26 09:13:48.452192 2019] [authz_core:debug] [pid 2886:tid 140595418887936] mod_authz_core.c(820): [client ::1:34974] AH01626: authorization result of <RequireAny>: granted

And this is the access log:

::1 - - [26/Mar/2019:09:05:42 +0530] "POST /cgi-bin/add-user.fcg HTTP/1.1" 413 144 "-" "curl/7.61.1"
::1 - - [26/Mar/2019:09:13:48 +0530] "POST /cgi-bin/add-user.fcg HTTP/1.1" 413 144 "-" "curl/7.61.1"

score 1 · Accepted Answer · answered Apr 02 '19 at 09:37

I see that the call to the Apache Server at 09:05:42

::1 - - [26/Mar/2019:09:05:42 +0530] "POST /cgi-bin/add-user.fcg HTTP/1.1" 413 144 "-" "curl/7.61.1"

correctly started the CGI Script

[Tue Mar 26 09:05:42.496956 2019] [fcgid:info] [pid 2883:tid 140595868158208] mod_fcgid: server localhost.localdomain:/var/www/cgi-bin/add-user.fcg(3148) started

So the Response Code 413 might come from your Script itself.

It would be useful to see what Content reaches your Script.

Yeah. Actually that was the problem, My FASTCGI library had POST request disabled by default. — Hemil, Apr 03 '19 at 03:40

413 error in apache even though my POST is much smaller than the max limit

1 Answers1