Opened 7 years ago
Closed 7 years ago
#1563 closed defect (worksforme)
Use FD after close()
| Reported by: | 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 by , 7 years ago
comment:2 by , 7 years ago
| Resolution: | → worksforme |
|---|---|
| Status: | new → 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.
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.