Mercurial > hg > nginx
view src/core/ngx_log.h @ 9203:0de20f43db25
Fixed request termination with AIO and subrequests (ticket #2555).
When a request was terminated due to an error via ngx_http_terminate_request()
while an AIO operation was running in a subrequest, various issues were
observed. This happened because ngx_http_request_finalizer() was only set
in the subrequest where ngx_http_terminate_request() was called, but not
in the subrequest where the AIO operation was running. After completion
of the AIO operation normal processing of the subrequest was resumed, leading
to issues.
In particular, in case of the upstream module, termination of the request
called upstream cleanup, which closed the upstream connection. Attempts to
further work with the upstream connection after AIO operation completion
resulted in segfaults in ngx_ssl_recv(), "readv() failed (9: Bad file
descriptor) while reading upstream" errors, or socket leaks.
In ticket #2555, issues were observed with the following configuration
with cache background update (with thread writing instrumented to
introduce a delay, when a client closes the connection during an update):
location = /background-and-aio-write {
proxy_pass ...
proxy_cache one;
proxy_cache_valid 200 1s;
proxy_cache_background_update on;
proxy_cache_use_stale updating;
aio threads;
aio_write on;
limit_rate 1000;
}
Similarly, the same issue can be seen with SSI, and can be caused by
errors in subrequests, such as in the following configuration
(where "/proxy" uses AIO, and "/sleep" returns 444 after some delay,
causing request termination):
location = /ssi-active-boom {
ssi on;
ssi_types *;
return 200 '
<!--#include virtual="/proxy" -->
<!--#include virtual="/sleep" -->
';
limit_rate 1000;
}
Or the same with both AIO operation and the error in non-active subrequests
(which needs slightly different handling, see below):
location = /ssi-non-active-boom {
ssi on;
ssi_types *;
return 200 '
<!--#include virtual="/static" -->
<!--#include virtual="/proxy" -->
<!--#include virtual="/sleep" -->
';
limit_rate 1000;
}
Similarly, issues can be observed with just static files. However,
with static files potential impact is limited due to timeout safeguards
in ngx_http_writer(), and the fact that c->error is set during request
termination.
In a simple configuration with an AIO operation in the active subrequest,
such as in the following configuration, the connection is closed right
after completion of the AIO operation anyway, since ngx_http_writer()
tries to write to the connection and fails due to c->error set:
location = /ssi-active-static-boom {
ssi on;
ssi_types *;
return 200 '
<!--#include virtual="/static-aio" -->
<!--#include virtual="/sleep" -->
';
limit_rate 1000;
}
In the following configuration, with an AIO operation in a non-active
subrequest, the connection is closed only after send_timeout expires:
location = /ssi-non-active-static-boom {
ssi on;
ssi_types *;
return 200 '
<!--#include virtual="/static" -->
<!--#include virtual="/static-aio" -->
<!--#include virtual="/sleep" -->
';
limit_rate 1000;
}
Fix is to introduce r->main->terminated flag, which is to be checked
by AIO event handlers when the r->main->blocked counter is decremented.
When the flag is set, handlers are expected to wake up the connection
instead of the subrequest (which might be already cleaned up).
Additionally, now ngx_http_request_finalizer() is always set in the
active subrequest, so waking up the connection properly finalizes the
request even if termination happened in a non-active subrequest.
| author | Maxim Dounin <mdounin@mdounin.ru> |
|---|---|
| date | Tue, 30 Jan 2024 03:20:05 +0300 |
| parents | f18db38a9826 |
| children |
line wrap: on
line source
/* * Copyright (C) Igor Sysoev * Copyright (C) Nginx, Inc. */ #ifndef _NGX_LOG_H_INCLUDED_ #define _NGX_LOG_H_INCLUDED_ #include <ngx_config.h> #include <ngx_core.h> #define NGX_LOG_STDERR 0 #define NGX_LOG_EMERG 1 #define NGX_LOG_ALERT 2 #define NGX_LOG_CRIT 3 #define NGX_LOG_ERR 4 #define NGX_LOG_WARN 5 #define NGX_LOG_NOTICE 6 #define NGX_LOG_INFO 7 #define NGX_LOG_DEBUG 8 #define NGX_LOG_DEBUG_CORE 0x010 #define NGX_LOG_DEBUG_ALLOC 0x020 #define NGX_LOG_DEBUG_MUTEX 0x040 #define NGX_LOG_DEBUG_EVENT 0x080 #define NGX_LOG_DEBUG_HTTP 0x100 #define NGX_LOG_DEBUG_MAIL 0x200 #define NGX_LOG_DEBUG_STREAM 0x400 /* * do not forget to update debug_levels[] in src/core/ngx_log.c * after the adding a new debug level */ #define NGX_LOG_DEBUG_FIRST NGX_LOG_DEBUG_CORE #define NGX_LOG_DEBUG_LAST NGX_LOG_DEBUG_STREAM #define NGX_LOG_DEBUG_CONNECTION 0x80000000 #define NGX_LOG_DEBUG_ALL 0x7ffffff0 typedef u_char *(*ngx_log_handler_pt) (ngx_log_t *log, u_char *buf, size_t len); typedef void (*ngx_log_writer_pt) (ngx_log_t *log, ngx_uint_t level, u_char *buf, size_t len); struct ngx_log_s { ngx_uint_t log_level; ngx_open_file_t *file; ngx_atomic_uint_t connection; time_t disk_full_time; ngx_log_handler_pt handler; void *data; ngx_log_writer_pt writer; void *wdata; /* * we declare "action" as "char *" because the actions are usually * the static strings and in the "u_char *" case we have to override * their types all the time */ char *action; ngx_log_t *next; }; #define NGX_MAX_ERROR_STR 2048 /*********************************/ #if (NGX_HAVE_C99_VARIADIC_MACROS) #define NGX_HAVE_VARIADIC_MACROS 1 #define ngx_log_error(level, log, ...) \ if ((log)->log_level >= level) ngx_log_error_core(level, log, __VA_ARGS__) void ngx_log_error_core(ngx_uint_t level, ngx_log_t *log, ngx_err_t err, const char *fmt, ...); #define ngx_log_debug(level, log, ...) \ if ((log)->log_level & level) \ ngx_log_error_core(NGX_LOG_DEBUG, log, __VA_ARGS__) /*********************************/ #elif (NGX_HAVE_GCC_VARIADIC_MACROS) #define NGX_HAVE_VARIADIC_MACROS 1 #define ngx_log_error(level, log, args...) \ if ((log)->log_level >= level) ngx_log_error_core(level, log, args) void ngx_log_error_core(ngx_uint_t level, ngx_log_t *log, ngx_err_t err, const char *fmt, ...); #define ngx_log_debug(level, log, args...) \ if ((log)->log_level & level) \ ngx_log_error_core(NGX_LOG_DEBUG, log, args) /*********************************/ #else /* no variadic macros */ #define NGX_HAVE_VARIADIC_MACROS 0 void ngx_cdecl ngx_log_error(ngx_uint_t level, ngx_log_t *log, ngx_err_t err, const char *fmt, ...); void ngx_log_error_core(ngx_uint_t level, ngx_log_t *log, ngx_err_t err, const char *fmt, va_list args); void ngx_cdecl ngx_log_debug_core(ngx_log_t *log, ngx_err_t err, const char *fmt, ...); #endif /* variadic macros */ /*********************************/ #if (NGX_DEBUG) #if (NGX_HAVE_VARIADIC_MACROS) #define ngx_log_debug0(level, log, err, fmt) \ ngx_log_debug(level, log, err, fmt) #define ngx_log_debug1(level, log, err, fmt, arg1) \ ngx_log_debug(level, log, err, fmt, arg1) #define ngx_log_debug2(level, log, err, fmt, arg1, arg2) \ ngx_log_debug(level, log, err, fmt, arg1, arg2) #define ngx_log_debug3(level, log, err, fmt, arg1, arg2, arg3) \ ngx_log_debug(level, log, err, fmt, arg1, arg2, arg3) #define ngx_log_debug4(level, log, err, fmt, arg1, arg2, arg3, arg4) \ ngx_log_debug(level, log, err, fmt, arg1, arg2, arg3, arg4) #define ngx_log_debug5(level, log, err, fmt, arg1, arg2, arg3, arg4, arg5) \ ngx_log_debug(level, log, err, fmt, arg1, arg2, arg3, arg4, arg5) #define ngx_log_debug6(level, log, err, fmt, \ arg1, arg2, arg3, arg4, arg5, arg6) \ ngx_log_debug(level, log, err, fmt, \ arg1, arg2, arg3, arg4, arg5, arg6) #define ngx_log_debug7(level, log, err, fmt, \ arg1, arg2, arg3, arg4, arg5, arg6, arg7) \ ngx_log_debug(level, log, err, fmt, \ arg1, arg2, arg3, arg4, arg5, arg6, arg7) #define ngx_log_debug8(level, log, err, fmt, \ arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8) \ ngx_log_debug(level, log, err, fmt, \ arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8) #else /* no variadic macros */ #define ngx_log_debug0(level, log, err, fmt) \ if ((log)->log_level & level) \ ngx_log_debug_core(log, err, fmt) #define ngx_log_debug1(level, log, err, fmt, arg1) \ if ((log)->log_level & level) \ ngx_log_debug_core(log, err, fmt, arg1) #define ngx_log_debug2(level, log, err, fmt, arg1, arg2) \ if ((log)->log_level & level) \ ngx_log_debug_core(log, err, fmt, arg1, arg2) #define ngx_log_debug3(level, log, err, fmt, arg1, arg2, arg3) \ if ((log)->log_level & level) \ ngx_log_debug_core(log, err, fmt, arg1, arg2, arg3) #define ngx_log_debug4(level, log, err, fmt, arg1, arg2, arg3, arg4) \ if ((log)->log_level & level) \ ngx_log_debug_core(log, err, fmt, arg1, arg2, arg3, arg4) #define ngx_log_debug5(level, log, err, fmt, arg1, arg2, arg3, arg4, arg5) \ if ((log)->log_level & level) \ ngx_log_debug_core(log, err, fmt, arg1, arg2, arg3, arg4, arg5) #define ngx_log_debug6(level, log, err, fmt, \ arg1, arg2, arg3, arg4, arg5, arg6) \ if ((log)->log_level & level) \ ngx_log_debug_core(log, err, fmt, arg1, arg2, arg3, arg4, arg5, arg6) #define ngx_log_debug7(level, log, err, fmt, \ arg1, arg2, arg3, arg4, arg5, arg6, arg7) \ if ((log)->log_level & level) \ ngx_log_debug_core(log, err, fmt, \ arg1, arg2, arg3, arg4, arg5, arg6, arg7) #define ngx_log_debug8(level, log, err, fmt, \ arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8) \ if ((log)->log_level & level) \ ngx_log_debug_core(log, err, fmt, \ arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8) #endif #else /* !NGX_DEBUG */ #define ngx_log_debug0(level, log, err, fmt) #define ngx_log_debug1(level, log, err, fmt, arg1) #define ngx_log_debug2(level, log, err, fmt, arg1, arg2) #define ngx_log_debug3(level, log, err, fmt, arg1, arg2, arg3) #define ngx_log_debug4(level, log, err, fmt, arg1, arg2, arg3, arg4) #define ngx_log_debug5(level, log, err, fmt, arg1, arg2, arg3, arg4, arg5) #define ngx_log_debug6(level, log, err, fmt, arg1, arg2, arg3, arg4, arg5, arg6) #define ngx_log_debug7(level, log, err, fmt, arg1, arg2, arg3, arg4, arg5, \ arg6, arg7) #define ngx_log_debug8(level, log, err, fmt, arg1, arg2, arg3, arg4, arg5, \ arg6, arg7, arg8) #endif /*********************************/ ngx_log_t *ngx_log_init(u_char *prefix, u_char *error_log); void ngx_cdecl ngx_log_abort(ngx_err_t err, const char *fmt, ...); void ngx_cdecl ngx_log_stderr(ngx_err_t err, const char *fmt, ...); u_char *ngx_log_errno(u_char *buf, u_char *last, ngx_err_t err); ngx_int_t ngx_log_open_default(ngx_cycle_t *cycle); ngx_int_t ngx_log_redirect_stderr(ngx_cycle_t *cycle); ngx_log_t *ngx_log_get_file_log(ngx_log_t *head); char *ngx_log_set_log(ngx_conf_t *cf, ngx_log_t **head); /* * ngx_write_stderr() cannot be implemented as macro, since * MSVC does not allow to use #ifdef inside macro parameters. * * ngx_write_fd() is used instead of ngx_write_console(), since * CharToOemBuff() inside ngx_write_console() cannot be used with * read only buffer as destination and CharToOemBuff() is not needed * for ngx_write_stderr() anyway. */ static ngx_inline void ngx_write_stderr(char *text) { (void) ngx_write_fd(ngx_stderr, text, ngx_strlen(text)); } static ngx_inline void ngx_write_stdout(char *text) { (void) ngx_write_fd(ngx_stdout, text, ngx_strlen(text)); } extern ngx_module_t ngx_errlog_module; extern ngx_uint_t ngx_use_stderr; #endif /* _NGX_LOG_H_INCLUDED_ */