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

Temporary 100% CPU Load - How to Identify Root Cause?

Hello Folks,

This is the situation:
From time to time (on a day/in a week) our Astaro ASG320 v.8.202 runs on 100% CPU. All inhouse Internet traffic is very slow then and users are complaining.

RAM is usually ~60% used, SWAP ~30% and Log and Data Disk have enough space.

Using the console and the "top" command it shows me among other information:


  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND

19658 postgres  20   0 52616  35m  32m S 52.8  3.5   0:01.95 postgres

 4323 httpprox  20   0 1268m 288m 5048 S  38.6 28.7 432:21.06 httpproxy

These values differ. Sometimes the postgres and the httpproxy have a CPU load of 30-70% even. But everytime its these both services using most of the Astaro's device performance.

I GUESS someone causes some overload within the network.
I cannot figure out where from or who is doing so.
The users use the webfilter proxy to browse through the Internet.
Having the webfilter live log running there is nothing suspicious during those "slow" times.

We are using an Online Hard Disk service by Strato by the way. Users upload and download data mostly using a https (WebDAV) connection therefore.
The webfilter does NOT scan HTTPS traffic.

How can I identify and SOLVE the root cause of this 100% CPU load problem?

Thank you in advance!!
Regards,
Uwe

* * *

PS: Today this situation is happening very often! :-(

PPS: I cannot say that for sure but I think the following (and similar) webfilter live log lines occur when the CPU is on 100%:

2012:01:11-15:10:59 disgwac httpproxy[4323]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_handle_cmd" file="scr_scanner.c" line="510" message="cffs11.astaro.com: write: Connection refused"



2012:01:11-15:15:03 disgwac httpproxy[4323]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="confd_config_reload_func" file="confd-client.c" line="757" message="reloading config done, new version 25231"

2012:01:11-15:15:03 disgwac httpproxy[4323]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="confd_config_reload_func" file="confd-client.c" line="722" message="reloading config"



2012:01:11-15:15:14 disgwac httpproxy[4323]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_check_servers" file="scr_scanner.c" line="721" message="server 'cffs13.astaro.com' access time: 296ms"



012:01:11-15:45:55 disgwac httpproxy[4323]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_check_servers" file="scr_scanner.c" line="721" message="server 'cffs10.astaro.com' access time: 706ms"

2012:01:11-15:45:55 disgwac httpproxy[4323]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_check_servers" file="scr_scanner.c" line="721" message="server 'cffs12.astaro.com' access time: 99ms"

2012:01:11-15:45:55 disgwac httpproxy[4323]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_handle_cmd" file="scr_scanner.c" line="510" message="cffs01.astaro.com: write: Connection refused"

2012:01:11-15:45:56 disgwac httpproxy[4323]: id="0003" severity="info" sys="SecureWeb" sub="http" request="(nil)" function="sc_check_servers" file="scr_scanner.c" line="721" message="server 'cffs06.astaro.com' access time: 419ms"

This thread was automatically locked due to age.

Parents

0 UweT over 13 years ago

Update:

The 100% CPU load problem occurs again :-(


top - 09:59:50 up 17:44,  1 user,  load average: 4.70, 4.00, 3.08
Tasks: 132 total,   5 running, 125 sleeping,   0 stopped,   2 zombie
Cpu(s): 71.6%us, 16.8%sy,  0.0%ni,  0.0%id,  0.0%wa,  1.7%hi,  9.9%si,  0.0%st
Mem:   1027696k total,   941756k used,    85940k free,    21904k buffers
Swap:  1052248k total,   224860k used,   827388k free,   246732k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 8913 postgres  20   0 50544 7504 5568 R 27.4  0.7   2:00.22 postgres
 6268 snort     19  -1  144m  86m 1224 R 23.8  8.6  15:41.25 snort_inline
20421 wwwrun    20   0 99800  60m 1864 R 14.2  6.0   4:53.55 index.plx
23027 httpprox  20   0 1204m 231m 5388 S 13.9 23.1  11:00.17 httpproxy
(...)

That is inacceptable.

0 UweT over 13 years ago in reply to UweT

I have deactivated the PostgreSQL process via SSH and that command:

/etc/init.d/postgresql stop

Although it shows peaks which I wonder about CPU % is around 40-50% then.


top - 11:19:19 up 19:03,  1 user,  load average: 1.00, 1.88, 2.56
Tasks: 122 total,   1 running, 119 sleeping,   0 stopped,   2 zombie
Cpu(s): 15.6%us,  4.3%sy,  0.0%ni, 78.4%id,  0.3%wa,  0.3%hi,  1.0%si,  0.0%st
Mem:   1027696k total,   943504k used,    84192k free,    47908k buffers
Swap:  1052248k total,   252656k used,   799592k free,   321480k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
23027 httpprox  20   0 1210m 171m 5744 S  9.6 17.1  20:13.37 httpproxy
26504 root      20   0 18812  10m 2992 S  5.0  1.1   0:01.56 websec-reporter
 5937 root      20   0  6964 2660 1104 S  2.0  0.3   6:41.79 syslog-ng
 6268 snort     19  -1  147m  91m 1208 S  2.0  9.1  22:07.55 snort_inline

Webfilter Live log is still visible. Is this data being saved although i stopped the reporting service?

By the way:
What exactly does the PostgreSQL service do?

* * *

I wonder why this is happening: 68% CPU load for the httpproxy process:


top - 11:22:02 up 19:06,  1 user,  load average: 2.69, 2.06, 2.49
Tasks: 119 total,   2 running, 113 sleeping,   0 stopped,   4 zombie
Cpu(s): 79.9%us, 11.2%sy,  0.3%ni,  0.0%id,  0.0%wa,  1.3%hi,  7.3%si,  0.0%st
Mem:   1027696k total,   896484k used,   131212k free,    45472k buffers
Swap:  1052248k total,   259548k used,   792700k free,   283564k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
23027 httpprox  20   0 1212m 167m 5868 S 58.8 16.7  20:42.19 httpproxy
22879 wwwrun    20   0 69088  65m 8544 R 12.4  6.5   1:03.42 index.plx
 6268 snort     19  -1  148m  91m 1208 S  6.5  9.2  22:15.82 snort_inline
26504 root      20   0 18812  10m 2992 S  5.9  1.1   0:08.75 websec-reporter
22883 root      20   0 52484  23m 2800 S  4.9  2.3   0:25.23 confd.plx

0 UweT over 13 years ago in reply to UweT

Can I reinitalize the DB with these commands?:

/etc/init.d/postgresql stop

rm -fr /var/log/reporting/pgsql

/etc/init.d/postgresql start

mkdir /var/log/reporting/pgsql

chown postgres[:P]ostgres /var/log/reporting/pgsql

/var/storage/pgsql/init/reporting_db_init.sh -v

Reply

0 UweT over 13 years ago in reply to UweT

Can I reinitalize the DB with these commands?:

/etc/init.d/postgresql stop

rm -fr /var/log/reporting/pgsql

/etc/init.d/postgresql start

mkdir /var/log/reporting/pgsql

chown postgres[:P]ostgres /var/log/reporting/pgsql

/var/storage/pgsql/init/reporting_db_init.sh -v

Children

No Data