Skip to content

Commit

Permalink
HTTP: Remove short read check in nxt_http_static_buf_completion()
Browse files Browse the repository at this point in the history
On GH, @tonychuuy reported an issue when using Units 'share' action they
would get the following error in the unit log

  2024/01/15 17:53:41 [error] 49#52 *103 file "/var/www/html/public/vendor/telescope/app.css" has changed while sending response to a client

This would happen when trying to serve files over a certain size and the
requested file would not be sent.

This is due to a somewhat bogus check in
nxt_http_static_buf_completion()

I say bogus because it's not clear what the check is trying to
accomplish and the error message is not entirely accurate either.

The check in question goes like

    n = pread(file->fd, buf, size, offset);
    return n;
    ...
    if (n != size) {
        if (n >= 0) {
            /* log file changed error and finish */

            /* >> Problem is here << */
        }

       	/* log general error and finish */
    }

If the number of bytes read is not what we asked for and is > -1 (i.e
not an error) then it says the file has changed, but really it only
checks if the file has _shrunk_ (we can't get back _more_ bytes than we
asked for) since it was stat'd.

This is what happens

  recvfrom(22, "GET /tfile HTTP/1.1\r\nHost: local"..., 2048, 0, NULL, NULL) = 82
  openat(AT_FDCWD, "/mnt/9p/tfile", O_RDONLY|O_NONBLOCK) = 23
  newfstatat(23, "", {st_mode=S_IFREG|0644, st_size=149922, ...}, AT_EMPTY_PATH) = 0

We get a request from a client, open the requested file and stat(2) it to
get the file size.

We would then go into a pread/writev loop reading the file data and
sending it to the client until it's all been sent.

However what was happening in this case was this (showing a dummy file
of 149922 bytes)

  pread64(23, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 131072, 0) = 61440
  write(2, "2024/01/17 15:30:50 [error] 1849"..., 109) = 109

We wanted to read 131072 bytes but only read 61440 bytes, the above
check triggered and the file transfer was aborted and the above error
message logged.

Normally for a regular file you will only get less bytes than asked for
if the read call is interrupted by a signal or you're near the end of
file.

There is however at least another situation where this may happen, if
the file in question is being served from a network filesystem.

It turns out that was indeed the case here, the files where being served
over the 9P filesystem protocol. Unit was running in a docker container
in an Ubuntu VM under Windows/WSL2 and the files where being passed
through to the VM from Windows over 9P.

Whatever the intention of this check, it is clearly causing issues in
real world scenarios.

If it was really desired to check if the had changed since it was
opened/stat'd then it would require a different methodology and be a
patch for another day. But as it stands this current check does more
harm than good, so lets just remove it.

With it removed we now get for the above test file

  recvfrom(22, "GET /tfile HTTP/1.1\r\nHost: local"..., 2048, 0, NULL, NULL) = 82
  openat(AT_FDCWD, "/mnt/9p/tfile", O_RDONLY|O_NONBLOCK) = 23
  newfstatat(23, "", {st_mode=S_IFREG|0644, st_size=149922, ...}, AT_EMPTY_PATH) = 0
  mmap(NULL, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f367817b000
  pread64(23, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 131072, 0) = 61440
  pread64(23, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 18850, 61440) = 18850
  writev(22, [{iov_base="HTTP/1.1 200 OK\r\nLast-Modified: "..., iov_len=171}, {iov_base="\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., iov_len=61440}, {iov_base="\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., iov_len=18850}], 3) = 80461
  pread64(23, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 69632, 80290) = 61440
  pread64(23, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192, 141730) = 8192
  close(23)                   = 0
  writev(22, [{iov_base="\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., iov_len=61440}, {iov_base="\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., iov_len=8192}], 2) = 69632

So we can see we do two pread(2)s's and a writev(2), then another two
pread(2)s and another writev(2) and all the file data has been read and
sent to the client.

Reported-by: tonychuuy <https://github.com/tonychuuy>
Link: <https://en.wikipedia.org/wiki/9P_(protocol)>
Fixes: 08a8d15 ("Basic support for serving static files.")
Closes: nginx#1064
Reviewed-by: Zhidao Hong <z.hong@f5.com>
Reviewed-by: Andrei Zeliankou <zelenkov@nginx.com>
Signed-off-by: Andrew Clayton <a.clayton@nginx.com>
  • Loading branch information
ac000 committed Jan 20, 2024
1 parent 6fd29be commit 5454849
Showing 1 changed file with 1 addition and 6 deletions.
7 changes: 1 addition & 6 deletions src/nxt_http_static.c
Original file line number Diff line number Diff line change
Expand Up @@ -879,12 +879,7 @@ nxt_http_static_buf_completion(nxt_task_t *task, void *obj, void *data)

n = nxt_file_read(fb->file, b->mem.start, size, fb->file_pos);

if (n != size) {
if (n >= 0) {
nxt_log(task, NXT_LOG_ERR, "file \"%FN\" has changed "
"while sending response to a client", fb->file->name);
}

if (nxt_slow_path(n == NXT_ERROR)) {
nxt_http_request_error_handler(task, r, r->proto.any);
goto clean;
}
Expand Down

0 comments on commit 5454849

Please sign in to comment.