Kong cache discrepancies declared shm vs kong.singleton

Paging @thibaultcha as I know the mlcache is your baby :slight_smile: . This may have impact dating back to your suggestion in:

Of breaking out separate lua_shared_dict’s to prevent a risk of rate limiting entries filling up the standard kong_cache.

Now onto my findings:

So I use a custom OIDC plugin where I cache userInfo that gets returned from an OIDC lookup. Where I take a session cookie as the key and userinfo in json as the value. Originally I wanted to break out where that cache gets stored too, so I added:

/blob/master/templates/optum_nginx.template

lua_shared_dict kong                5m;
lua_shared_dict kong_cache          ${{MEM_CACHE_SIZE}};

# Rate limit isolated shared dict
lua_shared_dict kong_ratelimit      10m;
# Optum OIDC limit isolated shared dict
lua_shared_dict kong_oidcusers 10m;

optum-kong-oidc-plugin/blob/master/access.lua -

local singletons = require "kong.singletons"
--Exclusive shm for oidc users
--local shm = ngx.shared.kong_oidcusers

And code like so(you can see singletons use vs my own shm):

  --local userInfo, err = shm:get(eoauth_token, { ttl = 28800 }, getUserInfo, access_token, callback_url, conf)
local userInfo, err = singletons.cache:get(eoauth_token, { ttl = 28800 }, getUserInfo, access_token, callback_url, conf)

The behavior is this:
Using the kong singletons.cache:get only has to make that call once and then its cached and behaving as expected. Using the shm I declared it seems to never get in the callback…

With singletons.cache:get:

2018/04/10 18:16:38 [error] 54#0: *9490 [lua] access.lua:42: getKongKey(): Can we get it from the cache?, client: 10.129.2.1, server: kong, request: "GET /oidc/test HTTP/1.1", host: "gateway.com"
2018/04/10 18:16:39 [error] 54#0: *9490 [lua] access.lua:27: In the Callback, not cached!, client: 10.129.2.1, server: kong, request: "GET /oidc/test HTTP/1.1", host: "gateway.com"
2018/04/10 18:16:39 [error] 54#0: *9490 [lua] access.lua:169: run(): Iterate on needed keys in header!, client: 10.129.2.1, server: kong, request: "GET /oidc/test HTTP/1.1", host: "gateway.com"
2018/04/10 18:17:03 [error] 55#0: *11643 [lua] access.lua:169: run(): Iterate on needed keys in header!, client: 10.130.4.1, server: kong, request: "GET /oidc/test HTTP/1.1", host: "gateway.com"
2018/04/10 18:17:06 [error] 55#0: *11643 [lua] access.lua:42: getKongKey(): Can we get it from the cache?, client: 10.130.4.1, server: kong, request: "GET /oidc/test HTTP/1.1", host: "gateway.com"
2018/04/10 18:17:06 [error] 55#0: *11643 [lua] access.lua:169: run(): Iterate on needed keys in header!, client: 10.130.4.1, server: kong, request: "GET /oidc/test HTTP/1.1", host: "gateway.com"

With shm:

Can we get it from the cache?, client: 10.129.2.1, server: kong, request: "GET /oidc/test HTTP/1.1", host: "gateway.com"
2018/04/10 21:53:23 [error] 55#0: *63306 lua coroutine: runtime error: ...e/lua/5.1/kong/plugins/optum-kong-oidc-plugin/access.lua:166: attempt to concatenate local 'userInfo' (a nil value)

^ Repeating that every time, like its not making it into the callback at all and object seems to be nil when I try to print it outside the lua method as the local result of getUserInfo() that calls the cache

Is this due to the fact my Plugin declares the shm in an access.lua file as opposed to an init.lua for plugins? Is this due to something special kong.singletons is doing to its kong_cache that separately created shm’s declared are not taking advantage of?

EDIT - I just reread your topic a bit cause I see you made more changes to your suggestion on rate limiting than last time I read that git issue. Maybe I need to add these to constants too:

kong/constants.lua

I will try a few more changes to see if I can get it working as I would anticipate like the default shm does. If fails then may need a little more guidance. Will update later tonight.

Thanks,
Jeremy

@jeremyjpj0916 Can you share the code? I don’t understand what you are trying to do just from those stacktraces.

@thibaultcha Thanks for the quick response, back on tonight continuing to debug because I thought I had it but alas still seems broken using an shm I declare other than the singletons instance. Here is the meat of it:

From my access.lua file (snipped to just include relevant details)

local singletons = require "kong.singletons"
--Exclusive shm for oidc users
local shm = ngx.shared.kong_oidcusers


local function getUserInfo(access_token, callback_url, conf)
    local httpc = http:new()
    local res, err = httpc:request_uri(conf.user_url, {
        method = "GET",
        ssl_verify = false,
        headers = {
          ["Authorization"] = "Bearer " .. access_token,
        }
    })
	
  ngx.log(ngx.ERR, "In the Callback, not cached!")
	
  -- redirect to auth if user result is invalid not 200
  if res.status ~= 200 then
    return redirect_to_auth(conf, callback_url)
  end

  local userJson = cjson.decode(res.body)

  return userJson
end

local function getKongKey(eoauth_token, access_token, callback_url, conf)
  -- This will add a 28800 second (8 hour) expiring TTL on this cached value
  -- https://github.com/thibaultcha/lua-resty-mlcache/blob/master/README.md
  ngx.log(ngx.ERR, "Can we get it from the cache?")
	
  local userInfo, err = shm:get(eoauth_token, { ttl = 28800 }, getUserInfo, access_token, callback_url, conf)
  --local userInfo, err = singletons.cache:get(eoauth_token, { ttl = 28800 }, getUserInfo, access_token, callback_url, conf)
	
  if err then
    ngx.log(ngx.ERR, "Could not retrieve UserInfo: ", err)
    return
  end
	
  return userInfo
end

And where its invoked way later down

 --Check boolean and then if EOAUTH has existing key -> userInfo value
  if conf.user_info_cache_enabled then
      local userInfo = getKongKey(encrypted_token, access_token, callback_url, conf)
      ngx.log(ngx.ERR, "User info found: " .. userInfo)
	if userInfo then
		  for i, key in ipairs(conf.user_keys) do
		   
		   ngx.log(ngx.ERR, "Iterate on needed keys in header!")
					
		   ngx.header["X-Oauth-".. key] = userInfo[key]
		   ngx.req.set_header("X-Oauth-".. key, userInfo[key])
                  end
   ....

So what I thought would help would be adding this to my constants.lua(I was missing this this afternoon):

  DICTS = {
    "kong",
    "kong_cache",
    "kong_process_events",
    "kong_cluster_events",
    "kong_healthchecks",
    "kong_oidcusers",
    "kong_ratelimit",
},

But still the behavior is when I use the shm I declared it will never enter the callback method at all because it never prints the:

  ngx.log(ngx.ERR, "In the Callback, not cached!")

portion of code to my logs, yet if I used the kong singletons instance it works fine. Nothing is printing from err either and the return of the getKongKey() method for the

local userInfo

is simply always nil. Maybe its not dangerous to let userInfo (which is a standard json response from REST OIDC user info endpoints) live in the kong_cache which gets used by singletons.cache:get call. But I thought it neat to break it out like you had shown in the earlier mentioned git issue and prevent any potential filling of the most important shm kong has.

As soon as I uncomment the Kong singletons cache calls it works like a charm always.

EDIT - honestly its not an issue. On the safe side I am going to bump up our kong_cache to 1024m, that should be a heck of a gracious amount of memory for any number of oidc users on an 8 hour ttl :smile: . I guess the main takeaway here is no, a declared SHM cannot be used like the kong singletons kong_cache can. And that’s due to all that logic that has already executed in cache.lua (I think) on the kong_cache compared to when you declare your own. BUT for rate limiting shm specifically in your prior bug fix discussion it does not even have the callback methods or such being used so its probably still works as you intended:

local newval, err = shm:incr(cache_key, value, 0)
....
local current_metric, err = shm:get(cache_key)

Thx.

It seems to me like you are confusing lua_shared_dict and lua-resty-mlcache? The former being one component of the later, which is a library built on top of it. A lua_shared_dict will not have all of the features an mlcache has, otherwise what would the point of the library be? See the signature for shm:get.

As a side note, in your callback, you have:

if res.status ~= 200 then
    return redirect_to_auth(conf, callback_url)
end

If this is interrupting the request phase and preventing the callback from properly returning (i.e. if you are calling ngx.say() or ngx.exit() in redirect_to_auth()), then this is wrong, and should be avoided. It will prevent mlcache from releasing the lock on the key.

1 Like

You are 100% correct I was missing the distinction, so declaring my own mlcache instance would prove a bit more complex, and can it even safely be declared within a plugin? Or best to use another declared singleton instance pointing to a different shm(I see cache.lua is hardcoded to kong_cache).

Also thanks for the catch, my redirect_to_auth() looks a bit like so:

function redirect_to_auth( conf, callback_url )
    -- Track the endpoint they wanted access to so we can transparently redirect them back
    if type(ngx.header["Set-Cookie"]) == "table" then
	ngx.header["Set-Cookie"] = { "EOAuthRedirectBack=" .. ngx.var.request_uri .. ";Path=/;Expires=" .. ngx.cookie_time(ngx.time() + 120) .. ";Max-Age=120;HttpOnly", unpack(ngx.header["Set-Cookie"]) }
    else
	ngx.header["Set-Cookie"] = { "EOAuthRedirectBack=" .. ngx.var.request_uri .. ";Path=/;Expires=" .. ngx.cookie_time(ngx.time() + 120) .. ";Max-Age=120;HttpOnly", ngx.header["Set-Cookie"] }
    end
	
    -- Redirect to the /oauth endpoint
    local oauth_authorize = nil
    if(conf.pf_idp_adapter_id == "") then --Standard Auth URL(Something other than ping)
       oauth_authorize = conf.authorize_url .. "?response_type=code&client_id=" .. conf.client_id .. "&redirect_uri=" .. callback_url .. "&scope=" .. conf.scope
    else --Ping Federate Auth URL
       oauth_authorize = conf.authorize_url .. "?pfidpadapterid=" .. conf.pf_idp_adapter_id .. "&response_type=code&client_id=" .. conf.client_id .. "&redirect_uri=" .. callback_url .. "&scope=" .. conf.scope
    end
    
    return ngx.redirect(oauth_authorize)
end

Are ngx.redirect() calls problematic as well? Do you have a better recommendation? So far the behavior seems desired and performing as expected from my findings, its a simple snippet that if the userInfo lookup fails then the obvious next move to me would be to redirect to the starting point of OIDC and having them login once again for a reattempt from the beginning. Cache lookup works without going into the call back and so forth. Hoping to release this plugin to the community soon so many can benefit! The more tools people have in the Kong arsenal the better. Appreciate your time looking at this.