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

7.402 http proxy going mad (hangs)

Hi,

we do have the following problem:

the HTTP Proxy will stop working after some hours (sometimes it's a few days). The result is this:

The proxy comsumes > 99% CPU time (top), the load of the machine goes up to 53 !! (uptime) and new TCP Sessions to port 8080 will see a RESET (sniffed at the firewall).

We disabled almost all options that could have caused the problem (except AV scanning). Same problem. 

After a restart of the proxy (/var/mdw/scripts/httpproxy restart), the proxy runs fine and with good performance for a couple of hours/days. Then the same game starts again.

If the proxy hangs, there are no more log entries in /var/log/http.log, except these:

2009:04:29-15:04:42 astaro-2 httpproxy[5377]: [     (nil)] sc_check_servers (scr_scanner.c:722) server 'cffs01.astaro.com' access time: 23ms
2009:04:29-15:04:42 astaro-2 httpproxy[5377]: [     (nil)] sc_check_servers (scr_scanner.c:722) server 'cffs02.astaro.com' access time: 32ms
etc.

We did some log analysis to check if the problem is caused by some clients or too much requests. However, there are very few requests per second (5-10), when the problem occurs and just a few clients active (1-5).

We are not able to identify any hardware problem as the problem source and suspect it could be a problem with the proxy software itself (bug). But then we wonder, why there are not more reports about such a problem.

Any idea how to troubleshoot this issue or what it could cause? Remember, the proxy does not accept new connections when it goes mad, but it runs at > 99% cpu time and causes a load of 53 !! on the machine. WHAT the hell is it doing???

Thanks
Al Gorithm


This thread was automatically locked due to age.
Parents
  • Al, what version of software?  What hardware?

    What do you see in the packet filter log when this happens?

    Do you have IPS enabled?

    Cheers - Bob
     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA


  • Al, what version of software?  What hardware?
    What do you see in the packet filter log when this happens?
    Do you have IPS enabled?
    Cheers - Bob


    Software: 7.402 (Problem since 7.4x)
    Hardware: Own server with AMD Opteron, 2 GHz, 3 GByte RAM
    Packet filter Logs: Nothing special, just a few (20-30) dropped packets (nbname, nbsession, etc.)
    IPS: No

    EDIT: Forgot to mention. It is a HA setup.

    Cheers
    Al Gorithm
  • I'm confused by "a load of 53 !! on the machine" as I don't see a "load" measure on my Executive Report.

    The HA might be an issue, is there anything unusual in the HA log at the time the lockup occurs.  Can you confirm that the HA connection is via gigabit Ethernet?

    The next time this occurs, ssh into the box and run top then press M (uppercase) to see what processes are going crazy.
     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
  • Bob, I think he's measuring the Load by going into the shell and running TOP.

    CTO, Convergent Information Security Solutions, LLC

    https://www.convergesecurity.com

    Advice given as posted on this forum does not construe a support relationship or other relationship with Convergent Information Security Solutions, LLC or its subsidiaries.  Use the advice given at your own risk.

  • I'm confused by "a load of 53 !! on the machine" as I don't see a "load" measure on my Executive Report.


    the command "uptime" show the load on a unix system. A Load of 53 is "insane". Acceptable values on a highly loaded system are ~5 - 10.


    The HA might be an issue, is there anything unusual in the HA log at the time the lockup occurs.  Can you confirm that the HA connection is via gigabit Ethernet?


    Yes, Gigabit. But why whould that matter? It is a HA (Active - Passive) cluster not an Active-Active cluster. So, there should be no load distribution via the heartbeat link.


    The next time this occurs, ssh into the box and run top then press M (uppercase) to see what processes are going crazy.


    As I mentioned it is only httpproxy, seen with top, ~99.x % CPU time.

    Running strace on the process id shows, that the process is still reading and writing to some handles (could be sockets), however tcpdump shows, that new sessions are not accepted (TCP Reset) and there is almost no traffic on port 8080 when the http proxy is in that state, so I wonder what the proxy is reading and writing, if there is no traffic on the proxy port. Unfortunately, at the time when I run strace, the handles are already open and I cannot see if they are sockets or files.

    Regards
    Al
  • I did some further research and figured out, that the whole problem started on 22.04.2009. I can see the following messages in the HA log since then.

    2009:04:23-08:20:28 astaro-2 ha_daemon[3196]: id="38A1" severity="warn" sys="System" sub="ha" name="Current load average 23.44 is to high, warning 2 of 15 before switching to slave mode!"

    On the same day, the system.log shows a lot of errors from the postgres database. 


    2009:04:22-11:47:50 astaro-1 postgres[27998]: [3-1] ERROR:  Slony-I: Table pfilter is replicated and cannot be modified on a subscriber node
    
    2009:04:22-11:47:50 astaro-1 postgres[27998]: [3-2] STATEMENT:  INSERT INTO pfilter (dayabs, srcip, srccountry, dstip, dstcountry, svc, packets) VALUES ($1,$2,$3,$4,$5,$6,$7
    )
    2009:04:22-11:47:50 astaro-1 postgres[27998]: [4-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2009:04:22-11:47:50 astaro-1 postgres[27998]: [4-2] STATEMENT:  INSERT INTO pfilter (dayabs, srcip, srccountry, dstip, dstcountry, svc, packets) VALUES ($1,$2,$3,$4,$5,$6,$7
    )


    2009:04:22-12:38:43 astaro postgres[31288]: [4-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2009:04:22-12:38:43 astaro postgres[31290]: [3-3]  mailcount, mailsize) VALUES ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13)
    2009:04:22-12:38:43 astaro postgres[31291]: [7-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2009:04:22-12:38:43 astaro postgres[31288]: [4-2] STATEMENT:  INSERT INTO pfilter (dayabs, srcip, srccountry, dstip, dstcountry, svc, packets) VALUES ($1,$2,$3,$4,$5,$6,$7)
    2009:04:22-12:38:43 astaro postgres[31291]: [7-2] STATEMENT:  INSERT INTO websec_au (dayabs, secabs, clientip, clientusername, duration, transfer, requests) VALUES
    2009:04:22-12:38:43 astaro postgres[31288]: [5-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2009:04:22-12:38:43 astaro postgres[31291]: [7-3]  ($1,$2,$3,$4,$5,$6,$7)


    etc.

    Is there a direct connection of the http proxy to the database, i.e. will the proxy write any statistics directly to the database? If so, I suspect this connection (and possibly a broken database), to generate the failure of the proxy. 

    Is there a supported way to re-initialize the database part, that is needed by the proxy? 

    Thanks
    Al
Reply
  • I did some further research and figured out, that the whole problem started on 22.04.2009. I can see the following messages in the HA log since then.

    2009:04:23-08:20:28 astaro-2 ha_daemon[3196]: id="38A1" severity="warn" sys="System" sub="ha" name="Current load average 23.44 is to high, warning 2 of 15 before switching to slave mode!"

    On the same day, the system.log shows a lot of errors from the postgres database. 


    2009:04:22-11:47:50 astaro-1 postgres[27998]: [3-1] ERROR:  Slony-I: Table pfilter is replicated and cannot be modified on a subscriber node
    
    2009:04:22-11:47:50 astaro-1 postgres[27998]: [3-2] STATEMENT:  INSERT INTO pfilter (dayabs, srcip, srccountry, dstip, dstcountry, svc, packets) VALUES ($1,$2,$3,$4,$5,$6,$7
    )
    2009:04:22-11:47:50 astaro-1 postgres[27998]: [4-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2009:04:22-11:47:50 astaro-1 postgres[27998]: [4-2] STATEMENT:  INSERT INTO pfilter (dayabs, srcip, srccountry, dstip, dstcountry, svc, packets) VALUES ($1,$2,$3,$4,$5,$6,$7
    )


    2009:04:22-12:38:43 astaro postgres[31288]: [4-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2009:04:22-12:38:43 astaro postgres[31290]: [3-3]  mailcount, mailsize) VALUES ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13)
    2009:04:22-12:38:43 astaro postgres[31291]: [7-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2009:04:22-12:38:43 astaro postgres[31288]: [4-2] STATEMENT:  INSERT INTO pfilter (dayabs, srcip, srccountry, dstip, dstcountry, svc, packets) VALUES ($1,$2,$3,$4,$5,$6,$7)
    2009:04:22-12:38:43 astaro postgres[31291]: [7-2] STATEMENT:  INSERT INTO websec_au (dayabs, secabs, clientip, clientusername, duration, transfer, requests) VALUES
    2009:04:22-12:38:43 astaro postgres[31288]: [5-1] ERROR:  current transaction is aborted, commands ignored until end of transaction block
    2009:04:22-12:38:43 astaro postgres[31291]: [7-3]  ($1,$2,$3,$4,$5,$6,$7)


    etc.

    Is there a direct connection of the http proxy to the database, i.e. will the proxy write any statistics directly to the database? If so, I suspect this connection (and possibly a broken database), to generate the failure of the proxy. 

    Is there a supported way to re-initialize the database part, that is needed by the proxy? 

    Thanks
    Al
Children
No Data