lua-resty-redis icon indicating copy to clipboard operation
lua-resty-redis copied to clipboard

Bad Request : in function 'send'

Open rushi47 opened this issue 5 years ago • 7 comments
trafficstars

@agentzh Hope you are doing great :), I followed your comments and the issues you have solved for #44 and #104. But am still getting the same issue, for sure its because of my poor understanding and apologise for the same in advance. But am struggling to understand "resty.redis" part in the comment which you have mentioned in all the issues.

Below is the snippet of My Code which i tried and am still facing the issue.

Problem : I want to calculate the time redis takes to connect and do operation if its more than 0.100 i log it. To do that, i have overridden every method (Sharing only two here - new & get | And i Know there must be some better approach than this would love to know that too ).

- redis_extended.lua

local redis_import = require "resty.redis"
local red_mod = {}
function red_mod:new(o, ngx)
	o = o or {}
	setmetatable(o, self) -- http://lua-users.org/wiki/MetamethodsTutorial
	self.__index = self
	self.ngx = ngx
	self.redis = redis_import:new()
	return o
end

function red_mod:get(key)
	local start_time = self.ngx.now()

 --  local redis = require "resty.redis" 

> if i uncomment above line and use below redis:get instead of self.get 
>   everything works fine 
> (this is what i think from initial steps and am getting more confused
>  because of this cause at this point am not even initialising the object)

	local ok, err = self.redis:get(key)
	local end_time = self.ngx.now() - start_time
	if end_time > 0.100 then
		self.ngx.log(self.ngx.ERR, "!@@! Execution Time for REDIS:GET Operation :- ", end_time)
	end
	return ok, err
end

return red_mod

And am calling this in the other modules, which is part of nginx co-routine. So if above code is used in one module it doesnt break as soon as i use this in other modules it fails.

       local redis = require "eg-modules.redis_extended"
        local red = redis:new(nil, ngx)
	red:set_timeout(1000) -- 1 sec
	local ok, err = red:connect(redis_health_check_host, redis_health_check_port)
	if not ok then
		ngx.log(ngx.ERR,"failed to connect: ", err)
		return
	end
	local key = module.get_request_key(http_x_egnyte_request_id)
	**-- Thing breaks here, in Get call**
        local ok, err = red:get(key .. '.bck')

Everything works until the red:get call arrives, and at this point it throws the error. It will be great help, if you can point out in the code where i am going wrong. And on how to achieve this using any code snippet :-

Never ever share any cosocket objects (or any objects wrapping cosockets, like resty.redis objects) across the request handler boundary!


Out of Context- And to have understanding of nginx in depth & lua (so that i dont ask such dumb questions) can you share in links (books, videos, docs). Thanks a lot in advance :) .

Originally posted by @rushi47 in https://github.com/openresty/lua-resty-redis/issues/165#issuecomment-582836250

rushi47 avatar Feb 06 '20 10:02 rushi47

@rushi47 Your example is incomplete. We need something that we can directly run and reproduce the problem easily on our side. It's still not clear for example that how your Lua code snippets are run (in what contexts).

You are getting that error because the redis object was created in a different request context than the one using the redis object.

BTW, nginx has no coroutines. Coroutines are a Lua thing. Specifically OpenResty implements the "light thread" atop Lua's coroutines. What really matter here is "light threads".

agentzh avatar Feb 09 '20 18:02 agentzh

@rushi47 Also, you called the connect() method in your top-level code, but it is never defined in your "eg-modules.redis_extended" module.

agentzh avatar Feb 09 '20 18:02 agentzh

@agentzh, First of all Thanks a lot for the reply. I think i missed few things while explaining. Let me paste the full code.

@rushi47 Also, you called the connect() method in your top-level code, but it is never defined in your "eg-modules.redis_extended" module.

I didnt paste that method, the connect method is also defined in the code i just paste the method which i was facing issue in, let me paste the whole code.

Just to give top flow redis_extended.lua functions are called in utils.lua and utils.lua is part of nginx event processing. Pasting all the three code in Sequence.

  1. redis_extended.lua
local redis_import = require "resty.redis"
local red_mod = {}


function red_mod:new(o, ngx)
	o = o or {}
	setmetatable(o, self) -- http://lua-users.org/wiki/MetamethodsTutorial
	self.__index = self
	self.ngx = ngx
	self.redis = redis_import:new()
	return o
end


function red_mod:connect(redis_health_check_host, redis_health_check_port)
	local ok, err = self.redis:connect(redis_health_check_host, redis_health_check_port)
	return ok, err
end

function red_mod:incrby(key, value)
	local start_time = self.ngx.now() -- return time in seconds
	local ok, err = self.redis:incrby(key, value)
	local end_time = self.ngx.now() - start_time
	if end_time > 0.100 then
		self.ngx.log(self.ngx.ERR, "!@@! Time taken for REDIS:IncrBy Operation :- ", end_time)
	end
	return ok, err
end


function red_mod:set_keepalive(seconds, pool_size)
	local ok, err = self.redis:set_keepalive(10000, 50)
	return ok, err
end


function red_mod:set_timeout(seconds)
	self.redis:set_timeout(seconds)
end

function red_mod:del(key)
	local start_time = self.ngx.now() -- return time in seconds
	local ok, err = self.redis:del(key)
	local end_time = self.ngx.now() - start_time
	if end_time > 0.100 then
		self.ngx.log(self.ngx.ERR, "!@@! Execution Time for REDIS:DEL Operation :- ", end_time)
	end
	return ok, err
end

function red_mod:set(key, value)
	local start_time = self.ngx.now() -- return time in seconds
	local ok, err = self.redis:set(key, value)
	local end_time = self.ngx.now() - start_time
	if end_time > 0.100 then
		self.ngx.log(self.ngx.ERR, "!@@! Execution Time for REDIS:SET Operation :- ", end_time)
	end
	return ok, err
end


function red_mod:get(key)
	self.ngx.log(self.ngx.ERR, "!@@! Execution Time for REDIS:GET Operation :- ", key)
	local start_time = self.ngx.now() -- return time in seconds
	-- local redis = require "resty.redis"
	local ok, err = self.redis:get(key)
	local end_time = self.ngx.now() - start_time
	if end_time > 0.100 then
		self.ngx.log(self.ngx.ERR, "!@@! Execution Time for REDIS:GET Operation :- ", end_time)
	end
	return ok, err
end

function red_mod:expire(key, key_expiry)
	local start_time = self.ngx.now() -- return time in seconds
	local ok, err = self.redis:expire(key, key_expiry)
	local end_time = self.ngx.now() - start_time
	if end_time > 0.100 then
		self.ngx.log(self.ngx.ERR, "!@@! Execution Time for REDIS:EXPIRE Operation :- ", end_time)
	end
	return ok, err
end


return red_mod
  1. utils.lua
require "socket"

local redis = require "abc-modules.redis_extended"
-- key expiry is 3 hours - 10800 seconds
local KEY_EXPIRY = 10800
local module = {}
local last_health_check_ok_at = nil
local ngx_re = require "ngx.re"

function module.get_request_key(http_x_ABC_request_id)

	local key = string.format("eg.rrequest.%s", http_x_ABC_request_id)
	return key

end

function module.create_request_value(http_host, request_uri, http_x_ABC_kong_upstream, http_x_ABC_proxy, http_x_ABC_request_id)
	request_uri = string.sub((ngx_re.split(request_uri, "\\?")[1]),1,30)
	local value = string.format("%s|%s|%s|%s|%s|%s", http_host, request_uri, 
			http_x_ABC_kong_upstream, http_x_ABC_proxy, http_x_ABC_request_id, ngx.now())
	return value
end

function module.remove_redis_key(premature, redis_health_check_host, redis_health_check_port,
		http_host, request_uri, http_x_ABC_kong_upstream, http_x_ABC_proxy, 
		http_x_ABC_request_id)
	
	local red = redis:new(nil, ngx)
	red:set_timeout(1000) -- 1 sec
	local ok, err = red:connect(redis_health_check_host, redis_health_check_port)
	if not ok then
		ngx.log(ngx.ERR, "failed to connect: ", err)
		return
	end
	local key = module.get_request_key(http_x_ABC_request_id)
	local ok, err = red:del(key)
	ngx.log(ngx.DEBUG, ' !!!!!  REMOVE KEY ::: --  ', key, ' Redis Reply ::-- ', ok, " ERR : ", err)
	if tonumber(ok) == 0 then
		key = key .. '.bck'
		ngx.log(ngx.DEBUG, "!!!..Unable to find the existing key, creating bkp KEY ::-  ", key, ",", err)		
		local value = module.create_request_value(http_host, request_uri, http_x_ABC_kong_upstream, http_x_ABC_proxy, http_x_ABC_request_id)
		local ok, err = red:set(key, value)
		if not ok then
			ngx.log(ngx.ERR, 'Unable to set the back value')
		end
		red:expire(key, KEY_EXPIRY)
	end

    -- put it into the connection pool of size 50,
    -- with 10 seconds max idle time
    local ok, err = red:set_keepalive(10000, 50)
    if not ok then
		ngx.say("failed to set keepalive: ", err)
		return
    end

end

function module.end_request()
	local ok, err = ngx.timer.at(1, module.remove_redis_key,
		ngx.var.redis_health_check_host, ngx.var.redis_health_check_port,
		ngx.var.http_host, ngx.var.request_uri, ngx.var.http_x_ABC_kong_upstream, ngx.var.http_x_ABC_proxy, 
		ngx.var.http_x_ABC_request_id)

	if not ok then
		ngx.log(ngx.ERR, "Could not submit job: ", err)
		return
	end

end

function module.start_request()

	local ok, err = ngx.timer.at(0, module.set_redis_key,
		ngx.var.redis_health_check_host, ngx.var.redis_health_check_port,
		ngx.var.http_host, ngx.var.request_uri, ngx.var.http_x_ABC_kong_upstream, ngx.var.http_x_ABC_proxy,
		ngx.var.http_x_ABC_request_id)

	if not ok then
		ngx.log(ngx.ERR, "Could not submit job: ", err)
		return
	end

end


function module.set_redis_key(premature, redis_health_check_host, redis_health_check_port,
        http_host, request_uri, http_x_ABC_kong_upstream, http_x_ABC_proxy, 
        http_x_ABC_request_id)
	local red = redis:new(nil, ngx)
	red:set_timeout(1000) -- 1 sec
	local ok, err = red:connect(redis_health_check_host, redis_health_check_port)
	if not ok then
		ngx.log(ngx.ERR,"failed to connect: ", err)
		return
	end
	local key = module.get_request_key(http_x_ABC_request_id)
	local ok, err = red:get(key .. '.bck')
	ngx.log(ngx.DEBUG, ' !!!!!  KEY ::: --  ', key, ' Type : ', type(ok) ,' Redis Reply ::-- ', ok, " ERR : ", err)
	-- not ok means redis error and return 
	-- if ok == nil that means kye no found
	if not ok then
		ngx.log(ngx.ERR, 'Seems some issue with nginx !')
		return
	elseif ok == ngx.null then
		ngx.log(ngx.DEBUG, ' !!!.. Setting the new key :::: -- ')
		local value = module.create_request_value(http_host, request_uri, http_x_ABC_kong_upstream, http_x_ABC_proxy, http_x_ABC_request_id)
		ok, err = red:set(key, value)
		if not ok then
			ngx.log(ngx.ERR, "!!!..Unable to set the initial key: ", key, ", ::::: - ", ok)		
			return
		end
	else
		ngx.log(ngx.ERR, ' !!!!! Deleting the backlog KEY ::: --  ', key)
		local ok, err = red:del(key .. '.bck')
		ngx.log(ngx.ERR,' Redis Reply ::-- ', ok, " ERR : ", err)
		if not ok then
			ngx.log(ngx.ERR, 'Unable to del the backlog key !')
		end
	end
	red:expire(key, KEY_EXPIRY)
    -- put it into the connection pool of size 50,
    -- with 10 seconds max idle time
    local ok, err = red:set_keepalive(10000, 50)
    if not ok then
		ngx.say("failed to set keepalive: ", err)
		return
    end

end

  1. Nginx.conf
     init_by_lua_block {
             require 'luarocks.loader'
             require 'resty.core'

            ABC_utils = require 'ABC-modules.utils'
     }
     
       location / {
        set $upstream_host nil;
        set $upstream_scheme nil;

		set $redis_health_check_host "<%= scope['::XYZ::config::redis_host'] %>";
		set $redis_health_check_port <%= scope['::XYZ::config::redis_port'] %>;
		set $eg_rule_name  "";
		set $eg_identifier "";

        rewrite_by_lua_block {
        }

        access_by_lua_block {
	   ABC_utils.start_request()
        }

        proxy_http_version 1.1;
        proxy_set_header X-Real-IP $remote_addr;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_set_header Upgrade $upstream_upgrade;
        proxy_set_header Connection $upstream_connection;
        proxy_pass_header Server;
	proxy_set_header Host $host;
        proxy_set_header Range $http_range;

        proxy_ssl_name $upstream_host;

        header_filter_by_lua_block {
            
        }

        body_filter_by_lua_block {
            
        }

        log_by_lua_block {
	  ABC_utils.end_request()
        }
    }

rushi47 avatar Feb 10 '20 05:02 rushi47

@agentzh , Did you get any chance to look at it ? Thanks

rushi47 avatar Feb 13 '20 15:02 rushi47

@rushi47 can you provide a smaller case to reproduce it in our side? the current lua code that you provided is too long.

doujiang24 avatar Feb 15 '20 15:02 doujiang24

@doujiang24, Ok let me try again :-

  • Initialise the module in nginx.conf

init_by_lua_block {
             require 'luarocks.loader'
             require 'resty.core'

            ABC_utils = require 'ABC-modules.utils'
     }

  • Calling it in Access by Lua block :-
        access_by_lua_block {
	   ABC_utils.start_request()
        }
  • Method of the module
require "socket"

**local redis = require "abc-modules.redis_extended"**
-- key expiry is 3 hours - 10800 seconds
local KEY_EXPIRY = 10800
local module = {}
local last_health_check_ok_at = nil
local ngx_re = require "ngx.re"

function module.start_request()

	local ok, err = ngx.timer.at(0, module.set_redis_key,
		ngx.var.redis_health_check_host, ngx.var.redis_health_check_port,
		ngx.var.http_host, ngx.var.request_uri, ngx.var.http_x_ABC_kong_upstream, ngx.var.http_x_ABC_proxy,
		ngx.var.http_x_ABC_request_id)

	if not ok then
		ngx.log(ngx.ERR, "Could not submit job: ", err)
		return
	end

end


function module.set_redis_key(premature, redis_health_check_host, redis_health_check_port,
        http_host, request_uri, http_x_ABC_kong_upstream, http_x_ABC_proxy, 
        http_x_ABC_request_id)
	local red = redis:new(nil, ngx)
	red:set_timeout(1000) -- 1 sec
	local ok, err = red:connect(redis_health_check_host, redis_health_check_port)
	if not ok then
		ngx.log(ngx.ERR,"failed to connect: ", err)
		return
	end
	local key = http_x_ABC_request_id
	local ok, err = red:get(key)
  • The redis module which is imported above and is overridden :-
local redis_import = require "resty.redis"
local red_mod = {}


function red_mod:new(o, ngx)
	o = o or {}
	setmetatable(o, self) -- http://lua-users.org/wiki/MetamethodsTutorial
	self.__index = self
	self.ngx = ngx
	self.redis = redis_import:new()
	return o
end

function red_mod:connect(redis_health_check_host, redis_health_check_port)
	local ok, err = self.redis:connect(redis_health_check_host, redis_health_check_port)
	return ok, err
end

function red_mod:get(key)
	self.ngx.log(self.ngx.ERR, "!@@! Execution Time for REDIS:GET Operation :- ", key)
	local start_time = self.ngx.now() -- return time in seconds
	-- local redis = require "resty.redis"
	local ok, err = self.redis:get(key)
	local end_time = self.ngx.now() - start_time
	if end_time > 0.100 then
		self.ngx.log(self.ngx.ERR, "!@@! Execution Time for REDIS:GET Operation :- ", end_time)
	end
	return ok, err
end

return red_mod

If you want to look at the all methods or maybe all code you can always refer to above comments. Please let me know if you still need any help.

rushi47 avatar Feb 18 '20 09:02 rushi47

@doujiang24, Did you get chance to look at this ?

rushi47 avatar Feb 26 '20 11:02 rushi47