Kong's interaction with binary nginx access modules

[smanolache]

Hello,

I have a custom nginx access module. It executes before the lua module and sometimes it returns HTTP_UNAUTHORIZED. When this happens I get no response whatsoever from Kong (no headers, no body, the http connection is just closed). I get the following error in the logs:

failed to run header_filter_by_lua*: /usr/local/share/lua/5.1/kong.lua:218: attempt to index field 'plugin' (a nil value)

I suspect the following happens: the access_by_lua set by Kong is not executed any more => some ngx.ctx variables (ngx.ctx.api or ngx.ctx.stop_phases for example) are not set => they are checked/used later, for example in the {header|body}_filter_by_lua callbacks and, as they are not defined, those ngx.ctx variables cause errors in the lua interpreter.

I have replaced if not ngx.ctx.stop_phases then by if ngx.ctx.stop_phases ~= nil and not ngx.ctx.stop_phases then in the exec_plugins_{header|body}_filter in kong.lua and now I'm getting normal responses from kong, i.e. I'm getting the 401 Unauthorized header with the corresponding error message from nginx.

I propose that all kong lua callbacks check first for the existence of one ngx.ctx.api or ngx.ctx.plugin or ngx.ctx.stop_phases before taking action.

[thibaultcha]

Thanks for bringing this up, I'll take a look at changing it, but you can also submit your changes via a PR!

[smanolache]

I've created a pull request names "Issue 594" to address this issue.

[thibaultcha]

May I ask how exactly are you exiting from your module? For example with lua-nginx-module, if you call ngx.exit, then other context handlers are not supposed to be executed. Basically I do not understand why you are entering the header_filter_by_lua context if you are exiting before the Lua module.

[smanolache]

Here's a snippet of the code of my binary nginx module. It's really a binary handler, written in C and compiled into nginx. It has nothing to do with lua or ngx_lua_module, it does not "see" the ngx.exit function.

The handler is the only callback that my module sets. I have simplified the code, removed the conf directives and the conf creation and merging callbacks. I think the code below is sufficient for reproduction.

ngx_module_t ngx_http_check_digest_module = {
    NGX_MODULE_V1, &module_ctx, NULL, NGX_HTTP_MODULE, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NGX_MODULE_V1_PADDING
};

static ngx_http_module_t module_ctx = {
    NULL, &hook_setup, NULL, NULL, NULL, NULL, NULL, NULL
};

static ngx_int_t hook_setup(ngx_conf_t *cf) {
    ngx_http_handler_pt *h;
    ngx_http_core_main_conf_t *cmcf;
    cmcf = ngx_http_conf_get_module_main_conf(cf, ngx_http_core_module);
    h = ngx_array_push(&cmcf->phases[NGX_HTTP_ACCESS_PHASE].handlers);
    if (NULL == h)
        return NGX_ERROR;
    *h = &handler;
    return NGX_OK;
}

static ngx_int_t handler(ngx_http_request_t *r) {
   /* most of the time this function returns NGX_DECLINED */
   /* but sometimes it returns NGX_HTTP_UNAUTHORIZED */
   /* the function does not modify any field of the ngx_http_request_t structure */
   return NGX_HTTP_UNAUTHORIZED;
}

[thibaultcha]

Here's a snippet of the code of my binary nginx module. It's really a binary handler, written in C and compiled into nginx. It has nothing to do with lua or ngx_lua_module, it does not "see" the ngx.exit function.

Yes, it was my understanding already.

I will see into this.

[smanolache]

I've compiled nginx with debug symbols and I get the stack trace below. So the lua_header_filter callbacks are invoked when nginx tries to send the error response that was triggered by the binary module's HTTP_UNAUTHORIZED (ngx_http_finalize_request->...->ngx_http_send_special_response->ngx_http_send_header->...->ngx_http_lua_header_filter).

#0  ngx_http_lua_header_filter (r=0x18cd5e0) at ../ngx_lua-0.9.16/src/ngx_http_lua_headerfilterby.c:239
#1  0x00000000004963be in ngx_http_not_modified_header_filter (r=0x18cd5e0) at src/http/modules/ngx_http_not_modified_filter_module.c:61
#2  0x0000000000460f44 in ngx_http_send_header (r=0x18cd5e0) at src/http/ngx_http_core_module.c:1954
#3  0x0000000000469748 in ngx_http_send_special_response (r=0x18cd5e0, clcf=0x18e27c8, err=9) at src/http/ngx_http_special_response.c:662
#4  0x00000000004690fd in ngx_http_special_response_handler (r=0x18cd5e0, error=401) at src/http/ngx_http_special_response.c:474
#5  0x000000000046e3ff in ngx_http_finalize_request (r=0x18cd5e0, rc=401) at src/http/ngx_http_request.c:2327
#6  0x000000000045f338 in ngx_http_core_access_phase (r=0x18cd5e0, ph=0x1907790) at src/http/ngx_http_core_module.c:1121
#7  0x000000000045eb4d in ngx_http_core_run_phases (r=0x18cd5e0) at src/http/ngx_http_core_module.c:851
#8  0x000000000045eaba in ngx_http_handler (r=0x18cd5e0) at src/http/ngx_http_core_module.c:834
#9  0x000000000046d88a in ngx_http_process_request (r=0x18cd5e0) at src/http/ngx_http_request.c:1904
#10 0x000000000046c311 in ngx_http_process_request_headers (rev=0x190ec60) at src/http/ngx_http_request.c:1335

[thibaultcha]

I have compiled OpenResty with a similar module, found the issue, and will provide a fix for it in the refactor/resolver branch. Thanks for the report, I will let you know when it's done so you can try it out before we push a hotfix release.

[thibaultcha]

#708 now handles this properly, and I ended up refactoring kong.lua. Not sure it will be released in a hotfix, but definitely in the next version. If you need it for now I suggest sticking to checking the stop_phases variable for its initialization like you did.

Thank you for reporting this!