Blank lines in nginx access logs

[ro...@bidstalk.com]

Hi,

I have setup my access logs configuration in nginx and it currently looks like this 

location / {

 set NGX_FILE_VAR1 = "";

 set NGX_FILE_VAR2 = "";

 

 log_format FILE_VAR_FORMAT1 $NGX_FILE_VAR1;

 access_log "/path/to/logfile1.log" FILE_VAR_FORMAT1;

 log_format FILE_VAR_FORMAT2 $NGX_FILE_VAR2;

 access_log "/path/to/logfile2.log" FILE_VAR_FORMAT2;

}

The issue I am seeing is that one of the access_log file is getting lots of blank lines. I am getting a blank line per request to server. When the server gives a response I see proper log values that I am setting in ngx.var.NGX_FILE_VAR1 and ngx.var.NGX_FILE_VAR2, but even for ignored requests when I am not setting values in these variables, I am seeing blank lines printed to the log files.

I am not sure if my way of setting up multiple access_log files as mentioned above is wrong.

Please Help. Please let me know if more information is required.

Thanks,

Roop

[Yichun Zhang (agentzh)]

Hello!

On Mon, May 12, 2014 at 10:07 AM, roop wrote:
> I have setup my access logs configuration in nginx and it currently looks
> like this
>
> location / {
> set NGX_FILE_VAR1 = "";
> set NGX_FILE_VAR2 = "";
>
> log_format FILE_VAR_FORMAT1 $NGX_FILE_VAR1;
> access_log "/path/to/logfile1.log" FILE_VAR_FORMAT1;
>
> log_format FILE_VAR_FORMAT2 $NGX_FILE_VAR2;
> access_log "/path/to/logfile2.log" FILE_VAR_FORMAT2;
>

Have you ever tested your configuration snippet above on your side? It
contains obvious mistakes and nginx won't even load it:

[emerg] 5156#0: invalid number of arguments in "set" directive

Check out nginx's official documentation for the "set" directive for
the correct usage:

http://nginx.org/en/docs/http/ngx_http_rewrite_module.html#set

Please do not be too lazy to even test out your pasted configurations,
otherwise I may not take you seriously enough. One suggestion is
always to copy & paste your tested configurations to save others'
time.

Also, for a minimal and complete use case, you also need to provide
your test requests and steps to reproduce the issue reliably in
others' boxes :)

Always providing the versions of the related software you're using
(like your nginx's and your OS's versions) is also considered a good
habit :)

Best regards,
-agentzh

[ro...@bidstalk.com]

Hi azentzh,

Sorry for the wrong variable declaration in the previous post.

Here is the updated format, I typed it incorrectly while posting by mistake

location / {

 set $NGX_FILE_VAR1 "";

 set $NGX_FILE_VAR2 "";

 content_by_lua_file code/init_req.lua;

 

 log_format FILE_VAR_FORMAT1 $NGX_FILE_VAR1;

 access_log "/path/to/logfile1.log" FILE_VAR_FORMAT1;

 log_format FILE_VAR_FORMAT2 $NGX_FILE_VAR2;

 access_log "/path/to/logfile2.log" FILE_VAR_FORMAT2;

}

Request to server : curl -v localhost --header "host:sandbox.bids.stg.bidstalk.com" --data '{"at":2,"device":{"connectiontype":0,"devicetype":1,"geo":{"country":"JPN","region":"Gunma","lat":34.3853,"lon":132.4553,"type":3,"zip":"00051"},"ip":"58.183.128.0","carrier":"SoftBank JP","didsha1":"23456789922","js":1,"make":"Apple","model":"iPhone5","os":"iOS","ua":"Mozilla/5.0 (iPhone; CPU iPhone OS 6_1_1 like Mac OS X) AppleWebKit/536.26 (KHTML, like Gecko) Version/6.0 Mobile/10B145 Safari/8536.25"},"ext":{"udi":{}},"id":"r9r2HHDrAs","imp":[{"banner":{"btype":[1,2,3,4],"h":50,"mimes":["image/png","image/jpg","image/gif"],"pos":0,"w":320},"displaymanager":"SOMA","displaymanagerver":"somaapi-400","id":"1"},{"banner":{"btype":[1,2,3,4],"h":50,"mimes":["image/png","image/jpg","image/gif"],"pos":0,"w":320},"displaymanager":"SOMA","displaymanagerver":"somaapi-400","id":"2"}],"site":{"cat":["IAB1"],"domain":"www.matomy997.com","id":"65758263","name":"NetworkPub_F_997(kk)","publisher":{"id":"923838746"}},"user":{}}'

OS_Version : CentOS release 6.5 (Final)

Nginx Version : ngx_openresty-1.2.6.6

Steps to reproduce :

-Add the access_log to your config as mentioned above.

-Send the curl request

-During curl the content_by_lua file code will be executed, try setting values the variables declared in ngx.var[NGX_FILE_VAR1] or ngx.var[NGX_FILE_VAR2] for the request and see that there are blank lines coming in one of the access_log files.

-What I am seeing on my end is that for the condition when I am not logging anything to one of the files, blank lines are being printed into that file, while the other access_log file gets the parameters I want to log. Also the same blank line behavior is happening in both access_log files if I disable the code in lua which sets the variables (I was expecting that in this case nothing should come to access_logs).

Some of these request responses are to be logged into one access_log file and for other types of headers in the request some response values are to be logged into another access_log file, but blank lines are coming constantly per request in one of the access_log files as mentioned in the previous post.

Please let me know in case any more information is required.

Thanks,

Roop

[Yichun Zhang (agentzh)]

Hello!

On Mon, May 12, 2014 at 11:40 PM, roop wrote:
> Also the
> same blank line behavior is happening in both access_log files if I disable
> the code in lua which sets the variables (I was expecting that in this case
> nothing should come to access_logs).
>

What you're seeing should be the expected behavior of the standard
ngx_http_log_module you're using. No matter your nginx variables'
values are empty or not, ngx_http_log_module will append a newline
character for you anyway.

For your requirements, you'd better roll out your own logger in Lua or
something else. See
https://github.com/cloudflare/lua-resty-logger-socket for an example.

Regards,
-agentzh

[ro...@bidstalk.com]

Hi azentzh,

Yeah we also figured that nginx tries to print to all the access logs in a location for a request match.

So we have set the access_logs up under different server url and locations and not seeing blank lines, kind of a workaround.

Thanks for the help and looking into the issue.

-Roop

On Monday, May 12, 2014 10:37:31 PM UTC+5:30, ro...@bidstalk.com wrote: