Opened 6 years ago

Closed 6 years ago

#625 closed defect (fixed)

access_log directive: if= bug for buffered logs

Reported by: Anton Yuzhaninov Owned by: Sergey Kandaurov
Priority: minor Milestone:
Component: nginx-core Version: 1.7.x
Keywords: Cc:
uname -a: FreeBSD aleph.mgmt.vega.ru 10.0-STABLE-20140715 FreeBSD 10.0-STABLE-20140715 #0 r268644M: Tue Jul 15 07:55:58 UTC 2014 root@aleph.mgmt.vega.ru:/usr/obj/usr/src/sys/MGMT amd64
nginx -V: nginx version: nginx/1.7.4
TLS SNI support enabled
configure arguments: --prefix=/usr/local/vega --with-cc-opt='-I /usr/local/include' --with-ld-opt='-L /usr/local/lib' --conf-path=/usr/local/vega/etc/service/nginx_frontend/nginx.conf --sbin-path=/usr/local/vega/sbin/nginx-frontend --pid-path=/usr/local/vega/run/nginx-frontend/nginx.pid --http-client-body-temp-path=/usr/local/vega/run/nginx-frontend/client_body_temp --http-proxy-temp-path=/usr/local/vega/run/nginx-frontend/proxy_temp --http-fastcgi-temp-path=/usr/local/vega/run/nginx-frontend/fastcgi_temp --http-log-path=/usr/local/vega/run/nginx-frontend/access_log --error-log-path=/usr/local/vega/run/nginx-frontend/error_log --with-http_ssl_module --with-http_stub_status_module --with-http_gzip_static_module --without-select_module --without-poll_module --without-http_browser_module --without-http_limit_conn_module --user=vega.www --group=vega.www --with-debug

Description

In nginx 1.7.0 the if= parameter was added to the access_log directive for conditional logging. This condition fails to work for buffered logs.

Example nginx config:

# ?x=[01] or no x
map $arg_x $x1 {
  default 1;
  2       0;
}
# ?x=2 only
map $arg_x $x2 {
  default 0;
  2       1;
}

server {
  ...
  access_log /var/log/nginx/access_log;
  ...
  location = /a.gif {
    empty_gif;
    access_log /var/log/nginx/x1_log http_log buffer=16k if=$x1;
    access_log /var/log/nginx/x2_log http_log buffer=16k if=$x2;
  }

  location = /b.gif {
    empty_gif;
    access_log /var/log/nginx/x1_log http_log buffer=16k if=$x1;
    access_log /var/log/nginx/x2_log http_log buffer=16k if=$x2;
}

Test load can be created with some benchmark, e. g. http_load with url_file

http://127.0.0.1/a.gif
http://127.0.0.1/a.gif?x=0
http://127.0.0.1/a.gif?x=1
http://127.0.0.1/a.gif?x=2
http://127.0.0.1/b.gif
http://127.0.0.1/b.gif?x=0
http://127.0.0.1/b.gif?x=1
http://127.0.0.1/b.gif?x=2

After test in the x1_log file I can see requests to /b.gif?x=2 and /b.gif, /b.gif?x=0 in the x2_log. This is wrong.

After removing buffer=16k from access_log directive condition works just fine.

Change History (6)

comment:1 by maxim, 6 years ago

Owner: set to Sergey Kandaurov
Status: newassigned

comment:2 by Valentin V. Bartenev, 6 years ago

Thanks for the report.

The problem is caused by duplicate "buffer" option. You don't need to specify it again for the same file, and the configuration below should work fine:

location = /a.gif {
    empty_gif;
    access_log /var/log/nginx/x1_log http_log buffer=16k if=$x1;
    access_log /var/log/nginx/x2_log http_log buffer=16k if=$x2;
}

location = /b.gif {
    empty_gif;
    access_log /var/log/nginx/x1_log http_log if=$x1;
    access_log /var/log/nginx/x2_log http_log if=$x2;
}

But anyway, this is a bug.

comment:3 by Anton Yuzhaninov, 6 years ago

Yes with buffer=16k only in first location, I can't repeat the problem. But it is handy to use includes e. g.

location = /a.gif {
  ...
  include logs.conf;
}

location = /b.gif {
  ...
  include logs.conf;
}

In this case buffer parameter will be repeated.

comment:4 by Valentin V. Bartenev, 6 years ago

This patch should fix the problem:

  • src/http/modules/ngx_http_log_module.c

    diff -r 3f5f0ab59b35 -r 9d737dbbd763 src/http/modules/ngx_http_log_module.c
    a b ngx_http_log_set_log(ngx_conf_t *cf, ngx  
    11361136    ngx_int_t                          gzip;
    11371137    ngx_uint_t                         i, n;
    11381138    ngx_msec_t                         flush;
    1139     ngx_str_t                         *value, name, s, filter;
     1139    ngx_str_t                         *value, name, s;
    11401140    ngx_http_log_t                    *log;
    11411141    ngx_syslog_peer_t                 *peer;
    11421142    ngx_http_log_buf_t                *buffer;
    process_formats:  
    12571257    size = 0;
    12581258    flush = 0;
    12591259    gzip = 0;
    1260     filter.len = 0;
    12611260
    12621261    for (i = 3; i < cf->args->nelts; i++) {
    12631262
    process_formats:  
    13251324        }
    13261325
    13271326        if (ngx_strncmp(value[i].data, "if=", 3) == 0) {
    1328             filter.len = value[i].len - 3;
    1329             filter.data = value[i].data + 3;
     1327            value[i].len -= 3;
     1328            value[i].data += 3;
     1329
     1330            ngx_memzero(&ccv, sizeof(ngx_http_compile_complex_value_t));
     1331
     1332            ccv.cf = cf;
     1333            ccv.value = &value[i];
     1334            ccv.complex_value = ngx_palloc(cf->pool,
     1335                                           sizeof(ngx_http_complex_value_t));
     1336            if (ccv.complex_value == NULL) {
     1337                return NGX_CONF_ERROR;
     1338            }
     1339
     1340            if (ngx_http_compile_complex_value(&ccv) != NGX_OK) {
     1341                return NGX_CONF_ERROR;
     1342            }
     1343
     1344            log->filter = ccv.complex_value;
     1345
    13301346            continue;
    13311347        }
    13321348
    process_formats:  
    14051421        log->file->data = buffer;
    14061422    }
    14071423
    1408     if (filter.len) {
    1409         log->filter = ngx_palloc(cf->pool, sizeof(ngx_http_complex_value_t));
    1410         if (log->filter == NULL) {
    1411             return NGX_CONF_ERROR;
    1412         }
    1413 
    1414         ngx_memzero(&ccv, sizeof(ngx_http_compile_complex_value_t));
    1415 
    1416         ccv.cf = cf;
    1417         ccv.value = &filter;
    1418         ccv.complex_value = log->filter;
    1419 
    1420         if (ngx_http_compile_complex_value(&ccv) != NGX_OK) {
    1421             return NGX_CONF_ERROR;
    1422         }
    1423     }
    1424 
    14251424    return NGX_CONF_OK;
    14261425}
    14271426

comment:5 by Valentin Bartenev <vbart@…>, 6 years ago

In e3016ee8dba396614f28a3644996b8cc6de8f9e3/nginx:

Access log: fixed the "if=" parameter with buffering (ticket #625).

It might not work if there were more than one "access_log" directives
pointed to the same file and duplicate buffer parameters.

comment:6 by Valentin V. Bartenev, 6 years ago

Resolution: fixed
Status: assignedclosed

The fix will be released with nginx 1.7.5.

Note: See TracTickets for help on using tickets.