#1563 closed defect (worksforme)

Use FD after close()

Reported by: tal.saiag@… Owned by:
Priority: major Milestone:
Component: nginx-core Version: 1.15.x
Keywords: use close fd after free log Cc:
uname -a: Linux COMP_NAME 4.13.0-43-generic #48-Ubuntu SMP Wed May 16 12:18:48 UTC 2018 x86_64 GNU/Linux
nginx -V: nginx version: nginx/1.13.11 (Ubuntu) built by gcc 7.2.0 (Ubuntu 7.2.0-8ubuntu3.2) built with OpenSSL 1.1.0f 25 May 2017 TLS SNI support enabled configure arguments: --prefix=/usr/share/nginx --sbin-path=/usr/sbin/nginx --modules-path=/usr/lib/nginx/modules --conf-path=/etc/nginx/nginx.conf --error-log-path=/tmp/nginx/error.log --http-log-path=/tmp/nginx/access.log --pid-path=/run/nginx.pid --lock-path=/var/lock/nginx.lock --user=www-data --group=www-data --build=Ubuntu --http-client-body-temp-path=/var/lib/nginx/body --http-fastcgi-temp-path=/var/lib/nginx/fastcgi --http-proxy-temp-path=/var/lib/nginx/proxy --http-scgi-temp-path=/var/lib/nginx/scgi --http-uwsgi-temp-path=/var/lib/nginx/uwsgi --with-openssl=../openssl-1.1.0f --with-openssl-opt=enable-ec_nistp_64_gcc_128 --with-openssl-opt=no-nextprotoneg --with-openssl-opt=no-weak-ssl-ciphers --with-openssl-opt=no-ssl3 --with-pcre=../pcre-8.40 --with-pcre-jit --with-zlib=../zlib-1.2.11 --with-compat --with-file-aio --with-threads --with-http_addition_module --with-http_auth_request_module --with-http_dav_module --with-http_flv_module --with-http_gunzip_module --with-http_gzip_static_module --with-http_mp4_module --with-http_random_index_module --with-http_realip_module --with-http_slice_module --with-http_ssl_module --with-http_sub_module --with-http_stub_status_module --with-http_v2_module --with-http_secure_link_module --with-mail --with-mail_ssl_module --with-stream --with-stream_realip_module --with-stream_ssl_module --with-stream_ssl_preread_module --with-debug --with-cc-opt='-g -O2 -fPIE -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2' --with-ld-opt='-Wl,-Bsymbolic-functions -fPIE -pie -Wl,-z,relro -Wl,-z,now'

Description

On reload-configuration, the logging system uses the log file's FD after it has been closed (by calling ngx_close_file(file[i].fd) in ngx_cycle.c:ngx_init_cycle:750).
This causes the logging to be redirected accidentally to another opened FD (opened on the same number, by chance).
A workaround was to set: file[i].fd = NGX_INVALID_FILE; just before calling ngx_close_file(fd) on a (temp) saved FD number.
The logger simply suppresses errors in such case (since n = ngx_write_fd(...) will be -1 and ngx_errno != NGX_ENOSPC - see code under ngx_log.c:ngx_log_error_core:185)

ngx_fd_t fd = file[i].fd;
file[i].fd = NGX_INVALID_FILE;
if (ngx_close_file(fd) == NGX_FILE_ERROR) {

There are several more places closing a file descriptor which may manifest as bugs later on, unless also set to NGX_INVALID_FILE, but I was not affected by them...

Log messages sent when the file descriptor was closed:

ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB5213F0")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB520330")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB51F270")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB54DAB0, unused: 2416")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: run cleanup: 000055EADB53A8F0")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: run cleanup: 000055EADB53A038")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: cleanup resolver")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB54C120")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB529700")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB524630")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB523570")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB5224B0")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB50F6B0, unused: 0")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB51B260, unused: 0")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB5256F0, unused: 0")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB52A710, unused: 0")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB52E8F0, unused: 0")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB532900, unused: 0")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB536910, unused: 0")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB53ABA0, unused: 8")
ngx_write_fd(-1, "2018/05/30 17:44:36 [debug] 1#1: free: 000055EADB548110, unused: 12024")

Change History (2)

comment:1 Changed 18 months ago by mdounin

This causes the logging to be redirected accidentally to another opened FD (opened on the same number, by chance).

No file descriptors are opened between the "close the unnecessary open files" loop and returning from the function. As such, logging to the old file, even if happens, is not expected to be redirected to another opened file descriptor. Rather, it will result in an ENIVAL error from write(), much like with fd set to -1. While explicitly clearing the fd by setting it to -1 aka NGX_INVALID_FILE might be cleaner, it is not something required for correct operation.

If you think that writing to an incorrect file descriptor can happen nevertheless, please provide more details.

comment:2 Changed 17 months ago by mdounin

  • Resolution set to worksforme
  • Status changed from new to closed

Feedback timeout.

The only case when this can be a problem seems to be a configuration reload with master_process off, but it is not something working anyway, see #945.

Note: See TracTickets for help on using tickets.