Re: 100% CPU utilization by mod_authz_svn

2023-12-28 Thread Nathan Hartman
On Fri, Dec 22, 2023 at 6:23 AM radek.krotil.siemens.com via users <
users@subversion.apache.org> wrote:

> Hi SVN Community.
>
>
>
> I’d like to consult a problem with occasional high CPU utilization by
> mod_authz_svn. Please, do CC me and my colleague in the response, because
> we are subscribed to the list.
>
>
>
> Our Java application uses Subversion as a primary data storage and the SVN
> data are being accessed via Apache HTTPD mod_dav_svn and also by svnserve
> server on top of the same repository.
>
>
>
> We are facing a problem in one of our productive environments hosted in
> AWS. The server is running RHEL 8.8, Apache 2.4.37 with SVN 1.14.1
> binaries. Occasionally, the Apache HTTPD is acting strange, utilizing 100%
> CPU for periods of minutes to tens of minutes. This situation happens
> several times a week and causes delayed responses from the SVN server up to
> several minutes. Similar behavior is visible on several httpd server
> processes (mpm_event module is used), where each of them has tens of active
> requests being processed. When this CPU spike occurs, there several Apache
> HTTPD server processes with tens of threads busy in the following code
> related to the Subversion ACL.
>
>
>
> The access file is quite big. It contains about 2 group definitions
> with roughly 1 users assigned to them and about 35000 authorization
> rules for 15000 paths, and it’s size is over 5 MB. The access file is
> getting changed 100 times a day, but the CPU spikes do not correlate with
> the CPU spikes.
>
>
>
> Initially we suspected filesystem issues, but we were not able to confirm
> them. When the spike occurs, CPU I/O wait goes to zero and all the CPU is
> consumed in user space.
>
>
>
> We are looking for suggestions how to further troubleshoot the problem, or
> possible confirmation that this is a Subversion bug or inefficiency.
>
>
>
> Thank you,
>
> Radek Krotil
>
> Siemens Digital Industries Software
>
>
>
>
>
> *Pstack output example*
>
> Thread 127 (Thread 0x7f0003fcf700 (LWP 2934729)):
>
>
>
> #0  0x7f0049b79b60 in svn_authz.get_acl_access () from
> target:/lib64/libsvn_repos-1.so.0
>
> #1  0x7f0049b7a864 in update_user_rights () from
> target:/lib64/libsvn_repos-1.so.0
>
> #2  0x7f0048e35d06 in hash_do_callback () from
> target:/lib64/libsvn_subr-1.so.0
>
> #3  0x7f0058bc8ebe in apr_hash_do () from target:/lib64/libapr-1.so.0
>
> #4  0x7f0048e35d6a in svn_iter_apr_hash () from
> target:/lib64/libsvn_subr-1.so.0
>
> #5  0x7f0049b7a7b4 in expand_acl_callback () from
> target:/lib64/libsvn_repos-1.so.0
>
> #6  0x7f0048e35e41 in svn_iter_apr_array () from
> target:/lib64/libsvn_subr-1.so.0
>
> #7  0x7f0049b7c109 in svn_authz.parse () from
> target:/lib64/libsvn_repos-1.so.0
>
> #8  0x7f0049b78f74 in svn_repos_authz_read4 () from
> target:/lib64/libsvn_repos-1.so.0
>
> #9  0x7f004845e4a3 in get_access_conf () from
> target:/etc/httpd/modules/mod_authz_svn.so
>
> #10 0x7f004845e705 in req_check_access () from
> target:/etc/httpd/modules/mod_authz_svn.so
>
> #11 0x7f004845efd6 in auth_checker () from
> target:/etc/httpd/modules/mod_authz_svn.so
>
> #12 0x561c8b0724c8 in ap_run_auth_checker ()
>
> #13 0x561c8b074a9c in ap_process_request_internal ()
>
> #14 0x561c8b093a70 in ap_process_async_request ()
>
> #15 0x561c8b08fed0 in ap_process_http_connection ()
>
> #16 0x561c8b0862b8 in ap_run_process_connection ()
>
> #17 0x7f004d6b9a47 in process_socket () from
> target:/etc/httpd/modules/mod_mpm_event.so
>
> #18 0x7f004d6ba3ea in worker_thread () from
> target:/etc/httpd/modules/mod_mpm_event.so
>
> #19 0x7f005899a1ca in start_thread () from
> target:/lib64/libpthread.so.0
>
> #20 0x7f0058402e73 in clone () from target:/lib64/libc.so.6
>
>
>
>
>
> *TOP output looks as follows*
>
> top - 13:00:01 up 15 days,  7:09,  0 users,  load average: 129.31, 100.24,
> 53.38
>
> Tasks: 241 total,   7 running, 233 sleeping,   0 stopped,   1 zombie
>
> %Cpu(s): 95.6 us,  3.7 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.7 hi,  0.0
> si,  0.0 st
>
> MiB Mem : 126914.0 total,  55179.2 free,  20765.8 used,  50969.0 buff/cache
>
> MiB Swap:  0.0 total,  0.0 free,  0.0 used. 104540.6 avail Mem
>
>
>
> PID USER  PR  NIVIRTRESSHR S  %CPU  %MEM TIME+
> COMMAND
>
>  233319 apache20   0 5818164   2.9g  13844 S 456.2   2.3 183:35.14
> httpd
>
>  233318 apache20   0 5751168   2.7g  13844 S 443.8   2.2 127:53.12
> httpd
>
>  232848 apache20   0 5226028   2.0g  13844 S 218.8   1.6  46:08.83
> httpd
>
>  232849 apache20   0 5291384   2.1g  13804 S 168.8   1.7  68:34.92
> httpd
>
>  232847 apache20   0 5291628   1.7g  13908 S 137.5   1.4  39:14.61
> httpd
>
>
>
> *And Apache server status clearly shows the number of “stuck” requests*
>
> Apache Server Status for localhost (via ::1)
>
> Server Version: Apache/2.4.37 (Red Hat Enterprise Linux) OpenSSL/1.1.1k
> SVN/1.14.1
>
> Server MPM: event
>
> 

Re: 100% CPU utilization by mod_authz_svn

2023-12-22 Thread Daniel Sahlberg
Den fre 22 dec. 2023 kl 12:22 skrev radek.krotil.siemens.com via users <
users@subversion.apache.org>:

> Hi SVN Community.
>
>
>
> I’d like to consult a problem with occasional high CPU utilization by
> mod_authz_svn. Please, do CC me and my colleague in the response, because
> we are subscribed to the list.
>
>
>
> Our Java application uses Subversion as a primary data storage and the SVN
> data are being accessed via Apache HTTPD mod_dav_svn and also by svnserve
> server on top of the same repository.
>
>
>
> We are facing a problem in one of our productive environments hosted in
> AWS. The server is running RHEL 8.8, Apache 2.4.37 with SVN 1.14.1
> binaries. Occasionally, the Apache HTTPD is acting strange, utilizing 100%
> CPU for periods of minutes to tens of minutes. This situation happens
> several times a week and causes delayed responses from the SVN server up to
> several minutes. Similar behavior is visible on several httpd server
> processes (mpm_event module is used), where each of them has tens of active
> requests being processed. When this CPU spike occurs, there several Apache
> HTTPD server processes with tens of threads busy in the following code
> related to the Subversion ACL.
>
>
>
> The access file is quite big. It contains about 2 group definitions
> with roughly 1 users assigned to them and about 35000 authorization
> rules for 15000 paths, and it’s size is over 5 MB. The access file is
> getting changed 100 times a day, but the CPU spikes do not correlate with
> the CPU spikes.
>
>
>
> Initially we suspected filesystem issues, but we were not able to confirm
> them. When the spike occurs, CPU I/O wait goes to zero and all the CPU is
> consumed in user space.
>
>
>
> We are looking for suggestions how to further troubleshoot the problem, or
> possible confirmation that this is a Subversion bug or inefficiency.
>
>
>
> Thank you,
>
> Radek Krotil
>
> Siemens Digital Industries Software
>
>
>
>
>
> *Pstack output example*
>
> Thread 127 (Thread 0x7f0003fcf700 (LWP 2934729)):
>
>
>
> #0  0x7f0049b79b60 in svn_authz.get_acl_access () from
> target:/lib64/libsvn_repos-1.so.0
>
> #1  0x7f0049b7a864 in update_user_rights () from
> target:/lib64/libsvn_repos-1.so.0
>
> #2  0x7f0048e35d06 in hash_do_callback () from
> target:/lib64/libsvn_subr-1.so.0
>
> #3  0x7f0058bc8ebe in apr_hash_do () from target:/lib64/libapr-1.so.0
>
> #4  0x7f0048e35d6a in svn_iter_apr_hash () from
> target:/lib64/libsvn_subr-1.so.0
>
> #5  0x7f0049b7a7b4 in expand_acl_callback () from
> target:/lib64/libsvn_repos-1.so.0
>
> #6  0x7f0048e35e41 in svn_iter_apr_array () from
> target:/lib64/libsvn_subr-1.so.0
>
> #7  0x7f0049b7c109 in svn_authz.parse () from
> target:/lib64/libsvn_repos-1.so.0
>
> #8  0x7f0049b78f74 in svn_repos_authz_read4 () from
> target:/lib64/libsvn_repos-1.so.0
>
> #9  0x7f004845e4a3 in get_access_conf () from
> target:/etc/httpd/modules/mod_authz_svn.so
>
> #10 0x7f004845e705 in req_check_access () from
> target:/etc/httpd/modules/mod_authz_svn.so
>
> #11 0x7f004845efd6 in auth_checker () from
> target:/etc/httpd/modules/mod_authz_svn.so
>
> #12 0x561c8b0724c8 in ap_run_auth_checker ()
>
> #13 0x561c8b074a9c in ap_process_request_internal ()
>
> #14 0x561c8b093a70 in ap_process_async_request ()
>
> #15 0x561c8b08fed0 in ap_process_http_connection ()
>
> #16 0x561c8b0862b8 in ap_run_process_connection ()
>
> #17 0x7f004d6b9a47 in process_socket () from
> target:/etc/httpd/modules/mod_mpm_event.so
>
> #18 0x7f004d6ba3ea in worker_thread () from
> target:/etc/httpd/modules/mod_mpm_event.so
>
> #19 0x7f005899a1ca in start_thread () from
> target:/lib64/libpthread.so.0
>
> #20 0x7f0058402e73 in clone () from target:/lib64/libc.so.6
>
>
>
>
>
> *TOP output looks as follows*
>
> top - 13:00:01 up 15 days,  7:09,  0 users,  load average: 129.31, 100.24,
> 53.38
>
> Tasks: 241 total,   7 running, 233 sleeping,   0 stopped,   1 zombie
>
> %Cpu(s): 95.6 us,  3.7 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.7 hi,  0.0
> si,  0.0 st
>
> MiB Mem : 126914.0 total,  55179.2 free,  20765.8 used,  50969.0 buff/cache
>
> MiB Swap:  0.0 total,  0.0 free,  0.0 used. 104540.6 avail Mem
>
>
>
> PID USER  PR  NIVIRTRESSHR S  %CPU  %MEM TIME+
> COMMAND
>
>  233319 apache20   0 5818164   2.9g  13844 S 456.2   2.3 183:35.14
> httpd
>
>  233318 apache20   0 5751168   2.7g  13844 S 443.8   2.2 127:53.12
> httpd
>
>  232848 apache20   0 5226028   2.0g  13844 S 218.8   1.6  46:08.83
> httpd
>
>  232849 apache20   0 5291384   2.1g  13804 S 168.8   1.7  68:34.92
> httpd
>
>  232847 apache20   0 5291628   1.7g  13908 S 137.5   1.4  39:14.61
> httpd
>
>
>
> *And Apache server status clearly shows the number of “stuck” requests*
>
> Apache Server Status for localhost (via ::1)
>
> Server Version: Apache/2.4.37 (Red Hat Enterprise Linux) OpenSSL/1.1.1k
> SVN/1.14.1
>
> Server MPM: event
>
> 

100% CPU utilization by mod_authz_svn

2023-12-22 Thread radek.krotil.siemens.com via users
Hi SVN Community.

I’d like to consult a problem with occasional high CPU utilization by 
mod_authz_svn. Please, do CC me and my colleague in the response, because we 
are subscribed to the list.

Our Java application uses Subversion as a primary data storage and the SVN data 
are being accessed via Apache HTTPD mod_dav_svn and also by svnserve server on 
top of the same repository.

We are facing a problem in one of our productive environments hosted in AWS. 
The server is running RHEL 8.8, Apache 2.4.37 with SVN 1.14.1 binaries. 
Occasionally, the Apache HTTPD is acting strange, utilizing 100% CPU for 
periods of minutes to tens of minutes. This situation happens several times a 
week and causes delayed responses from the SVN server up to several minutes. 
Similar behavior is visible on several httpd server processes (mpm_event module 
is used), where each of them has tens of active requests being processed. When 
this CPU spike occurs, there several Apache HTTPD server processes with tens of 
threads busy in the following code related to the Subversion ACL.

The access file is quite big. It contains about 2 group definitions with 
roughly 1 users assigned to them and about 35000 authorization rules for 
15000 paths, and it’s size is over 5 MB. The access file is getting changed 100 
times a day, but the CPU spikes do not correlate with the CPU spikes.

Initially we suspected filesystem issues, but we were not able to confirm them. 
When the spike occurs, CPU I/O wait goes to zero and all the CPU is consumed in 
user space.

We are looking for suggestions how to further troubleshoot the problem, or 
possible confirmation that this is a Subversion bug or inefficiency.

Thank you,
Radek Krotil
Siemens Digital Industries Software


Pstack output example
Thread 127 (Thread 0x7f0003fcf700 (LWP 2934729)):

#0  0x7f0049b79b60 in svn_authz.get_acl_access () from 
target:/lib64/libsvn_repos-1.so.0
#1  0x7f0049b7a864 in update_user_rights () from 
target:/lib64/libsvn_repos-1.so.0
#2  0x7f0048e35d06 in hash_do_callback () from 
target:/lib64/libsvn_subr-1.so.0
#3  0x7f0058bc8ebe in apr_hash_do () from target:/lib64/libapr-1.so.0
#4  0x7f0048e35d6a in svn_iter_apr_hash () from 
target:/lib64/libsvn_subr-1.so.0
#5  0x7f0049b7a7b4 in expand_acl_callback () from 
target:/lib64/libsvn_repos-1.so.0
#6  0x7f0048e35e41 in svn_iter_apr_array () from 
target:/lib64/libsvn_subr-1.so.0
#7  0x7f0049b7c109 in svn_authz.parse () from 
target:/lib64/libsvn_repos-1.so.0
#8  0x7f0049b78f74 in svn_repos_authz_read4 () from 
target:/lib64/libsvn_repos-1.so.0
#9  0x7f004845e4a3 in get_access_conf () from 
target:/etc/httpd/modules/mod_authz_svn.so
#10 0x7f004845e705 in req_check_access () from 
target:/etc/httpd/modules/mod_authz_svn.so
#11 0x7f004845efd6 in auth_checker () from 
target:/etc/httpd/modules/mod_authz_svn.so
#12 0x561c8b0724c8 in ap_run_auth_checker ()
#13 0x561c8b074a9c in ap_process_request_internal ()
#14 0x561c8b093a70 in ap_process_async_request ()
#15 0x561c8b08fed0 in ap_process_http_connection ()
#16 0x561c8b0862b8 in ap_run_process_connection ()
#17 0x7f004d6b9a47 in process_socket () from 
target:/etc/httpd/modules/mod_mpm_event.so
#18 0x7f004d6ba3ea in worker_thread () from 
target:/etc/httpd/modules/mod_mpm_event.so
#19 0x7f005899a1ca in start_thread () from target:/lib64/libpthread.so.0
#20 0x7f0058402e73 in clone () from target:/lib64/libc.so.6


TOP output looks as follows

top - 13:00:01 up 15 days,  7:09,  0 users,  load average: 129.31, 100.24, 53.38
Tasks: 241 total,   7 running, 233 sleeping,   0 stopped,   1 zombie
%Cpu(s): 95.6 us,  3.7 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.7 hi,  0.0 si,  0.0 st
MiB Mem : 126914.0 total,  55179.2 free,  20765.8 used,  50969.0 buff/cache
MiB Swap:  0.0 total,  0.0 free,  0.0 used. 104540.6 avail Mem

PID USER  PR  NIVIRTRESSHR S  %CPU  %MEM TIME+ COMMAND
 233319 apache20   0 5818164   2.9g  13844 S 456.2   2.3 183:35.14 httpd
 233318 apache20   0 5751168   2.7g  13844 S 443.8   2.2 127:53.12 httpd
 232848 apache20   0 5226028   2.0g  13844 S 218.8   1.6  46:08.83 httpd
 232849 apache20   0 5291384   2.1g  13804 S 168.8   1.7  68:34.92 httpd
 232847 apache20   0 5291628   1.7g  13908 S 137.5   1.4  39:14.61 httpd

And Apache server status clearly shows the number of “stuck” requests
Apache Server Status for localhost (via ::1)
Server Version: Apache/2.4.37 (Red Hat Enterprise Linux) OpenSSL/1.1.1k 
SVN/1.14.1
Server MPM: event
Server Built: Aug 17 2023 10:52:25

Current Time: Monday, 18-Dec-2023 13:00:01 UTC
Restart Time: Saturday, 16-Dec-2023 05:23:02 UTC
Parent Server Config. Generation: 2
Parent Server MPM Generation: 1
Server uptime: 2 days 7 hours 36 minutes 58 seconds
Server load: 129.31 100.24 53.38
Total accesses: 212201 - Total Traffic: 1.9 GB - Total Duration: 67348142
CPU Usage: