[OpenAFS] Slow loading of virtually hosted web content
Jeffrey E Altman
jaltman@auristor.com
Fri, 19 Nov 2021 21:34:10 -0500
This is a cryptographically signed message in MIME format.
--------------ms080001070806040706080806
Content-Type: multipart/alternative;
boundary="------------O9iAT32RuXs650YQRjLEG3rv"
--------------O9iAT32RuXs650YQRjLEG3rv
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit
On 11/10/2021 3:27 PM, Kendrick Hernandez (kendrick.hernandez@umbc.edu)
wrote:
> Hi all,
>
> We host around 240 departmental and campus web sites (individual afs
> volumes) across 6 virtual web servers on AFS storage. The web servers
> are 4 core, 16G VMs, and the 4 file servers are 4 core 32G VMs. All
> CentOS 7 systems.
>
> In the past week or so, we've encountered high-load on the web servers
> (primary consumers being apache and afsd) during periods of increased
> traffic, and we're trying to identify ways to tune performance.
"In the past week or so" appears to imply that the high-load was not
observed previously. If that is the case, one question to ask is "what
changed?" Analysis of the Apache access and error logs compared to the
prior period might provide some important clues.
> After seeing the following in the logs:
>
> 2021 11 08 08:52:03 -05:00 virthost4 [kern.warning] kernel: afs:
> Warning: We are having trouble keeping the AFS stat cache trimmed
> down under the configured limit (current -stat setting: 3000,
> current vcache usage: 18116).
> 2021 11 08 08:52:03 -05:00 virthost4 [kern.warning] kernel: afs:
> If AFS access seems slow, consider raising the -stat setting for afsd.
>
There is a one-to-one mapping between AFS vnodes and Linux inodes.
Unlike some other platforms with OpenAFS kernel modules, the Linux
kernel module does not strictly enforce the vnode cache (aka vcache)
limit. When the limit is reached instead of finding a vnode to recycle,
new vnodes are created and a background task attempts to prune excess
vnodes. Its that background task which is logging the text quoted above.
> I increased the disk cache to 10g and the -stat parameter to 100000,
> which has improved things somewhat, but we're not quite there yet.
As Ben Kaduk mentioned in his reply, callback promises must be tracked
by both the fileserver and the client. Increasing the vcache (-stat)
limit increases the number of vnodes for which callbacks must be
tracked. The umbc.edu cell is behind a firewall so its not possible for
me to probe the fileserver statistics to determine if increasing to
100,000 on the clients also requires an increase on the fileservers. If
the fileserver callback table is full, then it might have to prematurely
break callback promises to satisfy the new allocation. A callback break
requires issuing an RPC to the client whose promise is being broken.
> This is the current client cache configuration from one of the web
> servers:
>
> Chunk files: 281250
> Stat caches: 100000
> Data caches: 10000
>
The data cache might need to be increased if the web servers are serving
content from more than 18,000 files
>
> Volume caches: 200
>
If the web servers are serving data from 240 volumes, then 200 volumes
is too small.
>
> Chunk size: 1048576
> Cache size: 9000000 kB
> Set time: no
> Cache type: disk
>
>
> Has anyone else experienced this? I think the bottleneck is with the
> cache manager and not the file servers themselves, because they don't
> seem to be impacted much during those periods of high load, and I can
> access files in those web volumes from my local client without any
> noticable lag.
Apart from the cache settings how the web server is configured and how
it accesses content from /afs matters.
* Are the web servers configured with mod_waklog to obtain tokens for
authenticated users?
* Are PAGs in use?
* How many active RX connections are there from the cache manager to the
fileservers?
* Are the volumes being served primarily RW volumes or RO volumes?
* Are the contents of the volumes frequently changing?
Finally, compared to the AuriStorFS and kafs clients, the OpenAFS cache
manager suffers from a number of bottlenecks on multiprocessor systems
due to reliance on a global lock to protect internal data structures.
The cache manager's callback service is another potential bottleneck
because only one incoming RPC can be processed at a time and each
incoming RPC must acquire the aforementioned global lock for the life of
the call.
Good luck,
Jeffrey Altman
--------------O9iAT32RuXs650YQRjLEG3rv
Content-Type: text/html; charset=UTF-8
Content-Transfer-Encoding: 8bit
<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
</head>
<body>
<div class="moz-cite-prefix">On 11/10/2021 3:27 PM, Kendrick
Hernandez (<a class="moz-txt-link-abbreviated" href="mailto:kendrick.hernandez@umbc.edu">kendrick.hernandez@umbc.edu</a>) wrote:<br>
</div>
<blockquote type="cite"
cite="mid:CABWMJQUUa4mHFrTR7jAA8gZ9g9R16PqZ2NZ4Nss0zaDqM6915w@mail.gmail.com">
<meta http-equiv="content-type" content="text/html; charset=UTF-8">
<div dir="ltr">Hi all,
<div><br>
</div>
<div>We host around 240 departmental and campus web sites
(individual afs volumes) across 6 virtual web servers on AFS
storage. The web servers are 4 core, 16G VMs, and the 4 file
servers are 4 core 32G VMs. All CentOS 7 systems. <br>
</div>
<div><br>
</div>
<div>In the past week or so, we've encountered high-load on the
web servers (primary consumers being apache and afsd) during
periods of increased traffic, and we're trying to identify
ways to tune performance. </div>
</div>
</blockquote>
"In the past week or so" appears to imply that the high-load was not
observed previously. If that is the case, one question to ask is
"what changed?" Analysis of the Apache access and error logs
compared to the prior period might provide some important clues.<br>
<blockquote type="cite"
cite="mid:CABWMJQUUa4mHFrTR7jAA8gZ9g9R16PqZ2NZ4Nss0zaDqM6915w@mail.gmail.com">
<div dir="ltr">
<div>After seeing the following in the logs:</div>
<div><br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px
0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><span
style="font-family:monospace">2021 11 08 08:52:03 -05:00
virthost4 [kern.warning] kernel: afs: Warning: We are having
trouble keeping the AFS stat cache trimmed down under the
configured limit (current -stat setting: 3000, current
vcache usage: 18116).</span><br>
<span style="font-family:monospace">2021 11 08 08:52:03 -05:00
virthost4 [kern.warning] kernel: afs: If AFS access seems
slow, consider raising the -stat setting for afsd.</span></blockquote>
</div>
</blockquote>
<p>There is a one-to-one mapping between AFS vnodes and Linux
inodes. Unlike some other platforms with OpenAFS kernel modules,
the Linux kernel module does not strictly enforce the vnode cache
(aka vcache) limit. When the limit is reached instead of finding
a vnode to recycle, new vnodes are created and a background task
attempts to prune excess vnodes. Its that background task which
is logging the text quoted above. <br>
</p>
<blockquote type="cite"
cite="mid:CABWMJQUUa4mHFrTR7jAA8gZ9g9R16PqZ2NZ4Nss0zaDqM6915w@mail.gmail.com">
<div dir="ltr">
<div>I increased the disk cache to 10g and the -stat parameter
to 100000, which has improved things somewhat, but we're not
quite there yet. </div>
</div>
</blockquote>
<p>As Ben Kaduk mentioned in his reply, callback promises must be
tracked by both the fileserver and the client. Increasing the
vcache (-stat) limit increases the number of vnodes for which
callbacks must be tracked. The umbc.edu cell is behind a firewall
so its not possible for me to probe the fileserver statistics to
determine if increasing to 100,000 on the clients also requires an
increase on the fileservers. If the fileserver callback table is
full, then it might have to prematurely break callback promises to
satisfy the new allocation. A callback break requires issuing an
RPC to the client whose promise is being broken.<br>
</p>
<blockquote type="cite"
cite="mid:CABWMJQUUa4mHFrTR7jAA8gZ9g9R16PqZ2NZ4Nss0zaDqM6915w@mail.gmail.com">
<div dir="ltr">
<div>This is the current client cache configuration from one of
the web servers:<br>
</div>
<div><br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px
0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div><span style="font-family:monospace">Chunk files: 281250<br>
Stat caches: 100000</span></div>
<div><span style="font-family:monospace"></span></div>
<span style="font-family:monospace">Data caches: 10000</span><br>
</blockquote>
</div>
</blockquote>
The data cache might need to be increased if the web servers are
serving content from more than 18,000 files<br>
<blockquote type="cite"
cite="mid:CABWMJQUUa4mHFrTR7jAA8gZ9g9R16PqZ2NZ4Nss0zaDqM6915w@mail.gmail.com">
<div dir="ltr">
<blockquote class="gmail_quote" style="margin:0px 0px 0px
0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><span
style="font-family:monospace">Volume caches: 200</span><br>
</blockquote>
</div>
</blockquote>
If the web servers are serving data from 240 volumes, then 200
volumes is too small.<br>
<blockquote type="cite"
cite="mid:CABWMJQUUa4mHFrTR7jAA8gZ9g9R16PqZ2NZ4Nss0zaDqM6915w@mail.gmail.com">
<div dir="ltr">
<blockquote class="gmail_quote" style="margin:0px 0px 0px
0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><span
style="font-family:monospace">Chunk size: 1048576</span><br>
<span style="font-family:monospace">Cache size: 9000000 kB</span><br>
<span style="font-family:monospace">Set time: no</span><br>
<span style="font-family:monospace">Cache type: disk</span></blockquote>
<div><br>
</div>
<div>Has anyone else experienced this? I think the bottleneck is
with the cache manager and not the file servers themselves,
because they don't seem to be impacted much during those
periods of high load, and I can access files in those web
volumes from my local client without any noticable lag. <br>
</div>
</div>
</blockquote>
<p>Apart from the cache settings how the web server is configured
and how it accesses content from /afs matters. <br>
</p>
<p>* Are the web servers configured with mod_waklog to obtain tokens
for authenticated users?</p>
<p>* Are PAGs in use?</p>
<p>* How many active RX connections are there from the cache manager
to the fileservers?</p>
<p>* Are the volumes being served primarily RW volumes or RO
volumes?</p>
<p>* Are the contents of the volumes frequently changing?<br>
</p>
<p>Finally, compared to the AuriStorFS and kafs clients, the OpenAFS
cache manager suffers from a number of bottlenecks on
multiprocessor systems due to reliance on a global lock to protect
internal data structures. The cache manager's callback service is
another potential bottleneck because only one incoming RPC can be
processed at a time and each incoming RPC must acquire the
aforementioned global lock for the life of the call. <br>
</p>
<p>Good luck,</p>
<p>Jeffrey Altman</p>
<p><br>
</p>
</body>
</html>
--------------O9iAT32RuXs650YQRjLEG3rv--
--------------ms080001070806040706080806
Content-Type: application/pkcs7-signature; name="smime.p7s"
Content-Transfer-Encoding: base64
Content-Disposition: attachment; filename="smime.p7s"
Content-Description: S/MIME Cryptographic Signature
MIAGCSqGSIb3DQEHAqCAMIACAQExDzANBglghkgBZQMEAgEFADCABgkqhkiG9w0BBwEAAKCC
DGswggXSMIIEuqADAgECAhBAAW0B1qVVQ32wvx2EXYU6MA0GCSqGSIb3DQEBCwUAMDoxCzAJ
BgNVBAYTAlVTMRIwEAYDVQQKEwlJZGVuVHJ1c3QxFzAVBgNVBAMTDlRydXN0SUQgQ0EgQTEy
MB4XDTE5MDkwNTE0MzE0N1oXDTIyMTEwMTE0MzE0N1owcDEvMC0GCgmSJomT8ixkAQETH0Ew
MTQxMEMwMDAwMDE2RDAxRDZBNTQwMDAwMDQ0NDcxGTAXBgNVBAMTEEplZmZyZXkgRSBBbHRt
YW4xFTATBgNVBAoTDEF1cmlTdG9yIEluYzELMAkGA1UEBhMCVVMwggEiMA0GCSqGSIb3DQEB
AQUAA4IBDwAwggEKAoIBAQCY1TC9QeWnUgEoJ81FcAVnhGn/AWuzvkYRUG5/ZyXDdaM212e8
ybCklgSmZweqNdrfaaHXk9vwjpvpD4YWgb07nJ1QBwlvRV/VPAaDdneIygJJWBCzaMVLttKO
0VimH/I/HUwFBQT2mrktucCEf2qogdi2P+p5nuhnhIUiyZ71Fo43gF6cuXIMV/1rBNIJDuwM
Q3H8zi6GL0p4mZFZDDKtbYq2l8+MNxFvMrYcLaJqejQNQRBuZVfv0Fq9pOGwNLAk19baIw3U
xdwx+bGpTtS63Py1/57MQ0W/ZXE/Ocnt1qoDLpJeZIuEBKgMcn5/iN9+Ro5zAuOBEKg34wBS
8QCTAgMBAAGjggKcMIICmDAOBgNVHQ8BAf8EBAMCBPAwgYQGCCsGAQUFBwEBBHgwdjAwBggr
BgEFBQcwAYYkaHR0cDovL2NvbW1lcmNpYWwub2NzcC5pZGVudHJ1c3QuY29tMEIGCCsGAQUF
BzAChjZodHRwOi8vdmFsaWRhdGlvbi5pZGVudHJ1c3QuY29tL2NlcnRzL3RydXN0aWRjYWEx
Mi5wN2MwHwYDVR0jBBgwFoAUpHPa72k1inXMoBl7CDL4a4nkQuwwCQYDVR0TBAIwADCCASsG
A1UdIASCASIwggEeMIIBGgYLYIZIAYb5LwAGAgEwggEJMEoGCCsGAQUFBwIBFj5odHRwczov
L3NlY3VyZS5pZGVudHJ1c3QuY29tL2NlcnRpZmljYXRlcy9wb2xpY3kvdHMvaW5kZXguaHRt
bDCBugYIKwYBBQUHAgIwga0MgapUaGlzIFRydXN0SUQgQ2VydGlmaWNhdGUgaGFzIGJlZW4g
aXNzdWVkIGluIGFjY29yZGFuY2Ugd2l0aCBJZGVuVHJ1c3QncyBUcnVzdElEIENlcnRpZmlj
YXRlIFBvbGljeSBmb3VuZCBhdCBodHRwczovL3NlY3VyZS5pZGVudHJ1c3QuY29tL2NlcnRp
ZmljYXRlcy9wb2xpY3kvdHMvaW5kZXguaHRtbDBFBgNVHR8EPjA8MDqgOKA2hjRodHRwOi8v
dmFsaWRhdGlvbi5pZGVudHJ1c3QuY29tL2NybC90cnVzdGlkY2FhMTIuY3JsMB8GA1UdEQQY
MBaBFGphbHRtYW5AYXVyaXN0b3IuY29tMB0GA1UdDgQWBBR7pHsvL4H5GdzNToI9e5BuzV19
bzAdBgNVHSUEFjAUBggrBgEFBQcDAgYIKwYBBQUHAwQwDQYJKoZIhvcNAQELBQADggEBAFlm
JYk4Ff1v/n0foZkv661W4LCRtroBaVykOXetrDDOQNK2N6JdTa146uIZVgBeU+S/0DLvJBKY
tkUHQ9ovjXJTsuCBmhIIw3YlHoFxbku0wHEpXMdFUHV3tUodFJJKF3MbC8j7dOMkag59/Mdz
Sjszdvit0av9nTxWs/tRKKtSQQlxtH34TouIke2UgP/Nn901QLOrJYJmtjzVz8DW3IYVxfci
SBHhbhJTdley5cuEzphELo5NR4gFjBNlxH7G57Hno9+EWILpx302FJMwTgodIBJbXLbPMHou
xQbOL2anOTUMKO8oH0QdQHCtC7hpgoQa7UJYJxDBI+PRaQ/HObkwggaRMIIEeaADAgECAhEA
+d5Wf8lNDHdw+WAbUtoVOzANBgkqhkiG9w0BAQsFADBKMQswCQYDVQQGEwJVUzESMBAGA1UE
ChMJSWRlblRydXN0MScwJQYDVQQDEx5JZGVuVHJ1c3QgQ29tbWVyY2lhbCBSb290IENBIDEw
HhcNMTUwMjE4MjIyNTE5WhcNMjMwMjE4MjIyNTE5WjA6MQswCQYDVQQGEwJVUzESMBAGA1UE
ChMJSWRlblRydXN0MRcwFQYDVQQDEw5UcnVzdElEIENBIEExMjCCASIwDQYJKoZIhvcNAQEB
BQADggEPADCCAQoCggEBANGRTTzPCic0kq5L6ZrUJWt5LE/n6tbPXPhGt2Egv7plJMoEpvVJ
JDqGqDYymaAsd8Hn9ZMAuKUEFdlx5PgCkfu7jL5zgiMNnAFVD9PyrsuF+poqmlxhlQ06sFY2
hbhQkVVQ00KCNgUzKcBUIvjv04w+fhNPkwGW5M7Ae5K5OGFGwOoRck9GG6MUVKvTNkBw2/vN
MOd29VGVTtR0tjH5PS5yDXss48Yl1P4hDStO2L4wTsW2P37QGD27//XGN8K6amWB6F2XOgff
/PmlQjQOORT95PmLkwwvma5nj0AS0CVp8kv0K2RHV7GonllKpFDMT0CkxMQKwoj+tWEWJTiD
KSsCAwEAAaOCAoAwggJ8MIGJBggrBgEFBQcBAQR9MHswMAYIKwYBBQUHMAGGJGh0dHA6Ly9j
b21tZXJjaWFsLm9jc3AuaWRlbnRydXN0LmNvbTBHBggrBgEFBQcwAoY7aHR0cDovL3ZhbGlk
YXRpb24uaWRlbnRydXN0LmNvbS9yb290cy9jb21tZXJjaWFscm9vdGNhMS5wN2MwHwYDVR0j
BBgwFoAU7UQZwNPwBovupHu+QucmVMiONnYwDwYDVR0TAQH/BAUwAwEB/zCCASAGA1UdIASC
ARcwggETMIIBDwYEVR0gADCCAQUwggEBBggrBgEFBQcCAjCB9DBFFj5odHRwczovL3NlY3Vy
ZS5pZGVudHJ1c3QuY29tL2NlcnRpZmljYXRlcy9wb2xpY3kvdHMvaW5kZXguaHRtbDADAgEB
GoGqVGhpcyBUcnVzdElEIENlcnRpZmljYXRlIGhhcyBiZWVuIGlzc3VlZCBpbiBhY2NvcmRh
bmNlIHdpdGggSWRlblRydXN0J3MgVHJ1c3RJRCBDZXJ0aWZpY2F0ZSBQb2xpY3kgZm91bmQg
YXQgaHR0cHM6Ly9zZWN1cmUuaWRlbnRydXN0LmNvbS9jZXJ0aWZpY2F0ZXMvcG9saWN5L3Rz
L2luZGV4Lmh0bWwwSgYDVR0fBEMwQTA/oD2gO4Y5aHR0cDovL3ZhbGlkYXRpb24uaWRlbnRy
dXN0LmNvbS9jcmwvY29tbWVyY2lhbHJvb3RjYTEuY3JsMB0GA1UdJQQWMBQGCCsGAQUFBwMC
BggrBgEFBQcDBDAOBgNVHQ8BAf8EBAMCAYYwHQYDVR0OBBYEFKRz2u9pNYp1zKAZewgy+GuJ
5ELsMA0GCSqGSIb3DQEBCwUAA4ICAQAN4YKu0vv062MZfg+xMSNUXYKvHwvZIk+6H1pUmivy
DI4I6A3wWzxlr83ZJm0oGIF6PBsbgKJ/fhyyIzb+vAYFJmyI8I/0mGlc+nIQNuV2XY8cypPo
VJKgpnzp/7cECXkX8R4NyPtEn8KecbNdGBdEaG4a7AkZ3ujlJofZqYdHxN29tZPdDlZ8fR36
/mAFeCEq0wOtOOc0Eyhs29+9MIZYjyxaPoTS+l8xLcuYX3RWlirRyH6RPfeAi5kySOEhG1qu
NHe06QIwpigjyFT6v/vRqoIBr7WpDOSt1VzXPVbSj1PcWBgkwyGKHlQUOuSbHbHcjOD8w8wH
SDbL+L2he8hNN54doy1e1wJHKmnfb0uBAeISoxRbJnMMWvgAlH5FVrQWlgajeH/6NbYbBSRx
ALuEOqEQepmJM6qz4oD2sxdq4GMN5adAdYEswkY/o0bRKyFXTD3mdqeRXce0jYQbWm7oapqS
ZBccFvUgYOrB78tB6c1bxIgaQKRShtWR1zMM0JfqUfD9u8Fg7G5SVO0IG/GcxkSvZeRjhYcb
TfqF2eAgprpyzLWmdr0mou3bv1Sq4OuBhmTQCnqxAXr4yVTRYHkp5lCvRgeJAme1OTVpVPth
/O7HJ7VuEP9GOr6kCXCXmjB4P3UJ2oU0NqfoQdcSSSt9hliALnExTEjii20B2nSDojGCAxQw
ggMQAgEBME4wOjELMAkGA1UEBhMCVVMxEjAQBgNVBAoTCUlkZW5UcnVzdDEXMBUGA1UEAxMO
VHJ1c3RJRCBDQSBBMTICEEABbQHWpVVDfbC/HYRdhTowDQYJYIZIAWUDBAIBBQCgggGXMBgG
CSqGSIb3DQEJAzELBgkqhkiG9w0BBwEwHAYJKoZIhvcNAQkFMQ8XDTIxMTEyMDAyMzQxMFow
LwYJKoZIhvcNAQkEMSIEIK2v4s7a8PbAQE6iiYSCVGal538vr2wH8/r/ot2dOARrMF0GCSsG
AQQBgjcQBDFQME4wOjELMAkGA1UEBhMCVVMxEjAQBgNVBAoTCUlkZW5UcnVzdDEXMBUGA1UE
AxMOVHJ1c3RJRCBDQSBBMTICEEABbQHWpVVDfbC/HYRdhTowXwYLKoZIhvcNAQkQAgsxUKBO
MDoxCzAJBgNVBAYTAlVTMRIwEAYDVQQKEwlJZGVuVHJ1c3QxFzAVBgNVBAMTDlRydXN0SUQg
Q0EgQTEyAhBAAW0B1qVVQ32wvx2EXYU6MGwGCSqGSIb3DQEJDzFfMF0wCwYJYIZIAWUDBAEq
MAsGCWCGSAFlAwQBAjAKBggqhkiG9w0DBzAOBggqhkiG9w0DAgICAIAwDQYIKoZIhvcNAwIC
AUAwBwYFKw4DAgcwDQYIKoZIhvcNAwICASgwDQYJKoZIhvcNAQEBBQAEggEAArO42d92uizn
59YJwGHJ8tFCHhBmrszsL4TYKgbx8Zuble2KV9rqfskYNC9sQOITLn86sTRUPLtKHyYD4BPy
CNmVClxGmrSYvLo3r+invfzJmO1FpZqV/tl1HRDp97PIqOv2bMsgNszZBv+5AktumDKjJmNp
GkJ7r445EfsilYCZvILRoS4oykw1zq664pcgjBxF4rzI39CzaaNfEpunaXX3i1WYmNSTKgaK
NYQpU0K76EmCD4qWGLIYugWXMWMBMxaW1zOadJEDHDVLHvchMTcshdxct5GYGwVmBcSHcc0I
r+33qiP1qifh6w7rYNA3RxlC/Z62V0u1vqqaQvR5rQAAAAAAAA==
--------------ms080001070806040706080806--