This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

Web Protection Causing 100% CPU Use

Having an issue with my UTM web filtering causing 100% cpu use and causing all traffic to crawl.  When I look at the processes, I see httpproxy causing over 100% cpu usage.  When I turn off web filtering, the issue goes away.

This happened about two weeks ago without any configuration or environment changes.

 

I see this in the web protection logs when I turn on  and off web protection:

 

2018:12:09-19:48:49 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="285" message="reading configuration"
2018:12:09-19:48:50 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="parse_address" file="util.c" line="540" message="getaddrinfo: passthrough6.fw-notify.net: Name or service not known"
2018:12:09-19:48:50 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="confd_config_filter" file="confd-client.c" line="3859" message="failed to resolve passthrough6.fw-notify.net, using 2a01:198:200:680::8080"
2018:12:09-19:48:51 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="311" message="caching templates"
2018:12:09-19:48:51 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="314" message="reading profiles"
2018:12:09-19:48:51 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="disk_cache_read" file="diskcache.c" line="1705" message="fopen: /var/httpcache/cacheidx: No such file or directory"
2018:12:09-19:48:51 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="disk_cache_read" file="diskcache.c" line="1841" message="failed cache index rename: No such file or directory"
2018:12:09-19:48:51 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="rmdir_recursive_background_func" file="diskcache.c" line="681" message="removing zapped cache root folder /var/httpcache.001"
2018:12:09-19:48:54 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scanner_init" file="aptpscanner.c" line="185" message="ATP loaded"
2018:12:09-19:49:22 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scanner_init" file="saviscanner.c" line="514" message="Successfully loaded SAVI threat data, engine 3.74.0, threat data 5.56 from 16/10/2018 (25804084 detected threats)"
2018:12:09-19:49:22 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="libnavl_log" file="navl_externals_posix.c" line="43" message="E: InitInstance: Error initializing instance of plugin HPACK_UTIL"
2018:12:09-19:49:23 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="354" message="notifiying argos daemon"
2018:12:09-19:49:23 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="argos_notify" file="httpproxy.c" line="209" message="connect: Connection refused"
2018:12:09-19:49:23 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="360" message="finished startup"
2018:12:09-19:49:23 homefw httpproxy[29868]: Integrated HTTP-Proxy (c) 2007-2016 Sophos Ltd, Release 547.g1f8aab75.rb3
2018:12:09-19:49:49 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="http_parser_context_execute" file="http_parser_context.c" line="97" message="Unable to parse a http message of 160 bytes (HPE_INVALID_METHOD: invalid HTTP method)"
2018:12:09-19:49:49 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="0x9cf6a600" function="read_request_headers" file="request.c" line="1590" message="unable to parse a http message on handler 120 (Resource temporarily unavailable)"
2018:12:09-19:52:46 homefw URID[29804]: T=29804 ------ 1 - [exit] SIGTERM: exiting
2018:12:09-19:52:46 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="confd_config_reload_func" file="confd-client.c" line="587" message="reloading config"
2018:12:09-19:52:46 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="parse_address" file="util.c" line="540" message="getaddrinfo: passthrough6.fw-notify.net: Name or service not known"
2018:12:09-19:52:46 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="confd_config_filter" file="confd-client.c" line="3859" message="failed to resolve passthrough6.fw-notify.net, using 2a01:198:200:680::8080"
2018:12:09-19:52:46 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="epoll_loop" file="epoll.c" line="861" message="starting exit cleanup"
2018:12:09-19:52:47 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="confd_config_reload_func" file="confd-client.c" line="651" message="reloading config done, new version 117"
2018:12:09-19:52:47 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scan_exit" file="scanner.c" line="943" message="scanner subsystem shutting down"
2018:12:09-19:52:53 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scan_exit" file="scanner.c" line="949" message="scanner subsystem shut down"
2018:12:09-19:52:53 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="epoll_exit" file="epoll.c" line="681" message="epoll subsystem shutting down"
2018:12:09-19:52:53 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="epoll_exit" file="epoll.c" line="698" message="epoll subsystem shut down"
2018:12:09-19:52:53 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="disk_cache_release_cache" file="diskcache.c" line="407" message="writing cache index"
2018:12:09-19:52:53 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="disk_cache_release_cache" file="diskcache.c" line="409" message="writing cache index done"
2018:12:09-19:52:53 homefw httpproxy[29868]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="404" message="shutdown finished, exiting"
2018:12:09-19:57:07 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="285" message="reading configuration"
2018:12:09-19:57:08 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="parse_address" file="util.c" line="540" message="getaddrinfo: passthrough6.fw-notify.net: Name or service not known"
2018:12:09-19:57:08 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="confd_config_filter" file="confd-client.c" line="3859" message="failed to resolve passthrough6.fw-notify.net, using 2a01:198:200:680::8080"
2018:12:09-19:57:08 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="311" message="caching templates"
2018:12:09-19:57:08 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="314" message="reading profiles"
2018:12:09-19:57:08 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="disk_cache_read" file="diskcache.c" line="1765" message="calculated md5sum: [D41D8CD98F00B204E9800998ECF8427E], file md5sum: [D41D8CD98F00B204E9800998ECF8427E]"
2018:12:09-19:57:11 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scanner_init" file="aptpscanner.c" line="185" message="ATP loaded"
2018:12:09-19:57:42 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scanner_init" file="saviscanner.c" line="514" message="Successfully loaded SAVI threat data, engine 3.74.0, threat data 5.56 from 16/10/2018 (25804084 detected threats)"
2018:12:09-19:57:42 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="libnavl_log" file="navl_externals_posix.c" line="43" message="E: InitInstance: Error initializing instance of plugin HPACK_UTIL"
2018:12:09-19:57:42 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="354" message="notifiying argos daemon"
2018:12:09-19:57:42 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="argos_notify" file="httpproxy.c" line="209" message="connect: Connection refused"
2018:12:09-19:57:42 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="360" message="finished startup"
2018:12:09-19:57:42 homefw httpproxy[30982]: Integrated HTTP-Proxy (c) 2007-2016 Sophos Ltd, Release 547.g1f8aab75.rb3
2018:12:09-19:58:00 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="epoll_loop" file="epoll.c" line="861" message="starting exit cleanup"
2018:12:09-19:58:01 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scan_exit" file="scanner.c" line="943" message="scanner subsystem shutting down"
2018:12:09-19:58:30 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scan_exit" file="scanner.c" line="949" message="scanner subsystem shut down"
2018:12:09-19:58:30 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="epoll_exit" file="epoll.c" line="681" message="epoll subsystem shutting down"
2018:12:09-19:58:30 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="epoll_exit" file="epoll.c" line="698" message="epoll subsystem shut down"
2018:12:09-19:58:30 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="disk_cache_release_cache" file="diskcache.c" line="407" message="writing cache index"
2018:12:09-19:58:30 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="disk_cache_release_cache" file="diskcache.c" line="409" message="writing cache index done"
2018:12:09-19:58:30 homefw httpproxy[30982]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="404" message="shutdown finished, exiting"
2018:12:09-19:58:31 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="285" message="reading configuration"
2018:12:09-19:58:32 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="parse_address" file="util.c" line="540" message="getaddrinfo: passthrough6.fw-notify.net: Name or service not known"
2018:12:09-19:58:32 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="confd_config_filter" file="confd-client.c" line="3859" message="failed to resolve passthrough6.fw-notify.net, using 2a01:198:200:680::8080"
2018:12:09-19:58:32 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="311" message="caching templates"
2018:12:09-19:58:32 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="314" message="reading profiles"
2018:12:09-19:58:33 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="disk_cache_folder_has_files_or_invalid" file="diskcache.c" line="254" message=" cache root access /var/httpcache: No such file or directory"
2018:12:09-19:58:36 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scanner_init" file="aptpscanner.c" line="185" message="ATP loaded"
2018:12:09-19:59:02 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scanner_init" file="saviscanner.c" line="514" message="Successfully loaded SAVI threat data, engine 3.74.0, threat data 5.56 from 16/10/2018 (25804084 detected threats)"
2018:12:09-19:59:02 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="libnavl_log" file="navl_externals_posix.c" line="43" message="E: InitInstance: Error initializing instance of plugin HPACK_UTIL"
2018:12:09-19:59:03 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="354" message="notifiying argos daemon"
2018:12:09-19:59:03 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="argos_notify" file="httpproxy.c" line="209" message="connect: Connection refused"
2018:12:09-19:59:03 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="360" message="finished startup"
2018:12:09-19:59:03 homefw httpproxy[31262]: Integrated HTTP-Proxy (c) 2007-2016 Sophos Ltd, Release 547.g1f8aab75.rb3
2018:12:09-20:00:13 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="confd_config_reload_func" file="confd-client.c" line="587" message="reloading config"
2018:12:09-20:00:13 homefw URID[30928]: T=30928 ------ 1 - [exit] SIGTERM: exiting
2018:12:09-20:00:13 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="parse_address" file="util.c" line="540" message="getaddrinfo: passthrough6.fw-notify.net: Name or service not known"
2018:12:09-20:00:13 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="confd_config_filter" file="confd-client.c" line="3859" message="failed to resolve passthrough6.fw-notify.net, using 2a01:198:200:680::8080"
2018:12:09-20:00:14 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="epoll_loop" file="epoll.c" line="861" message="starting exit cleanup"
2018:12:09-20:00:14 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="confd_config_reload_func" file="confd-client.c" line="651" message="reloading config done, new version 119"
2018:12:09-20:00:14 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scan_exit" file="scanner.c" line="943" message="scanner subsystem shutting down"
2018:12:09-20:00:20 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scan_exit" file="scanner.c" line="949" message="scanner subsystem shut down"
2018:12:09-20:00:20 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="epoll_exit" file="epoll.c" line="681" message="epoll subsystem shutting down"
2018:12:09-20:00:20 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="epoll_exit" file="epoll.c" line="698" message="epoll subsystem shut down"
2018:12:09-20:00:20 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="disk_cache_release_cache" file="diskcache.c" line="407" message="writing cache index"
2018:12:09-20:00:20 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="disk_cache_release_cache" file="diskcache.c" line="409" message="writing cache index done"
2018:12:09-20:00:20 homefw httpproxy[31262]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="404" message="shutdown finished, exiting"


This thread was automatically locked due to age.
Parents
  • Hi Wayland and welcome to the UTM Community!

    This is just a WAG - try rebuilding you PostgreSQL databases.  This will erase history in reporting and graphs but will not affect your logs:

    /etc/init.d/postgresql92 rebuild

    Any luck with that?

    Cheers - Bob

     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
Reply
  • Hi Wayland and welcome to the UTM Community!

    This is just a WAG - try rebuilding you PostgreSQL databases.  This will erase history in reporting and graphs but will not affect your logs:

    /etc/init.d/postgresql92 rebuild

    Any luck with that?

    Cheers - Bob

     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
Children
  • Thanks for the welcome!

     

    Just gave it a shot and turned web protection back on.   Logs certainly seem a little different starting up so maybe that does the trick.

     

    2018:12:10-19:51:46 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="285" message="reading configuration"
    2018:12:10-19:51:47 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="parse_address" file="util.c" line="540" message="getaddrinfo: passthrough6.fw-notify.net: Name or service not known"
    2018:12:10-19:51:47 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="confd_config_filter" file="confd-client.c" line="3859" message="failed to resolve passthrough6.fw-notify.net, using 2a01:198:200:680::8080"
    2018:12:10-19:51:47 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="311" message="caching templates"
    2018:12:10-19:51:47 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="314" message="reading profiles"
    2018:12:10-19:51:47 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="disk_cache_read" file="diskcache.c" line="1765" message="calculated md5sum: [D41D8CD98F00B204E9800998ECF8427E], file md5sum: [D41D8CD98F00B204E9800998ECF8427E]"
    2018:12:10-19:51:50 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scanner_init" file="aptpscanner.c" line="185" message="ATP loaded"
    2018:12:10-19:52:22 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="scanner_init" file="saviscanner.c" line="514" message="Successfully loaded SAVI threat data, engine 3.74.0, threat data 5.56 from 16/10/2018 (25804084 detected threats)"
    2018:12:10-19:52:22 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="libnavl_log" file="navl_externals_posix.c" line="43" message="E: InitInstance: Error initializing instance of plugin HPACK_UTIL"
    2018:12:10-19:52:22 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="354" message="notifiying argos daemon"
    2018:12:10-19:52:22 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="argos_notify" file="httpproxy.c" line="209" message="connect: Connection refused"
    2018:12:10-19:52:22 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="main" file="httpproxy.c" line="360" message="finished startup"
    2018:12:10-19:52:22 homefw httpproxy[4374]: Integrated HTTP-Proxy (c) 2007-2016 Sophos Ltd, Release 547.g1f8aab75.rb3
    2018:12:10-19:52:39 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="http_parser_context_execute" file="http_parser_context.c" line="97" message="Unable to parse a http message of 160 bytes (HPE_INVALID_METHOD: invalid HTTP method)"
    2018:12:10-19:52:39 homefw httpproxy[4374]: id="0003" severity="info" sys="SecureWeb" sub="http" request="0x9fa8d600" function="read_request_headers" file="request.c" line="1590" message="unable to parse a http message on handler 102 (Resource temporarily unavailable)"