Best Practice for logging with ngx.log?

ahvoldman · 2019-12-16T02:45:18+00:00

Thanks for the reply but while i went through the link and tried to install lua-resty-http and session or tried to tried to run command opm install zmar...

Best Practice for logging with ngx.log?

ahvoldman

I am using this frequently for debugging:

ngx.log( ngx.DEBUG, message, var1, var2, var3 )

Is there a best practice for logging that avoids the cost of the concatenation?

something like:

if ( log_level == ngx.DEBUG ) then

....

I was thinking I could declare a global variable in the init blocks. Is there an API to check the most verbose log level the error_logs are using?

I understand there can be several error_log defined at different levels

Thanks!

rpaprocki

you still have to pay the cost of assembling the message and calling ngx.log before it’s filtered out by the log level.

For really verbose/expensive logging that is reserved for development or debugging, I used a macro system (really just sed and a makefile) in the past to avoid calling the log functions at all. Made on-the-fly changes a bit more challenging, but it improved hot path performance markedly.

https://github.com/p0pr0ck5/lua-resty-waf/blob/master/tools/debug-macro.sh

Sent from my iPhone

On Dec 15, 2019, at 10:45, Andres Voldman <ahvo...@gmail.com> wrote:

I am using this frequently for debugging:

ngx.log( ngx.DEBUG, message, var1, var2, var3 )

Is there a best practice for logging that avoids the cost of the concatenation?
something like:

if ( log_level == ngx.DEBUG ) then
....

I was thinking I could declare a global variable in the init blocks. Is there an API to check the most verbose log level the error_logs are using?
I understand there can be several error_log defined at different levels

Thanks!

ahvoldman

Hi, Thanks for your answer

Regarding this: "you still have to pay the cost of assembling the message and calling ngx.log before it’s filtered out by the log level. "

if the ngx.log is inside the if statement, there should not be any concatenation cost, just the cost of evaluating the variable

I found this:

local errlog = require "ngx.errlog"

log_level = errlog.get_sys_filter_level()

I don't know how expensive errlog.get_sys_filter_level() is. I guess it would be best to store the result in a global variable and use the variable

instead.

I will review your technique as well. Thanks again

PS: I just did a quick test with this

init_by_lua_block {

local errlog = require "ngx.errlog"

glog_level = errlog.get_sys_filter_level()

}

but didn't work. It's like the logs are configured after init_by_lua_block runs. get_sys_filter_level() works fine from within my application.
I will need to debug it a bit more

On Sunday, December 15, 2019 at 5:05:07 PM UTC-5, rpaprocki wrote:

you still have to pay the cost of assembling the message and calling ngx.log before it’s filtered out by the log level.

For really verbose/expensive logging that is reserved for development or debugging, I used a macro system (really just sed and a makefile) in the past to avoid calling the log functions at all. Made on-the-fly changes a bit more challenging, but it improved hot path performance markedly.

https://github.com/p0pr0ck5/lua-resty-waf/blob/master/tools/debug-macro.sh

Sent from my iPhone

On Dec 15, 2019, at 10:45, Andres Voldman <ahvo...@gmail.com> wrote:

I am using this frequently for debugging:

ngx.log( ngx.DEBUG, message, var1, var2, var3 )

Is there a best practice for logging that avoids the cost of the concatenation?
something like:

if ( log_level == ngx.DEBUG ) then
....

I was thinking I could declare a global variable in the init blocks. Is there an API to check the most verbose log level the error_logs are using?
I understand there can be several error_log defined at different levels

Thanks!

ahvoldman

I don't see how to edit my previous reply

looking briefly at code, it uses the request object

function _M.get_sys_filter_level()

local r = get_request()

return tonumber(ngx_lua_ffi_errlog_get_sys_filter_level(r))

end

so I guess I need to call "errlog.get_sys_filter_level()" at least once per request

On Monday, December 16, 2019 at 11:26:29 AM UTC-5, Andres Voldman wrote:

Hi, Thanks for your answer

Regarding this: "you still have to pay the cost of assembling the message and calling ngx.log before it’s filtered out by the log level. "

if the ngx.log is inside the if statement, there should not be any concatenation cost, just the cost of evaluating the variable

I found this:

local errlog = require "ngx.errlog"
log_level = errlog.get_sys_filter_level()

I don't know how expensive errlog.get_sys_filter_level() is. I guess it would be best to store the result in a global variable and use the variable
instead.

I will review your technique as well. Thanks again

PS: I just did a quick test with this
init_by_lua_block {
local errlog = require "ngx.errlog"
glog_level = errlog.get_sys_filter_level()
}

but didn't work. It's like the logs are configured after init_by_lua_block runs. get_sys_filter_level() works fine from within my application.
I will need to debug it a bit more

On Sunday, December 15, 2019 at 5:05:07 PM UTC-5, rpaprocki wrote:
you still have to pay the cost of assembling the message and calling ngx.log before it’s filtered out by the log level.

For really verbose/expensive logging that is reserved for development or debugging, I used a macro system (really just sed and a makefile) in the past to avoid calling the log functions at all. Made on-the-fly changes a bit more challenging, but it improved hot path performance markedly.

https://github.com/p0pr0ck5/lua-resty-waf/blob/master/tools/debug-macro.sh

Sent from my iPhone

On Dec 15, 2019, at 10:45, Andres Voldman <ahvo...@gmail.com> wrote:

I am using this frequently for debugging:

ngx.log( ngx.DEBUG, message, var1, var2, var3 )

Is there a best practice for logging that avoids the cost of the concatenation?
something like:

if ( log_level == ngx.DEBUG ) then
....

I was thinking I could declare a global variable in the init blocks. Is there an API to check the most verbose log level the error_logs are using?
I understand there can be several error_log defined at different levels

Thanks!