bug: the balancer_ip is old, resulting in 504 timeout

[flyer5200]

Issue description

Environment

• apisix version: 2.2
• OS: Linux e4c9cbe60a02 4.18.0-193.6.3.el8_2.x86_64 change: added doc of how to load plugin. #1 SMP Wed Jun 10 11:09:32 UTC 2020 x86_64 Linux
• OpenResty / Nginx version: nginx version: openresty/1.19.3.1 built by gcc 9.3.0 (Alpine 9.3.0)
• eureka: 2.0.1

Minimal test code / Steps to reproduce the issue

1. deploy my app using docker container, and use eureka as service discovery
2. apisix stared, can be routed to upstream correctly (Refresh every 5 seconds from eureka)
3. redeploy or restart my app, the container ip becomes other address
4. eureka fetch nodes ip is correct, but apisix balancer still use the old ip

What's the actual result? (including assertion message & call stack if applicable)

the request will hang and apisix return 504 gateway timeout
At this time, the upstream ip is 192.168.20.3 and 192.168.20.74, but apisix balancer still use the old ip 192.168.20.29

debug log:
➜ nginx tail -f error.log|grep resourceCenter

2021/01/21 11:53:53 [info] 36#36: *5157006 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too, client: 100.121.99.213, server: , request: "POST /resourceCenter/yyWeb/resource/makeAtHome/list HTTP/1.1", upstream: "http://192.168.20.29:19550/resourceCenter/yyWeb/resource/makeAtHome/list", host: "test-api.explame.com", referrer: "https://test-yy.explame.com/"
2021/01/21 11:53:57 [info] 36#36: *5157315 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too, client: 100.121.99.209, server: , request: "POST /resourceCenter/yyWeb/resource/makeAtHome/detail HTTP/1.1", upstream: "http://192.168.20.29:19550/resourceCenter/yyWeb/resource/makeAtHome/detail", host: "test-api.explame.com", referrer: "https://test-yy.explame.com/"
2021/01/21 11:53:59 [error] 38#38: 5157419 upstream timed out (110: Operation timed out), client: 100.121.99.213, server: , request: "POST /resourceCenter/yyWeb/resource/makeAtHome/detail HTTP/1.1", upstream: "http://192.168.20.29:19550/resourceCenter/yyWeb/resource/makeAtHome/detail", host: "test-api.explame.com", referrer: "https://test-yy.explame.com/"
2021/01/21 11:53:59 [info] 38#38: 5157419 [lua] balancer.lua:162: pick_server(): route: {"has_domain":false,"modifiedIndex":2705,"clean_handlers":{},"key":"/apisix/routes/3","value":{"name":"resource","uri":"/resourceCenter/","id":"3","methods":["GET","POST","OPTIONS"],"update_time":1608717708,"priority":0,"status":1,"desc":"resource服务路由配置","create_time":1607334184,"upstream":{"discovery_type":"eureka","pass_host":"pass","nodes":[{"weight":100,"port":19550,"metadata":{"management.port":"19550"},"host":"192.168.20.74"},{"weight":100,"port":19550,"metadata":{"management.port":"19550"},"host":"192.168.20.3"}],"type":"roundrobin","service_name":"RESOURCECENTER","hash_on":"vars"}},"createdIndex":46} while connecting to upstream, client: 100.121.99.213, server: , request: "POST /resourceCenter/yyWeb/resource/makeAtHome/detail HTTP/1.1", upstream: "http://192.168.20.29:19550/resourceCenter/yyWeb/resource/makeAtHome/detail", host: "test-api.explame.com", referrer: "https://test-yy.explame.com/"
2021/01/21 11:53:59 [info] 38#38: 5157419 [lua] balancer.lua:163: pick_server(): ctx: {"pass_host":"pass","upstream_conf":{"discovery_type":"eureka","pass_host":"pass","nodes":[{"weight":100,"port":19550,"metadata":{"management.port":"19550"},"host":"192.168.20.74"},{"weight":100,"port":19550,"metadata":{"management.port":"19550"},"host":"192.168.20.3"}],"type":"roundrobin","service_name":"RESOURCECENTER","hash_on":"vars"},"balancer_ip":"192.168.20.29","proxy_passed":true,"global_rules":{"conf_version":1,"automatic":true,"etcd_cli":{"is_cluster":false,"ssl_verify":true,"timeout":30,"ttl":-1,"key_prefix":"","sema":{"sem":"cdata<struct ngx_http_lua_sema_s >: 0x7fda282fa038"},"last_auth_time":1611130472.725,"endpoints":[{"api_prefix":"/v3","port":"2379","full_prefix":"http://etcd:2379/v3","scheme":"http","http_host":"http://etcd:2379","host":"etcd"}],"is_auth":false},"values_hash":{"1":1},"sync_times":0,"values":[{"value":{"plugins":{"prometheus":{},"cors":{"max_age":5,"allow_headers":"Origin,X-Requested-With,Content-Type,Accept,Authorization,QMHX-Authorization,x-ca-signature,x-ca-signature-headers,x-ca-timestamp,x-ca-deviceid,x-ca-version,x-ca-nonce,x-ca-appkey,content-md5","allow_origins":"","expose_headers":"","allow_credential":false,"allow_methods":"GET,POST,PUT,DELETE,OPTIONS"}},"id":"1"},"modifiedIndex":3858,"key":"/apisix/global_rules/1","clean_handlers":{},"createdIndex":2690}],"key":"/apisix/global_rules","item_schema":{"properties":{"id":{"anyOf":[{"minLength":1,"type":"string","maxLength":64,"pattern":"^[a-zA-Z0-9-_.]+$"},{"type":"integer","minimum":1}]},"plugins":{"type":"object"}},"type":"object","additionalProperties":false,"required":["plugins"]},"last_err":"timeout","prev_index":5921,"resync_delay":5,"last_err_time":1611201226,"need_reload":false,"checker":"function: 0x7fda2d063fd8","running":true},"server_picker":{"upstream":"table: 0x7fda28292ee0","get":"function: 0x7fda27f9e298"},"route_name":"resource","conf_id":"3","curr_req_matched":{"_method":"POST",":ext":"yyWeb/resource/makeAtHome/detail","_path":"/resourceCenter/"},"route_id":"3","var":{"request_method":"POST","uri":"/resourceCenter/yyWeb/resource/makeAtHome/detail","remote_addr":"100.121.99.213","_request":"cdata<void >: 0x55fbcafca410","host":"test-api.explame.com"},"conf_type":"route","matched_route":"table: 0x7fda282f9e90","conf_version":2705,"upstream_version":2705,"plugins":{},"balancer_try_count":1,"upstream_key":"roundrobin#upstream_table: 0x7fda28292ee0","upstream_healthcheck_parent":{"has_domain":false,"modifiedIndex":2705,"clean_handlers":{},"key":"/apisix/routes/3","value":{"name":"resource","uri":"/resourceCenter/","id":"3","methods":["GET","POST","OPTIONS"],"update_time":1608717708,"priority":0,"status":1,"desc":"resource服务路由配置","create_time":1607334184,"upstream":"table: 0x7fda28292ee0"},"createdIndex":46},"matched_upstream":"table: 0x7fda28292ee0","balancer_port":19550} while connecting to upstream, client: 100.121.99.213, server: , request: "POST /resourceCenter/yyWeb/resource/makeAtHome/detail HTTP/1.1", upstream: "http://192.168.20.29:19550/resourceCenter/yyWeb/resource/makeAtHome/detail", host: "test-api.explame.com", referrer: "https://test-yy.explame.com/"
2021/01/21 11:53:59 [info] 38#38: *5157419 [lua] balancer.lua:278: load_balancer(): proxy request to 192.168.20.29:19550 while connecting to upstream, client: 100.121.99.213, server: , request: "POST /resourceCenter/yyWeb/resource/makeAtHome/detail HTTP/1.1", upstream: "http://192.168.20.29:19550/resourceCenter/yyWeb/resource/makeAtHome/detail", host: "test-api.explame.com", referrer: "https://test-yy.explame.com/"
2021/01/21 11:53:59 [info] 38#38: *5157419 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too while connecting to upstream, client: 100.121.99.213, server: , request: "POST /resourceCenter/yyWeb/resource/makeAtHome/detail HTTP/1.1", upstream: "http://192.168.20.29:19550/resourceCenter/yyWeb/resource/makeAtHome/detail", host: "test-api.explame.com", referrer: "https://test-yy.explame.com/"

balancer.lua pick_server() log ctx:

{
"pass_host": "pass",
"upstream_conf": {
"discovery_type": "eureka",
"pass_host": "pass",
"nodes": [
{
"weight": 100,
"port": 19550,
"metadata": {
"management.port": "19550"
},
"host": "192.168.20.74"
},
{
"weight": 100,
"port": 19550,
"metadata": {
"management.port": "19550"
},
"host": "192.168.20.3"
}
],
"type": "roundrobin",
"service_name": "RESOURCECENTER",
"hash_on": "vars"
},
"balancer_ip": "192.168.20.29",
"proxy_passed": true,
"global_rules": {
"conf_version": 1,
"automatic": true,
"etcd_cli": {
"is_cluster": false,
"ssl_verify": true,
"timeout": 30,
"ttl": -1,
"key_prefix": "",
"sema": {
"sem": "cdata<struct ngx_http_lua_sema_s >: 0x7fda282fa038"
},
"last_auth_time": 1611130472.725,
"endpoints": [
{
"api_prefix": "/v3",
"port": "2379",
"full_prefix": "http://etcd:2379/v3",
"scheme": "http",
"http_host": "http://etcd:2379",
"host": "etcd"
}
],
"is_auth": false
},
"values_hash": {
"1": 1
},
"sync_times": 0,
"values": [
{
"value": {
"plugins": {
"prometheus": {},
"cors": {
"max_age": 5,
"allow_headers": "Origin,X-Requested-With,Content-Type,Accept,Authorization,QMHX-Authorization,x-ca-signature,x-ca-signature-headers,x-ca-timestamp,x-ca-deviceid,x-ca-version,x-ca-nonce,x-ca-appkey,content-md5",
"allow_origins": "",
"expose_headers": "",
"allow_credential": false,
"allow_methods": "GET,POST,PUT,DELETE,OPTIONS"
}
},
"id": "1"
},
"modifiedIndex": 3858,
"key": "/apisix/global_rules/1",
"clean_handlers": {},
"createdIndex": 2690
}
],
"key": "/apisix/global_rules",
"item_schema": {
"properties": {
"id": {
"anyOf": [
{
"minLength": 1,
"type": "string",
"maxLength": 64,
"pattern": "^[a-zA-Z0-9-_.]+$"
},
{
"type": "integer",
"minimum": 1
}
]
},
"plugins": {
"type": "object"
}
},
"type": "object",
"additionalProperties": false,
"required": [
"plugins"
]
},
"last_err": "timeout",
"prev_index": 5921,
"resync_delay": 5,
"last_err_time": 1611201226,
"need_reload": false,
"checker": "function: 0x7fda2d063fd8",
"running": true
},
"server_picker": {
"upstream": "table: 0x7fda28292ee0",
"get": "function: 0x7fda27f9e298"
},
"route_name": "resource",
"conf_id": "3",
"curr_req_matched": {
"_method": "POST",
":ext": "yyWeb/resource/makeAtHome/detail",
"_path": "/resourceCenter/"
},
"route_id": "3",
"var": {
"request_method": "POST",
"uri": "/resourceCenter/yyWeb/resource/makeAtHome/detail",
"remote_addr": "100.121.99.213",
"_request": "cdata<void >: 0x55fbcafca410",
"host": "test-api.explame.com"
},
"conf_type": "route",
"matched_route": "table: 0x7fda282f9e90",
"conf_version": 2705,
"upstream_version": 2705,
"plugins": {},
"balancer_try_count": 1,
"upstream_key": "roundrobin#upstream_table: 0x7fda28292ee0",
"upstream_healthcheck_parent": {
"has_domain": false,
"modifiedIndex": 2705,
"clean_handlers": {},
"key": "/apisix/routes/3",
"value": {
"name": "resource",
"uri": "/resourceCenter/",
"id": "3",
"methods": [
"GET",
"POST",
"OPTIONS"
],
"update_time": 1608717708,
"priority": 0,
"status": 1,
"desc": "resource服务路由配置",
"create_time": 1607334184,
"upstream": "table: 0x7fda28292ee0"
},
"createdIndex": 46
},
"matched_upstream": "table: 0x7fda28292ee0",
"balancer_port": 19550
}

What's the expected result?

When the upstream IP changes, apisix can handle the request correctly

[Firstsawyou]

@membphis @spacewander If you have time, please take a look.

[spacewander]

Fixed by #3295