Skip to content

Fix OpenResty race condition from global logging variable initialization#170

Open
Copilot wants to merge 2 commits intomasterfrom
copilot/fix-invalid-request-size-error
Open

Fix OpenResty race condition from global logging variable initialization#170
Copilot wants to merge 2 commits intomasterfrom
copilot/fix-invalid-request-size-error

Conversation

Copy link

Copilot AI commented Feb 5, 2026

The lualogging library creates a global logging variable at module load time. In OpenResty's concurrent environment, multiple workers initializing this global simultaneously causes race condition warnings and potential failures when creating multiple Enforcer instances.

Changes

  • Lazy load logging dependencies in src/util/Log.lua

    • Moved require "logging" inside getLogger()
    • Moved require "logging.file" inside getFileLogger()
    • Defers initialization until function call, avoiding concurrent module-level execution
  • Added regression test in tests/main/multi_enforcer_spec.lua

    • Validates multiple newEnforcerFromText calls work without race conditions
    • Covers the exact scenario from the reported issue

Example

Before:

-- Module-level requires execute during init, causing race conditions
local Logging = require "logging"
local fileLogging = require "logging.file"

function Log.getLogger()
    -- Uses already-loaded Logging
end

After:

function Log.getLogger()
    -- Load only when needed, in request context
    local Logging = require "logging"
    -- ... rest of implementation
end

Lua's require caches modules, so subsequent calls return the cached instance without re-execution.

Original prompt

This section details on the original issue you should resolve

<issue_title>ERROR: invalid request size</issue_title>
<issue_description>>test code

local Enforcer1 = require("casbin")
local Enforcer2 = require("casbin")

local model1 = [[
    [request_definition]
    r = path, method

    [policy_definition]
    p = path, method, eft

    [policy_effect]
    e = some(where (p.eft == allow)) && !some(where (p.eft == deny))

    [matchers]
    m = regexMatch(r.path, p.path) && keyMatch(r.method, p.method)
]]

local policy1 =[[
    p, ^/cate/sample/gen_label_no,              POST, allow
    p, ^/cate/sample/.*/[print|reprint],        PUT,  allow
]]

local model2 = [[
    [request_definition]
r = user, path, method

[policy_definition]
p = role, path, method

[role_definition]
g = _, _

[policy_effect]
e = some(where (p.eft == allow))

[matchers]
m = (g(r.user, p.role) || keyMatch(r.user, p.role)) && regexMatch(r.path, p.path) && keyMatch(r.method, p.method)
]]

local policy2 =[[

p, *,          ^/$,                         GET
p, *,          ^/portal,                    GET
p, *,          ^/admin,                     GET

p, sys-admin,  *,                           *
g, sys-admin,       guests
]]

local ex2 = Enforcer2:newEnforcerFromText(model2, policy2)

local pass2 =  ex2:enforce("guests", "/", "GET")
print( "pass2:",pass2)



local ex1 = Enforcer1:newEnforcerFromText(model1, policy1)

local pass1 =  ex1:enforce("/cate/sample/gen_label_no", "POST")
print( "pass1: ",pass1)


local pass3 =  ex2:enforce("guests", "/", "GET")

print( "pass3: ",pass3)

error info

$ resty t-casbin.lua                                                                                                                                           [18:08:36]
2023/10/05 18:08:38 [warn] 2508#0: *2 [lua] _G write guard:12: __newindex(): writing a global Lua variable ('logging') which may lead to race conditions between concurrent requests, so prefer the use of 'local' variables
stack traceback:
        /usr/local/openresty/luajit/share/lua/5.1/logging.lua:465: in main chunk
        [C]: in function 'require'
        /usr/local/openresty/luajit/share/lua/5.1/src/util/Log.lua:15: in main chunk
        [C]: in function 'require'
        ...ocal/openresty/luajit/share/lua/5.1/src/model/Policy.lua:16: in main chunk
        [C]: in function 'require'
        ...local/openresty/luajit/share/lua/5.1/src/model/Model.lua:16: in main chunk
        [C]: in function 'require'
        ...openresty/luajit/share/lua/5.1/src/main/CoreEnforcer.lua:18: in main chunk
        [C]: in function 'require'
        ...
        ...sty/luajit/share/lua/5.1/src/main/ManagementEnforcer.lua:15: in main chunk
        [C]: in function 'require'
        ...cal/openresty/luajit/share/lua/5.1/src/main/Enforcer.lua:15: in main chunk
        [C]: in function 'require'
        /usr/local/openresty/luajit/share/lua/5.1/casbin.lua:16: in main chunk
        [C]: in function 'require'
        t-casbin.lua:1: in function 'file_gen'
        init_worker_by_lua(nginx.conf:185):45: in function <init_worker_by_lua(nginx.conf:185):43>
        [C]: in function 'xpcall'
        init_worker_by_lua(nginx.conf:185):52: in function <init_worker_by_lua(nginx.conf:185):50>, context: ngx.timer
INFOModel: 

INFO[e.e]:
INFO{RM = {}, key = "e", policy = {}, policyMap = {}, priorityIndex = -1, tokens = {}, value = "some(where (p_eft == allow))"}
INFO[g.g]:
INFO{RM = {}, key = "g", policy = {}, policyMap = {}, priorityIndex = -1, tokens = {}, value = "_, _"}
INFO[r.r]:
INFO{RM = {}, key = "r", policy = {}, policyMap = {}, priorityIndex = -1, tokens = {"r_user", "r_path", "r_method"}, value = "user, path, method"}
INFO[p.p]:
INFO{RM = {}, key = "p", policy = {}, policyMap = {}, priorityIndex = -1, tokens = {"p_role", "p_path", "p_method"}, value = "role, path, method"}
INFO[m.m]:
INFO{RM = {}, key = "m", policy = {}, policyMap = {}, priorityIndex = -1, tokens = {}, value = "(g(r_user, p_role) || keyMatch(r_user, p_role)) && regexMatch(r_path, p_path) && keyMatch(r_method, p_method)"}
INFORequest: guests, /, GET ---> true
Hit Policy: { *, ^/$, GET }
pass2:true
INFOModel: 

INFO[p.p]:
INFO{RM = {}, key = "p", policy = {}, policyMap = {}, priorityIndex = -1, tokens = {"p_path", "p_method", "p_eft"}, value = "path, method, eft"}
INFO[m.m]:
INFO{RM = {}, key = "m", policy = {}, policyMap = {}, priorityIndex = -1, tokens = {}, value = "regexMatch(r_path, p_path) && keyMatch(r_method, p_method)"}
INFO[e.e]:
INFO{RM = {}, key = "e", policy = {}, policyMap = {}, priorityIndex = -1, tokens = {}, value = "some(where (p_eft == allow)) && !some(where (p_eft == deny))"}
INFO[r.r]:
INFO{RM = {}, key = "r", policy = {}, policyMap = {}, priorityIndex = -1, tokens = {"r_path", "r_method"}, value = "path, method"}
INFORequest: /cate/sample/gen_label_no, POST ---> true

pass1...

</details>



<!-- START COPILOT CODING AGENT SUFFIX -->

- Fixes casbin/lua-casbin#152

<!-- START COPILOT CODING AGENT TIPS -->
---

💡 You can make Copilot smarter by setting up custom instructions, customizing its development environment and configuring Model Context Protocol (MCP) servers. Learn more [Copilot coding agent tips](https://gh.io/copilot-coding-agent-tips) in the docs.

@CLAassistant
Copy link

CLA assistant check
Thank you for your submission! We really appreciate it. Like many open source projects, we ask that you sign our Contributor License Agreement before we can accept your contribution.
You have signed the CLA already but the status is still pending? Let us recheck it.

Co-authored-by: hsluoyz <3787410+hsluoyz@users.noreply.github.com>
Copilot AI changed the title [WIP] Fix error for invalid request size issue Fix OpenResty race condition from global logging variable initialization Feb 5, 2026
Copilot AI requested a review from hsluoyz February 5, 2026 03:25
@hsluoyz hsluoyz marked this pull request as ready for review February 5, 2026 06:53
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants