Nginx + sendfile serves wrong content from NFS share, may leak confidential information to unauthorized party.

[imjosi@…]

Nginx + sendfile serves wrong content from NFS share, may leak confidential information to unauthorized party.

We have a NFS share attached to Nginx server, and recently noticed that under heavy NFS server load Nginx logs an I/O error and then serves wrong content in next request.

Actual files on NFS share:

# ls -li /mnt/net/ktn/TML/data/{2,5}0041{7,8}.pdf
218685 -rw-r--r-- 1 root root 200417 Mar 21 13:05 /mnt/net/ktn/TML/data/200417.pdf
218687 -rw-r--r-- 1 root root 200418 Mar 21 13:05 /mnt/net/ktn/TML/data/200418.pdf
218686 -rw-r--r-- 1 root root 500417 Mar 21 13:05 /mnt/net/ktn/TML/data/500417.pdf

You can see that Nginx aborted the transfer for file 500417.pdf and then returned 500417 bytes in next request for file 200418.pdf when actual size must be 200418 bytes.

access.log

10.10.248.21 - - [22/Mar/2019:10:32:05 +0200] "GET /TML/data/200417.pdf HTTP/1.1" 200 200417 "-" "curl/7.52.1" "-" 0.000
10.10.248.21 - - [22/Mar/2019:10:32:09 +0200] "GET /TML/data/500417.pdf HTTP/1.1" 500 537 "-" "curl/7.52.1" "-" 0.000
10.10.248.21 - - [22/Mar/2019:10:32:10 +0200] "GET /TML/data/200418.pdf HTTP/1.1" 200 500417 "-" "curl/7.52.1" "-" 0.000

error.log

2019/03/22 10:32:09 [crit] 639#639: *223 open() "/mnt/net/ktn/TML/data/500417.pdf" failed (5: Input/output error), client: 10.10.248.21, server: _, request: "GET /TML/data/500417.pdf HTTP/1.1", host: "10.10.248.21:8080"

After comparing md5 cheksums we confirmed that in request for file 200418.pdf Nginx returned the contents of file 500417.pdf

We were able to reproduce this error numerous times using default config for 1.14.2-1~stretch package from nginx.org on both Debian 8 x32 and Debian 9 x64, using Debian 9 and Solaris 11 as a NFS servers.

Next we found that putting "sendfile off" for this location changes this behaviour and Nginx starts to return incomplete files instead of wrong ones. It is not clear if this problem is caused by a Nginx or underlaying NFS client, but at least it must be clearly stated in the Nginx documentation that using "sendfile" for NFS mounts is dangerous and may leak confidential information to unauthorized party.

NFS share mount parameters

xet6:/ktn/TML on /mnt/net/ktn/TML type nfs4 (ro,relatime,vers=4.1,rsize=131072,wsize=131072,namlen=255,soft,noresvport,proto=tcp,port=0,timeo=10,retrans=2,sec=sys,clientaddr=10.10.248.21,local_lock=none,addr=10.10.248.18)

Site config in Nginx:

# cat /etc/nginx/conf.d/56-TML.conf 
server {
    listen              8080 default_server;
    server_name         _;

    proxy_no_cache      now;
    proxy_cache_bypass  now;

    location / {
        root /mnt/net/ktn/ ;
    }

    # redirect server error pages to the static page /50x.html
    #
    error_page   500 502 503 504  /50x.html;
    location = /50x.html {
        root   /usr/share/nginx/html;
    }
}

[imjosi@…]

Nginx debug log

[imjosi@…]

Nginx running config

[Maxim Dounin]

From the debug log it looks like an OS-level problem. nginx properly opens a requested file, and returns its contents:

2019/03/22 10:32:10 [debug] 639#639: *224 http filename: "/mnt/net/ktn/TML/data/200418.pdf"
2019/03/22 10:32:10 [debug] 639#639: *224 add cleanup: 00005604A0581D88
2019/03/22 10:32:10 [debug] 639#639: *224 http static fd: 8
2019/03/22 10:32:10 [debug] 639#639: *224 http set discard body
2019/03/22 10:32:10 [debug] 639#639: *224 HTTP/1.1 200 OK
2019/03/22 10:32:10 [debug] 639#639: *224 write new buf t:1 f:0 00005604A0557450, pos 00005604A0557450, size: 249 file: 0, size: 0
2019/03/22 10:32:10 [debug] 639#639: *224 http write filter: l:0 f:0 s:249
2019/03/22 10:32:10 [debug] 639#639: *224 http output filter "/TML/data/200418.pdf?"
2019/03/22 10:32:10 [debug] 639#639: *224 http copy filter: "/TML/data/200418.pdf?"
2019/03/22 10:32:10 [debug] 639#639: *224 http postpone filter "/TML/data/200418.pdf?" 00007FFF5C0F04F0
2019/03/22 10:32:10 [debug] 639#639: *224 write old buf t:1 f:0 00005604A0557450, pos 00005604A0557450, size: 249 file: 0, size: 0
2019/03/22 10:32:10 [debug] 639#639: *224 write new buf t:0 f:1 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 500417
2019/03/22 10:32:10 [debug] 639#639: *224 http write filter: l:1 f:0 s:500666
2019/03/22 10:32:10 [debug] 639#639: *224 http write filter limit 0
2019/03/22 10:32:10 [debug] 639#639: *224 writev: 249 of 249
2019/03/22 10:32:10 [debug] 639#639: *224 sendfile: @0 500417
2019/03/22 10:32:10 [debug] 639#639: *224 sendfile: 500417 of 500417 @0

While in theory it is possible that nginx does something wrong at low level, and the name of the file as printed in the log does not match the one nginx passes to the open() system call, this is something highly unlikely. If you think this is the case, you may want to run nginx under strace to trace actual syscalls used.

[imjosi@…]

Strace with wrong content for file 200703.pdf

[imjosi@…]

Strace with wrong content for file 200703.pdf added, must be 200703 bytes not 500702.

During testing we noticed that setting worker_processes to 1 also eliminates this problem.

[Maxim Dounin]

So clearly this is an OS-level problem:

open("/mnt/net/ktn/TML/data/200703.pdf", O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 12
fstat64(12, {st_mode=S_IFREG|0644, st_size=500702, ...}) = 0

Likely a bug either in the NFS implementation on the server where nginx is running, or a bug in the NFS server itself. Closing this ticket as invalid, as clearly this is not a bug in nginx. You may want to report this problem elsewhere.

Note well that serving files from an NFS share with nginx is usually a bad idea, even if everything works correctly, since blocking a worker process on NFS operations will affect multiple connections in the same worker process. Instead, consider proxying to the server where files are available directly.