openresty / openresty/lua-nginx-module

ngx.location.capture_multi and proxy_pass upstream issue

Open
#2,153 0 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
C
Stars
11.8k
Forks
2.1k
Avg merge
6h 1m
Merged PRs (30d)
6

Description

This is my nginx.conf:
upstream backend_services {
    server $servicediscovery;
    keepalive 512;
}
lua_shared_dict token_cache 100M;   
lua_shared_dict prometheus_metrics 10M;
lua_package_path '/etc/nginx/conf.d/lua/?.lua;;';
init_by_lua_block {
  prometheus = require("prometheus").init("prometheus_metrics")
  metric_requests = prometheus:counter(
    "http_requests_total", "Number of HTTP requests", {"host", "status"})
  metric_latency = prometheus:histogram(
    "http_request_duration_seconds", "HTTP request latency", {"host", "method", "uri", "status"}, {0.3})
  metric_connections = prometheus:gauge(
    "http_connections", "Number of HTTP connections", {"state"})
}
log_by_lua_block {
  metric_requests:inc(1, {ngx.var.host, ngx.var.status})
  local news_pattern = "/news/blog/index.php"
  local pattern = "/(%w+)/(%w+)/(%w+)"
  local begin, last = string.find(ngx.var.uri, pattern)
  local n_begin, n_last = string.find(ngx.var.uri, news_pattern)
  local log_uri = nil
  if begin == nil then
	log_uri = ngx.var.uri
  else
     if n_begin ~= nil then
         log_uri = string.gsub(ngx.var.uri,"/$","")
     else
         log_uri = string.sub(ngx.var.uri, begin, last)
     end

  end

  metric_latency:observe(ngx.now() - ngx.req.start_time(), {ngx.var.host,ngx.var.request_method,log_uri,ngx.var.status})
}

server {

    gzip on;
    gzip_types      text/plain application/xml application/json;
    gzip_min_length 1000;

    listen 8080;
   
    location /ccg/prometheus/metrics {
        content_by_lua_block {
             metric_connections:set(ngx.var.connections_active, {"active"})
             metric_connections:set(ngx.var.connections_reading, {"reading"})
             metric_connections:set(ngx.var.connections_waiting, {"waiting"})
             metric_connections:set(ngx.var.connections_writing, {"writing"})
             prometheus:collect()
        }
    }

    location /ccg/healthcheck {
         #default_type application/json;
         add_header User-Agent $http_user_agent;         
         return 200 'HTTP Status 200';
    }

    location /ccg/authorize {
         # "http://MESH_PROXY_SERVICE/clspl/clinical"
         rewrite /ccg/(.*)  /$clsservicediscovery/clinical/$1 break;
         proxy_pass http://backend_services;
         proxy_http_version 1.1;
         proxy_set_header Connection "";
         proxy_set_header Host $host;
    }

    location /ccg/blog {
         # "http://MESH_PROXY_SERVICE/news/blog"
         access_by_lua_file  /etc/nginx/conf.d/lua/auth.lua;
         rewrite /ccg/(.*)  /$newsservicediscovery/$1 break;
         proxy_pass http://backend_services;
         proxy_http_version 1.1;
         proxy_set_header Connection "";
         proxy_set_header Host $host;
    }

    location /ccg/formularyservice {
         content_by_lua_file /etc/nginx/conf.d/lua/auth_with_upstream.lua;
    }

    location /forward/ccg/formularyservice {
         #"http://MESH_PROXY_SERVICE/formulary/formularyservice";
         rewrite /forward/ccg/(.*)  /$formularyservicediscovery/$1 break;
         proxy_pass http://backend_services;
         proxy_http_version 1.1;
         proxy_set_header Connection "";
         proxy_set_header Host $host;
    }

    location /ccg/cts {
         content_by_lua_file /etc/nginx/conf.d/lua/auth_with_upstream.lua;
    }

    location /forward/ccg/cts {
        #"http://<s2s url>//cts"
         #access_by_lua_file /etc/nginx/conf.d/lua/auth.lua;
         rewrite /forward/ccg/(.*)  /$1 break;
         proxy_pass http://$SEARCH_SERVICE_BASE_URL;
         proxy_http_version 1.1;
         proxy_set_header Connection "";
    }
    
    location /ccg/term {
         content_by_lua_file /etc/nginx/conf.d/lua/auth_with_upstream.lua;
    }

    location /forward/ccg/term {
        #"http://MESH_PROXY_SERVICE/termservice/term"
        rewrite /forward/ccg/(.*) /$termservicediscovery/$1 break;
        proxy_pass http://backend_services;
        proxy_http_version 1.1;
        proxy_set_header Connection "";
        proxy_set_header Host $host;
    }

    location /verifytoken/mtws.do {
        rewrite /verifytoken/(.*) /$ecomservicediscovery/$1 break;
        proxy_pass http://backend_services;
        proxy_http_version 1.1;
        proxy_set_header Connection "";
        proxy_set_header Host $host;
    }

}

where SEARCH_SERVICE_BASE_URL = search-s2s.us-west-2.dev.epocrates.aws.athenahealth.com

and my auth_with_upstream.lua is

local expiry_time_secs = 86400 -- expiry time for entries in token cache

local token_cache = ngx.shared.token_cache

local value, flags = token_cache:get(epltokenescaped) -- Always try reading token from cache

if value == nil or value == '' or crdescaped == nil or crdescaped == '' or value ~= crdescaped then ngx.log(ngx.DEBUG, "Inside if block of lua file") local requestUri = '/forward' .. ngx.var.request_uri ngx.log(ngx.DEBUG, "Request URI : " .. requestUri) local auth_res, upstream_res = ngx.location.capture_multi ({ {'/verifytoken/mtws.do?', { args = { crd = crdescaped, epltoken = epltokenescaped, mode = 'liteAuth' } } }, { '/forward' .. ngx.var.request_uri, { method = request_method_supported[ngx.var.request_method], body = ngx.var.request_body} }, }) 

 local auth_response = auth_res.body
     local json_response = cjson.decode(auth_response)
     local userId = json_response.userId
 local upstream_response = upstream_res.body
 ngx.log(ngx.DEBUG, "Response Body : " .. upstream_res.body)
 ngx.log(ngx.DEBUG, "Response Status : " .. upstream_res.status)

 local unAuthorizedJsonResponse = cjson.encode({
      version = "1",
      userId = 0,
      token = "TBD"
 })

if auth_res.status == ngx.HTTP_OK and userId > 0 then
    token_cache:set(epltokenescaped, crdescaped, expiry_time_secs)
    if upstream_res.status == ngx.HTTP_OK then
        ngx.status = upstream_res.status
        for header_name, header in pairs(upstream_res.header) do
	    ngx.header[header_name] = header
        end
        ngx.print(upstream_res.body)
        ngx.flush(true)
    end
    ngx.exit(upstream_res.status)
else
        ngx.status = ngx.HTTP_UNAUTHORIZED
        ngx.header.content_type = 'application/json'
    auth_res.body = unAuthorizedJsonResponse
    ngx.print(auth_res.body)
    ngx.exit(ngx.status)
end

else
ngx.log(ngx.DEBUG, "Inside else block of lua file") local requestUri = '/forward' .. ngx.var.request_uri ngx.log(ngx.DEBUG, "Request URI : " .. requestUri) local upstream_res = ngx.location.capture('/forward' .. ngx.var.request_uri, { method request_method_supported[ngx.var.request_method], body = ngx.var.request_body})

local response = upstream_res.body ngx.log(ngx.DEBUG, "Response Body : " .. upstream_res.body) ngx.log(ngx.DEBUG, "Response Status : " .. upstream_res.status) if upstream_res.status == ngx.HTTP_OK then ngx.status = upstream_res.status for header_name, header in pairs(upstream_res.header) do ngx.header[header_name] = header end ngx.print(response) ngx.flush(true) end ngx.exit(upstream_res.status) end

Any request of the form /ccg/cts , first go to auth_with_upstream.lua and tries to initiate two paraller request . One is for authentication /verifytoken/mtws.do? and other is for the upstream /forward/ccg/cts .

Inside nginx.conf in location directive of /forward/ccg/cts , proxy_pass is defined as mentioned above. Very strange issue I am facing. Sometimes the request to /ccg/cts succeeds and sometime it fails with 502 gateway error. If I restart this nginx service , then again the issue is resolved but after sometime again it starts.

NOTE : All my services are deployed in EC2 of AWS.
This is my logs :

`[debug] 26#26: *1495 [lua] auth_with_upstream.lua:26: Inside if block of lua file
[debug] 26#26: *1495 [lua] auth_with_upstream.lua:28: Request URI : /forward/ccg/cts/search?kgFlags=feature_kg_related_dx,feature_kg_rx_class,feature_kg_rx_for&appVersion=23.2.0-dev%20debug&os=Android&query=hydroxyzine&start=0&userId=9818732&token=df8093c4286c9306e053da54870a8ae3&core=all18_6&osVersion=12&end=30&premUser=true&qp=1&username=test_medinfo_p@epocrates.com.tttt
2023/02/14 15:58:14 [notice] 26#26: 1495 "/verifytoken/(.)" matches "/verifytoken/mtws.do", client: 10.135.114.41, server: , request: "GET /ccg/cts/search?kgFlags=feature_kg_related_dx,feature_kg_rx_class,feature_kg_rx_for&appVersion=23.2.0-dev%20debug&os=Android&query=hydroxyzine&start=0&userId=9818732&token=df8093c4286c9306e053da54870a8ae3&core=all18_6&osVersion=12&end=30&premUser=true&qp=1&username=test_medinfo_p@epocrates.com.tttt HTTP/1.1", subrequest: "/verifytoken/mtws.do", host: "content.dev.epocrates.com"

[notice] 26#26: *1495 rewritten data: "/ecm/mtws.do", args: "crd=test_medinfo_p%40epocrates.com.tttt&epltoken=df8093c4286c9306e053da54870a8ae3&mode=liteAuth", client: 10.135.114.41, server: , request: "GET /ccg/cts/search?kgFlags=feature_kg_related_dx,feature_kg_rx_class,feature_kg_rx_for&appVersion=23.2.0-dev%20debug&os=Android&query=hydroxyzine&start=0&userId=9818732&token=df8093c4286c9306e053da54870a8ae3&core=all18_6&osVersion=12&end=30&premUser=true&qp=1&username=test_medinfo_p@epocrates.com.tttt HTTP/1.1", subrequest: "/verifytoken/mtws.do", host: "content.dev.epocrates.com"

[notice] 26#26: 1495 "/forward/ccg/(.)" matches "/forward/ccg/cts/search", client: 10.135.114.41, server: , request: "GET /ccg/cts/search?kgFlags=feature_kg_related_dx,feature_kg_rx_class,feature_kg_rx_for&appVersion=23.2.0-dev%20debug&os=Android&query=hydroxyzine&start=0&userId=9818732&token=df8093c4286c9306e053da54870a8ae3&core=all18_6&osVersion=12&end=30&premUser=true&qp=1&username=test_medinfo_p@epocrates.com.tttt HTTP/1.1", subrequest: "/forward/ccg/cts/search", host: "content.dev.epocrates.com"

[notice] 26#26: *1495 rewritten data: "/cts/search", args: "kgFlags=feature_kg_related_dx,feature_kg_rx_class,feature_kg_rx_for&appVersion=23.2.0-dev%20debug&os=Android&query=hydroxyzine&start=0&userId=9818732&token=df8093c4286c9306e053da54870a8ae3&core=all18_6&osVersion=12&end=30&premUser=true&qp=1&username=test_medinfo_p@epocrates.com.tttt", client: 10.135.114.41, server: , request: "GET /ccg/cts/search?kgFlags=feature_kg_related_dx,feature_kg_rx_class,feature_kg_rx_for&appVersion=23.2.0-dev%20debug&os=Android&query=hydroxyzine&start=0&userId=9818732&token=df8093c4286c9306e053da54870a8ae3&core=all18_6&osVersion=12&end=30&premUser=true&qp=1&username=test_medinfo_p@epocrates.com.tttt HTTP/1.1", subrequest: "/forward/ccg/cts/search", host: "content.dev.epocrates.com"

[error] 26#26: *1495 connect() failed (113: No route to host) while connecting to upstream, client: 10.135.114.41, server: , request: "GET /ccg/cts/search?kgFlags=feature_kg_related_dx,feature_kg_rx_class,feature_kg_rx_for&appVersion=23.2.0-dev%20debug&os=Android&query=hydroxyzine&start=0&userId=9818732&token=df8093c4286c9306e053da54870a8ae3&core=all18_6&osVersion=12&end=30&premUser=true&qp=1&username=test_medinfo_p@epocrates.com.tttt HTTP/1.1", subrequest: "/cts/search", upstream: "http://10.135.116.127:80/cts/search?kgFlags=feature_kg_related_dx,feature_kg_rx_class,feature_kg_rx_for&appVersion=23.2.0-dev%20debug&os=Android&query=hydroxyzine&start=0&userId=9818732&token=df8093c4286c9306e053da54870a8ae3&core=all18_6&osVersion=12&end=30&premUser=true&qp=1&username=test_medinfo_p@epocrates.com.tttt", host: "content.dev.epocrates.com"

[warn] 26#26: *1495 upstream server temporarily disabled while connecting to upstream, client: 10.135.114.41, server: , request: "GET /ccg/cts/search?kgFlags=feature_kg_related_dx,feature_kg_rx_class,feature_kg_rx_for&appVersion=23.2.0-dev%20debug&os=Android&query=hydroxyzine&start=0&userId=9818732&token=df8093c4286c9306e053da54870a8ae3&core=all18_6&osVersion=12&end=30&premUser=true&qp=1&username=test_medinfo_p@epocrates.com.tttt HTTP/1.1", subrequest: "/cts/search", upstream: "http://10.135.116.127:80/cts/search?kgFlags=feature_kg_related_dx,feature_kg_rx_class,feature_kg_rx_for&appVersion=23.2.0-dev%20debug&os=Android&query=hydroxyzine&start=0&userId=9818732&token=df8093c4286c9306e053da54870a8ae3&core=all18_6&osVersion=12&end=30&premUser=true&qp=1&username=test_medinfo_p@epocrates.com.tttt", host: "content.dev.epocrates.com"`

If you notice in the logs , the upstream call is going as http://10.135.116.127:80/cts/search?kgFlags=feature_kg_related_dx...
but actually it should be as http://search-s2s.us-west-2.dev.epocrates.aws.athenahealth.com/cts/search?kgFlags=feature_kg_related_dx....

Please help me resolve this issue. I tried adding resolver inside location directive suspecting it could be issue because of elastic IP in aws but that did not help. Not sure what is the root cause.

PS : Other services working fine which are using backend_services as upstream.

Contributor guide

No contributing guide indexed for this repository

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with auth_with_upstream.lua and the /forward/ccg/cts location in nginx.conf, focusing on the ngx.location.capture_multi calls and the logged 502 response. Compare successful and failing requests using the debug log, especially the “No route to host” message for 10.135.116.127:80. Done means identifying the cause of the intermittent upstream failure and documenting a reproducible fix or configuration change.

Written by the indexing model from the issue text.

Assessment

Tech stack
lua, nginx
Domain
backend, networking
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.