Mercurial > hg > nginx
view src/core/ngx_syslog.c @ 7281:bd6563e81cea
Limit req: improved handling of negative times.
Negative times can appear since workers only update time on an event
loop iteration start. If a worker was blocked for a long time during
an event loop iteration, it is possible that another worker already
updated the time stored in the node. As such, time since last update
of the node (ms) will be negative.
Previous code used ngx_abs(ms) in the calculations. That is, negative
times were effectively treated as positive ones. As a result, it was
not possible to maintain high request rates, where the same node can be
updated multiple times from during an event loop iteration.
In particular, this affected setups with many SSL handshakes, see
http://mailman.nginx.org/pipermail/nginx/2018-May/056291.html.
Fix is to only update the last update time stored in the node if the
new time is larger than previously stored one. If a future time is
stored in the node, we preserve this time as is.
To prevent breaking things on platforms without monotonic time available
if system time is updated backwards, a safety limit of 60 seconds is
used. If the time stored in the node is more than 60 seconds in the future,
we assume that the time was changed backwards and update lr->last
to the current time.
author | Maxim Dounin <mdounin@mdounin.ru> |
---|---|
date | Wed, 30 May 2018 15:40:34 +0300 |
parents | 7f9935f07fe9 |
children | 29adacffdefa |
line wrap: on
line source
/* * Copyright (C) Nginx, Inc. */ #include <ngx_config.h> #include <ngx_core.h> #include <ngx_event.h> #define NGX_SYSLOG_MAX_STR \ NGX_MAX_ERROR_STR + sizeof("<255>Jan 01 00:00:00 ") - 1 \ + (NGX_MAXHOSTNAMELEN - 1) + 1 /* space */ \ + 32 /* tag */ + 2 /* colon, space */ static char *ngx_syslog_parse_args(ngx_conf_t *cf, ngx_syslog_peer_t *peer); static ngx_int_t ngx_syslog_init_peer(ngx_syslog_peer_t *peer); static void ngx_syslog_cleanup(void *data); static char *facilities[] = { "kern", "user", "mail", "daemon", "auth", "intern", "lpr", "news", "uucp", "clock", "authpriv", "ftp", "ntp", "audit", "alert", "cron", "local0", "local1", "local2", "local3", "local4", "local5", "local6", "local7", NULL }; /* note 'error/warn' like in nginx.conf, not 'err/warning' */ static char *severities[] = { "emerg", "alert", "crit", "error", "warn", "notice", "info", "debug", NULL }; static ngx_log_t ngx_syslog_dummy_log; static ngx_event_t ngx_syslog_dummy_event; char * ngx_syslog_process_conf(ngx_conf_t *cf, ngx_syslog_peer_t *peer) { ngx_pool_cleanup_t *cln; peer->facility = NGX_CONF_UNSET_UINT; peer->severity = NGX_CONF_UNSET_UINT; if (ngx_syslog_parse_args(cf, peer) != NGX_CONF_OK) { return NGX_CONF_ERROR; } if (peer->server.sockaddr == NULL) { ngx_conf_log_error(NGX_LOG_EMERG, cf, 0, "no syslog server specified"); return NGX_CONF_ERROR; } if (peer->facility == NGX_CONF_UNSET_UINT) { peer->facility = 23; /* local7 */ } if (peer->severity == NGX_CONF_UNSET_UINT) { peer->severity = 6; /* info */ } if (peer->tag.data == NULL) { ngx_str_set(&peer->tag, "nginx"); } peer->conn.fd = (ngx_socket_t) -1; peer->conn.read = &ngx_syslog_dummy_event; peer->conn.write = &ngx_syslog_dummy_event; ngx_syslog_dummy_event.log = &ngx_syslog_dummy_log; cln = ngx_pool_cleanup_add(cf->pool, 0); if (cln == NULL) { return NGX_CONF_ERROR; } cln->data = peer; cln->handler = ngx_syslog_cleanup; return NGX_CONF_OK; } static char * ngx_syslog_parse_args(ngx_conf_t *cf, ngx_syslog_peer_t *peer) { u_char *p, *comma, c; size_t len; ngx_str_t *value; ngx_url_t u; ngx_uint_t i; value = cf->args->elts; p = value[1].data + sizeof("syslog:") - 1; for ( ;; ) { comma = (u_char *) ngx_strchr(p, ','); if (comma != NULL) { len = comma - p; *comma = '\0'; } else { len = value[1].data + value[1].len - p; } if (ngx_strncmp(p, "server=", 7) == 0) { if (peer->server.sockaddr != NULL) { ngx_conf_log_error(NGX_LOG_EMERG, cf, 0, "duplicate syslog \"server\""); return NGX_CONF_ERROR; } ngx_memzero(&u, sizeof(ngx_url_t)); u.url.data = p + 7; u.url.len = len - 7; u.default_port = 514; if (ngx_parse_url(cf->pool, &u) != NGX_OK) { if (u.err) { ngx_conf_log_error(NGX_LOG_EMERG, cf, 0, "%s in syslog server \"%V\"", u.err, &u.url); } return NGX_CONF_ERROR; } peer->server = u.addrs[0]; } else if (ngx_strncmp(p, "facility=", 9) == 0) { if (peer->facility != NGX_CONF_UNSET_UINT) { ngx_conf_log_error(NGX_LOG_EMERG, cf, 0, "duplicate syslog \"facility\""); return NGX_CONF_ERROR; } for (i = 0; facilities[i] != NULL; i++) { if (ngx_strcmp(p + 9, facilities[i]) == 0) { peer->facility = i; goto next; } } ngx_conf_log_error(NGX_LOG_EMERG, cf, 0, "unknown syslog facility \"%s\"", p + 9); return NGX_CONF_ERROR; } else if (ngx_strncmp(p, "severity=", 9) == 0) { if (peer->severity != NGX_CONF_UNSET_UINT) { ngx_conf_log_error(NGX_LOG_EMERG, cf, 0, "duplicate syslog \"severity\""); return NGX_CONF_ERROR; } for (i = 0; severities[i] != NULL; i++) { if (ngx_strcmp(p + 9, severities[i]) == 0) { peer->severity = i; goto next; } } ngx_conf_log_error(NGX_LOG_EMERG, cf, 0, "unknown syslog severity \"%s\"", p + 9); return NGX_CONF_ERROR; } else if (ngx_strncmp(p, "tag=", 4) == 0) { if (peer->tag.data != NULL) { ngx_conf_log_error(NGX_LOG_EMERG, cf, 0, "duplicate syslog \"tag\""); return NGX_CONF_ERROR; } /* * RFC 3164: the TAG is a string of ABNF alphanumeric characters * that MUST NOT exceed 32 characters. */ if (len - 4 > 32) { ngx_conf_log_error(NGX_LOG_EMERG, cf, 0, "syslog tag length exceeds 32"); return NGX_CONF_ERROR; } for (i = 4; i < len; i++) { c = ngx_tolower(p[i]); if (c < '0' || (c > '9' && c < 'a' && c != '_') || c > 'z') { ngx_conf_log_error(NGX_LOG_EMERG, cf, 0, "syslog \"tag\" only allows " "alphanumeric characters " "and underscore"); return NGX_CONF_ERROR; } } peer->tag.data = p + 4; peer->tag.len = len - 4; } else if (len == 10 && ngx_strncmp(p, "nohostname", 10) == 0) { peer->nohostname = 1; } else { ngx_conf_log_error(NGX_LOG_EMERG, cf, 0, "unknown syslog parameter \"%s\"", p); return NGX_CONF_ERROR; } next: if (comma == NULL) { break; } p = comma + 1; } return NGX_CONF_OK; } u_char * ngx_syslog_add_header(ngx_syslog_peer_t *peer, u_char *buf) { ngx_uint_t pri; pri = peer->facility * 8 + peer->severity; if (peer->nohostname) { return ngx_sprintf(buf, "<%ui>%V %V: ", pri, &ngx_cached_syslog_time, &peer->tag); } return ngx_sprintf(buf, "<%ui>%V %V %V: ", pri, &ngx_cached_syslog_time, &ngx_cycle->hostname, &peer->tag); } void ngx_syslog_writer(ngx_log_t *log, ngx_uint_t level, u_char *buf, size_t len) { u_char *p, msg[NGX_SYSLOG_MAX_STR]; ngx_uint_t head_len; ngx_syslog_peer_t *peer; peer = log->wdata; if (peer->busy) { return; } peer->busy = 1; peer->severity = level - 1; p = ngx_syslog_add_header(peer, msg); head_len = p - msg; len -= NGX_LINEFEED_SIZE; if (len > NGX_SYSLOG_MAX_STR - head_len) { len = NGX_SYSLOG_MAX_STR - head_len; } p = ngx_snprintf(p, len, "%s", buf); (void) ngx_syslog_send(peer, msg, p - msg); peer->busy = 0; } ssize_t ngx_syslog_send(ngx_syslog_peer_t *peer, u_char *buf, size_t len) { ssize_t n; if (peer->conn.fd == (ngx_socket_t) -1) { if (ngx_syslog_init_peer(peer) != NGX_OK) { return NGX_ERROR; } } /* log syslog socket events with valid log */ peer->conn.log = ngx_cycle->log; if (ngx_send) { n = ngx_send(&peer->conn, buf, len); } else { /* event module has not yet set ngx_io */ n = ngx_os_io.send(&peer->conn, buf, len); } if (n == NGX_ERROR) { if (ngx_close_socket(peer->conn.fd) == -1) { ngx_log_error(NGX_LOG_ALERT, ngx_cycle->log, ngx_socket_errno, ngx_close_socket_n " failed"); } peer->conn.fd = (ngx_socket_t) -1; } return n; } static ngx_int_t ngx_syslog_init_peer(ngx_syslog_peer_t *peer) { ngx_socket_t fd; fd = ngx_socket(peer->server.sockaddr->sa_family, SOCK_DGRAM, 0); if (fd == (ngx_socket_t) -1) { ngx_log_error(NGX_LOG_ALERT, ngx_cycle->log, ngx_socket_errno, ngx_socket_n " failed"); return NGX_ERROR; } if (ngx_nonblocking(fd) == -1) { ngx_log_error(NGX_LOG_ALERT, ngx_cycle->log, ngx_socket_errno, ngx_nonblocking_n " failed"); goto failed; } if (connect(fd, peer->server.sockaddr, peer->server.socklen) == -1) { ngx_log_error(NGX_LOG_ALERT, ngx_cycle->log, ngx_socket_errno, "connect() failed"); goto failed; } peer->conn.fd = fd; /* UDP sockets are always ready to write */ peer->conn.write->ready = 1; return NGX_OK; failed: if (ngx_close_socket(fd) == -1) { ngx_log_error(NGX_LOG_ALERT, ngx_cycle->log, ngx_socket_errno, ngx_close_socket_n " failed"); } return NGX_ERROR; } static void ngx_syslog_cleanup(void *data) { ngx_syslog_peer_t *peer = data; /* prevents further use of this peer */ peer->busy = 1; if (peer->conn.fd == (ngx_socket_t) -1) { return; } if (ngx_close_socket(peer->conn.fd) == -1) { ngx_log_error(NGX_LOG_ALERT, ngx_cycle->log, ngx_socket_errno, ngx_close_socket_n " failed"); } }