WAF not working? Long lost child come home, graceful restarting

Running 9.400-9 soft release. Not sure if the problem is specific to 9.4 or would have existed under 9.3.

WAF log:

2016:04:06-05:43:01 astaro1-1 reverseproxy: id="0299" srcip="127.0.0.1" localip="127.0.0.1" size="1" user="-" host="127.0.0.1" method="GET" statuscode="200" reason="-" extra="-" exceptions="-" time="96039" url="/session-cleanup" server="localhost" referer="-" cookie="-" set-cookie="-"
2016:04:06-05:43:01 astaro1-1 reverseproxy: regular session cleanup: success (sessions deleted: 0)
2016:04:06-05:43:02 astaro1-2 reverseproxy: regular session cleanup: success (sessions deleted: 0)
2016:04:06-05:43:02 astaro1-2 reverseproxy: id="0299" srcip="127.0.0.1" localip="127.0.0.1" size="1" user="-" host="127.0.0.1" method="GET" statuscode="200" reason="-" extra="-" exceptions="-" time="198011" url="/session-cleanup" server="localhost" referer="-" cookie="-" set-cookie="-"
2016:04:06-13:31:27 astaro1-2 reverseproxy: [Wed Apr 06 13:31:27.190702 2016] [mpm_worker:notice] [pid 6068:tid 4148152000] AH00297: SIGUSR1 received.  Doing graceful restart
2016:04:06-13:31:30 astaro1-1 reverseproxy: [Wed Apr 06 13:31:30.767132 2016] [mpm_worker:notice] [pid 6090:tid 4147971776] AH00297: SIGUSR1 received.  Doing graceful restart
2016:04:06-13:31:31 astaro1-2 reverseproxy: [Wed Apr 06 13:31:31.001367 2016] [mpm_worker:notice] [pid 6068:tid 4148152000] AH00292: Apache/2.4.10 (Unix) OpenSSL/1.0.1k configured -- resuming normal operations
2016:04:06-13:31:31 astaro1-2 reverseproxy: [Wed Apr 06 13:31:31.001417 2016] [core:notice] [pid 6068:tid 4148152000] AH00094: Command line: '/usr/apache/bin/httpd'
2016:04:06-13:31:31 astaro1-2 reverseproxy: [Wed Apr 06 13:31:31.001529 2016] [mpm_worker:warn] [pid 6068:tid 4148152000] AH00291: long lost child came home! (pid 7889)
2016:04:06-13:31:31 astaro1-2 reverseproxy: [Wed Apr 06 13:31:31.001579 2016] [mpm_worker:warn] [pid 6068:tid 4148152000] AH00291: long lost child came home! (pid 7890)
2016:04:06-13:31:34 astaro1-1 reverseproxy: [Wed Apr 06 13:31:34.000430 2016] [mpm_worker:notice] [pid 6090:tid 4147971776] AH00292: Apache/2.4.10 (Unix) OpenSSL/1.0.1k configured -- resuming normal operations
2016:04:06-13:31:34 astaro1-1 reverseproxy: [Wed Apr 06 13:31:34.000462 2016] [core:notice] [pid 6090:tid 4147971776] AH00094: Command line: '/usr/apache/bin/httpd'
2016:04:06-13:31:34 astaro1-1 reverseproxy: [Wed Apr 06 13:31:34.000516 2016] [mpm_worker:warn] [pid 6090:tid 4147971776] AH00291: long lost child came home! (pid 8297)
2016:04:06-13:31:34 astaro1-1 reverseproxy: [Wed Apr 06 13:31:34.000543 2016] [mpm_worker:warn] [pid 6090:tid 4147971776] AH00291: long lost child came home! (pid 8298)
2016:04:06-13:33:09 astaro1-2 reverseproxy: [Wed Apr 06 13:33:09.069603 2016] [mpm_worker:notice] [pid 6068:tid 4148152000] AH00297: SIGUSR1 received.  Doing graceful restart
2016:04:06-13:33:09 astaro1-2 reverseproxy: AH00112: Warning: DocumentRoot [/var/www/REF_RevFroInterPlain] does not exist
2016:04:06-13:33:09 astaro1-1 reverseproxy: [Wed Apr 06 13:33:09.989042 2016] [mpm_worker:notice] [pid 6090:tid 4147971776] AH00297: SIGUSR1 received.  Doing graceful restart
2016:04:06-13:33:10 astaro1-2 reverseproxy: [Wed Apr 06 13:33:10.000385 2016] [mpm_worker:notice] [pid 6068:tid 4148152000] AH00292: Apache/2.4.10 (Unix) OpenSSL/1.0.1k configured -- resuming normal operations
2016:04:06-13:33:10 astaro1-2 reverseproxy: [Wed Apr 06 13:33:10.000417 2016] [core:notice] [pid 6068:tid 4148152000] AH00094: Command line: '/usr/apache/bin/httpd'
2016:04:06-13:33:10 astaro1-2 reverseproxy: [Wed Apr 06 13:33:10.000460 2016] [mpm_worker:warn] [pid 6068:tid 4148152000] AH00291: long lost child came home! (pid 10085)
2016:04:06-13:33:10 astaro1-2 reverseproxy: [Wed Apr 06 13:33:10.000484 2016] [mpm_worker:warn] [pid 6068:tid 4148152000] AH00291: long lost child came home! (pid 10086)
2016:04:06-13:33:10 astaro1-1 reverseproxy: AH00112: Warning: DocumentRoot [/var/www/REF_RevFroInterPlain] does not exist
2016:04:06-13:33:11 astaro1-1 reverseproxy: [Wed Apr 06 13:33:11.000749 2016] [mpm_worker:notice] [pid 6090:tid 4147971776] AH00292: Apache/2.4.10 (Unix) OpenSSL/1.0.1k configured -- resuming normal operations
2016:04:06-13:33:11 astaro1-1 reverseproxy: [Wed Apr 06 13:33:11.000779 2016] [core:notice] [pid 6090:tid 4147971776] AH00094: Command line: '/usr/apache/bin/httpd'
2016:04:06-13:33:11 astaro1-1 reverseproxy: [Wed Apr 06 13:33:11.000821 2016] [mpm_worker:warn] [pid 6090:tid 4147971776] AH00291: long lost child came home! (pid 31736)
2016:04:06-13:33:11 astaro1-1 reverseproxy: [Wed Apr 06 13:33:11.000842 2016] [mpm_worker:warn] [pid 6090:tid 4147971776] AH00291: long lost child came home! (pid 31737)

Any ideas what the problem is or where I should look?

Thanks,

James.
Parents
  • Hi,

    the logs don't show any unusual behavior. OK, there are many restarts of the WAF but if you have configured multiple things that's possible.
    What's the exact problem?

    Sabine

  • We had a security audit done and WAF wasn't stopping anything. There were no WAF logs from back then, so it must have been turned off. There are logs now, so I'm just wanting to make sure it is all working OK.

    What about the poor long lost children?

    And I'm not sure why the WAF would keep restarting? Does it start apache every time there is new connection to a real web server, and then quit it when the connection closes?

    How do I know it is working OK I suppose is the real problem (without firing up Metasploit or something like that).

    James.

  • Every time you change something in the Webadmin for WAF, the Apache must restart otherwise it would not take up the changes. Therefore, if you set up your WAF the first time, you'll get many restarts.

    The long lost child messages are normal in the case of doing a graceful restart. The message sounds like something is wrong but it's not.

    If traffic goes over the WAF, you should see that traffic in the log. At the moment, there is not traffic at all.

    Traffic looks like this:
    2016:04:06-10:44:28 myUTM reverseproxy: id="0299" srcip="10.x.x.x" localip="10.x.x.y" size="209" user="-" host="10.x.x.x" method="GET" statuscode="200" reason="-" extra="-" exceptions="-" time="3255" url="/" server="myserver.local" referer="-" cookie="-" set-cookie="-"


    Sabine

Reply
  • Every time you change something in the Webadmin for WAF, the Apache must restart otherwise it would not take up the changes. Therefore, if you set up your WAF the first time, you'll get many restarts.

    The long lost child messages are normal in the case of doing a graceful restart. The message sounds like something is wrong but it's not.

    If traffic goes over the WAF, you should see that traffic in the log. At the moment, there is not traffic at all.

    Traffic looks like this:
    2016:04:06-10:44:28 myUTM reverseproxy: id="0299" srcip="10.x.x.x" localip="10.x.x.y" size="209" user="-" host="10.x.x.x" method="GET" statuscode="200" reason="-" extra="-" exceptions="-" time="3255" url="/" server="myserver.local" referer="-" cookie="-" set-cookie="-"


    Sabine

Children
No Data