This question has been radically edited due to further investigation into the problem
TL:DR; We have been running Apache on Ubuntu serving NFS pages for over 20 years now and a new emergent issue has us completely flummoxed - it started manifesting around four weeks ago (around February 24th).
The question: What is going on, and how do we fix it?
Network, Drivespace, Memory, CPU do not appear to be the problem here. This seems to be something to do with a sudden uptick of file meta-data being requested.
Update 23.2/03/2023
This seems to be the same as https://serverfault.com/questions/1126320/heavy-nfs-metadata-traffic-flooding-nfsv4-1-server-aws-efs
Update 23/03/2023
Not having User/Group set in the apache.conf is creating a side-effect, such that apache will now run as root, which it normally doesn't want to do. (We have yet to report this as a bug, which we consider, in apache's own words, to be a BIG_SECURITY_HOLE).
Essentially, what the differences are between the nfs traffic and apache2, are to do with whether or not apache2 is running as root. As to why that is making a difference, we are still unclear.
So, why would commenting out User/Group change anything? (FYI, It doesn't matter which User/Group is declared).
Essentially, it appears that commenting out User/Group actually enables Apache2 to run as root. Clearly this would be an apache bug as, if we define root/root in User/Group, we see (via apachectl -t)
Apache has not been designed to serve pages while
running as root. There are known race conditions that
will allow any local user to read any file on the system.
If you still desire to serve pages as root then
add -DBIG_SECURITY_HOLE to the CFLAGS env variable
and then rebuild the server.
It is strongly suggested that you instead modify the User
directive in your httpd.conf file to list a non-root
user.
Just to show what we see when user/group is turned off...
root 402354 0.1 3.7 608224 36872 ? Ss 12:17 0:00 /usr/sbin/apache2 -k start
root 402355 0.0 0.7 57448 7084 ? S 12:17 0:00 /usr/sbin/apache2 -k start
root 402356 0.0 1.4 608596 13984 ? S 12:17 0:00 /usr/sbin/apache2 -k start
root 402357 0.0 1.8 608788 18668 ? S 12:17 0:00 /usr/sbin/apache2 -k start
root 402358 0.0 1.4 608596 13984 ? S 12:17 0:00 /usr/sbin/apache2 -k start
root 402359 0.0 1.4 608596 13984 ? S 12:17 0:00 /usr/sbin/apache2 -k start
root 402360 0.0 1.4 608596 13984 ? S 12:17 0:00 /usr/sbin/apache2 -k start
It seems that both Apache needs to be root in order to use the NFS cache, or it completely ignore, destroy, or undermine it (unless running as root) when it is effectively not being run as root. (ie, when User/Group is set in the config files).
Note that turning off User/Group is an Apache thing and not an NFS thing.
Details follow.
We have installed two vanilla AWS Ubuntu 22.04.2 Servers onto a private network and, using apt update/apt upgrade, we have brought them fully up to date.
One, "nfs" has been configured as an nfs server, onto a mounted 100GB reformatted EBS drive. None of this differs from many other systems we have installed over the years.
On "nfs" The /etc/exports file looks like this:
/mnt/nx 10.0.0.0/16(rw,sync,insecure_locks,no_subtree_check,all_squash,anonuid=1002,anongid=1002)
(user 1002 is a general purpose user, identified with the same rights on both boxes. Regardless, with all_squash, www-data has r/w access.)
Meanwhile, /etc/fstab is as follows:
/dev/xvdf /mnt/nx ext4 defaults,nofail 0 2
On the apache box "apache", the /etc/fstab is as follows
nfs.private.net:/mnt/nx /websites nfs
sudo mount nfs
mounts the nfs correctly.
local tests have repeatedly shown that the drive is mounted correctly, and many tests have shown that the nfs server is doing exactly what it should.
For the purpose of testing, there are no other 'moving parts' - no other network devices, nor are there any other connected systems. The boxes are isolated, with no other connections nor non-system background services.
We have installed both apache and nginx - both show the problem. But we are most familiar with apache2.4
So, we set this up such that it can serve a 'vanilla' website - it has been configured to serve over SSL.
There is one, dummy, flat file used with some random html in it that serves as a test page. 'test.html'
From the "apache" box, we are easily able to make requests via the apache server, and successfully retrieve the html as expected.
curl -o /dev/null -w "%{time_total} \n" -s --resolve apache.private.net:443:10.0.31.198 https://apache.private.net/test.html
we wrap that into a while, as such
while true; do curl -o /dev/null -w "%{time_total} \n" -s --resolve apache.private.net:443:10.0.31.198 "https://apache.private.net/test.html"; done
Typical/Acceptable results are as follows (on micro instances).
0.081165
0.080225
0.080009
0.081856
0.082625
0.081589
However, we have done one weird thing to get this to work as above. We have commented out the user/group line in the apache config files.
#User www-data
#Group www-data
If we uncomment them, and restart apache
systemctl restart apache2
everything seems the same as above, but it is not. There is a small increment in timing, which is greatly magnified with systems such as php.
0.090778
0.089920
0.089189
0.089006
0.088288
0.089497
0.089113
However, let's just check what is happening "under the hood".
I'm going to use the above request, but monitor just one request with User/Group set, on tcpdump (there is no other traffic)
tcpdump -Z root -s 9000 port 2049
This is the typical output for every single HTTPS request. We are seeing 16+ nfs request/responses. Repeated requests thrash the network each time.
18:02:31.777116 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 2817:2989, ack 2689, win 8106, options [nop,nop,TS val 1038289658 ecr 3939993554], length 172: NFS request xid 3583950656 168 getattr fh 0,2/53
18:02:31.777685 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 2689:2861, ack 2989, win 9045, options [nop,nop,TS val 3940004552 ecr 1038289658], length 172: NFS reply xid 3583950656 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.777700 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [.], ack 2861, win 8105, options [nop,nop,TS val 1038289659 ecr 3940004552], length 0
18:02:31.777757 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 2989:3169, ack 2861, win 8106, options [nop,nop,TS val 1038289659 ecr 3940004552], length 180: NFS request xid 3600727872 176 getattr fh 0,2/53
18:02:31.778188 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 2861:3033, ack 3169, win 9045, options [nop,nop,TS val 3940004553 ecr 1038289659], length 172: NFS reply xid 3600727872 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.778220 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 3169:3349, ack 3033, win 8106, options [nop,nop,TS val 1038289659 ecr 3940004553], length 180: NFS request xid 3617505088 176 getattr fh 0,2/53
18:02:31.778569 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 3033:3205, ack 3349, win 9045, options [nop,nop,TS val 3940004553 ecr 1038289659], length 172: NFS reply xid 3617505088 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.778617 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 3349:3521, ack 3205, win 8106, options [nop,nop,TS val 1038289660 ecr 3940004553], length 172: NFS request xid 3634282304 168 getattr fh 0,2/53
18:02:31.778976 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 3205:3377, ack 3521, win 9045, options [nop,nop,TS val 3940004553 ecr 1038289660], length 172: NFS reply xid 3634282304 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.779011 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 3521:3693, ack 3377, win 8106, options [nop,nop,TS val 1038289660 ecr 3940004553], length 172: NFS request xid 3651059520 168 getattr fh 0,2/53
18:02:31.779434 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 3377:3549, ack 3693, win 9045, options [nop,nop,TS val 3940004554 ecr 1038289660], length 172: NFS reply xid 3651059520 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.779464 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 3693:3873, ack 3549, win 8106, options [nop,nop,TS val 1038289660 ecr 3940004554], length 180: NFS request xid 3667836736 176 getattr fh 0,2/53
18:02:31.779885 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 3549:3721, ack 3873, win 9045, options [nop,nop,TS val 3940004554 ecr 1038289660], length 172: NFS reply xid 3667836736 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.779932 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 3873:4045, ack 3721, win 8106, options [nop,nop,TS val 1038289661 ecr 3940004554], length 172: NFS request xid 3684613952 168 getattr fh 0,2/53
18:02:31.780355 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 3721:3893, ack 4045, win 9045, options [nop,nop,TS val 3940004555 ecr 1038289661], length 172: NFS reply xid 3684613952 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.780385 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 4045:4225, ack 3893, win 8106, options [nop,nop,TS val 1038289661 ecr 3940004555], length 180: NFS request xid 3701391168 176 getattr fh 0,2/53
18:02:31.780749 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 3893:4065, ack 4225, win 9045, options [nop,nop,TS val 3940004555 ecr 1038289661], length 172: NFS reply xid 3701391168 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.780774 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 4225:4405, ack 4065, win 8106, options [nop,nop,TS val 1038289662 ecr 3940004555], length 180: NFS request xid 3718168384 176 getattr fh 0,2/53
18:02:31.781175 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 4065:4237, ack 4405, win 9045, options [nop,nop,TS val 3940004556 ecr 1038289662], length 172: NFS reply xid 3718168384 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.781212 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 4405:4577, ack 4237, win 8106, options [nop,nop,TS val 1038289662 ecr 3940004556], length 172: NFS request xid 3734945600 168 getattr fh 0,2/53
18:02:31.781558 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 4237:4409, ack 4577, win 9045, options [nop,nop,TS val 3940004556 ecr 1038289662], length 172: NFS reply xid 3734945600 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.781584 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 4577:4757, ack 4409, win 8106, options [nop,nop,TS val 1038289663 ecr 3940004556], length 180: NFS request xid 3751722816 176 getattr fh 0,2/53
18:02:31.781952 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 4409:4581, ack 4757, win 9045, options [nop,nop,TS val 3940004556 ecr 1038289663], length 172: NFS reply xid 3751722816 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.781976 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 4757:4937, ack 4581, win 8106, options [nop,nop,TS val 1038289663 ecr 3940004556], length 180: NFS request xid 3768500032 176 getattr fh 0,2/53
18:02:31.782394 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 4581:4753, ack 4937, win 9045, options [nop,nop,TS val 3940004557 ecr 1038289663], length 172: NFS reply xid 3768500032 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.782467 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 4937:5109, ack 4753, win 8106, options [nop,nop,TS val 1038289663 ecr 3940004557], length 172: NFS request xid 3785277248 168 getattr fh 0,2/53
18:02:31.782834 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 4753:4925, ack 5109, win 9045, options [nop,nop,TS val 3940004557 ecr 1038289663], length 172: NFS reply xid 3785277248 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.782862 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 5109:5289, ack 4925, win 8106, options [nop,nop,TS val 1038289664 ecr 3940004557], length 180: NFS request xid 3802054464 176 getattr fh 0,2/53
18:02:31.783239 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 4925:5097, ack 5289, win 9045, options [nop,nop,TS val 3940004558 ecr 1038289664], length 172: NFS reply xid 3802054464 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.783267 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 5289:5469, ack 5097, win 8106, options [nop,nop,TS val 1038289664 ecr 3940004558], length 180: NFS request xid 3818831680 176 getattr fh 0,2/53
18:02:31.783644 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 5097:5269, ack 5469, win 9045, options [nop,nop,TS val 3940004558 ecr 1038289664], length 172: NFS reply xid 3818831680 reply ok 168 getattr NON 4 ids 0/-1469769628 sz 464598276
18:02:31.783688 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 5469:5633, ack 5269, win 8106, options [nop,nop,TS val 1038289665 ecr 3940004558], length 164: NFS request xid 3835608896 160 getattr fh 0,2/53
18:02:31.784051 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 5269:5377, ack 5633, win 9045, options [nop,nop,TS val 3940004558 ecr 1038289665], length 108: NFS reply xid 3835608896 reply ok 104 getattr NON 3 ids 0/-1469769628 sz 464598276
18:02:31.827894 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [.], ack 5377, win 8106, options [nop,nop,TS val 1038289709 ecr 3940004558], length 0
Now, turning User/Group off (and restarting apache) The first HTTPS request is as follows (3 NFS request/responses), and the next HTTPS 10-15 requests generate no nfs traffic at all (we believe, thanks to the default nfs client caching) :
18:06:39.993397 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 6669:6837, ack 6525, win 8106, options [nop,nop,TS val 1038537874 ecr 3940246142], length 168: NFS request xid 3969826624 164 getattr fh 0,2/53
18:06:39.994129 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 6525:6769, ack 6837, win 9045, options [nop,nop,TS val 3940252768 ecr 1038537874], length 244: NFS reply xid 3969826624 reply ok 240 getattr NON 3 ids 0/-1469769628 sz 464598276
18:06:39.994145 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [.], ack 6769, win 8105, options [nop,nop,TS val 1038537875 ecr 3940252768], length 0
18:06:39.994372 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 6837:7073, ack 6769, win 8106, options [nop,nop,TS val 1038537875 ecr 3940252768], length 236: NFS request xid 3986603840 232 getattr fh 0,2/53
18:06:39.994832 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 6769:7125, ack 7073, win 9045, options [nop,nop,TS val 3940252769 ecr 1038537875], length 356: NFS reply xid 3986603840 reply ok 352 getattr NON 5 ids 0/-1469769628 sz 464598276
18:06:39.995036 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [P.], seq 7073:7249, ack 7125, win 8106, options [nop,nop,TS val 1038537876 ecr 3940252769], length 176: NFS request xid 4003381056 172 getattr fh 0,2/53
18:06:39.995520 IP ip-10-0-31-227.eu-west-1.compute.internal.nfs > ip-10-0-31-198.eu-west-1.compute.internal.911: Flags [P.], seq 7125:7241, ack 7249, win 9045, options [nop,nop,TS val 3940252770 ecr 1038537876], length 116: NFS reply xid 4003381056 reply ok 112 getattr NON 3 ids 0/-1469769628 sz 464598276
18:06:40.035889 IP ip-10-0-31-198.eu-west-1.compute.internal.911 > ip-10-0-31-227.eu-west-1.compute.internal.nfs: Flags [.], ack 7241, win 8106, options [nop,nop,TS val 1038537917 ecr 3940252770], length 0
Just to remind you This architecture has been working fine for many years - despite people bemoaning NFS. The behaviour we are seeing is new and, as we have not made any major changes to our systems, we believe that the culprit may have been a recent system upgrade (via unattended-upgrades). We might be wrong. But answers that involve replacing NFS are not what we are looking for here.
www-datawhen run via Apache, so ifwww-datadoesn't have access right, there's your issue.