You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@apisix.apache.org by GitBox <gi...@apache.org> on 2022/08/09 06:23:00 UTC
[GitHub] [apisix] BansheeLW opened a new issue, #7633: bug: config_util.lua:71: attempt to call local 'f' (a nil value)
BansheeLW opened a new issue, #7633:
URL: https://github.com/apache/apisix/issues/7633
### Current Behavior
The service is configured with a health check. When the upstream node changes and the concurrent request is bright, there will be a large number of 500 errors（lua entry thread aborted because function 'f' is nil）
### Expected Behavior
The function 'f' should not be nil, the request should be completed normally
### Error Logs
The error log is found as follows:
2022/08/08 10:29:46 [error] 46#46: *144287093 lua entry thread aborted: runtime error: /usr/local/apisix/apisix/core/config_util.lua:71: attempt to call local 'f' (a nil value)
stack traceback:
coroutine 0:
/usr/local/apisix/apisix/core/config_util.lua: in function 'cancel_clean_handler'
/usr/local/apisix/apisix/upstream.lua:119: in function 'fetch_healthchecker'
/usr/local/apisix/apisix/upstream.lua:327: in function 'set_upstream'
/usr/local/apisix/apisix/init.lua:515: in function 'http_access_phase'
access_by_lua(nginx.conf:253):2: in main chunk, client: 172.31.xx.xx, server: _, request: "GET xxxxxxx
According to the error message, find the location of the error code:
file path: apisix/core/config_util.lua
function _M.cancel_clean_handler(item, idx, fire)
local f = item.clean_handlers[idx]
core_tab.remove(item.clean_handlers, idx)
if fire then
f(item)
end
end
### Steps to Reproduce
1. Install apisix to EKS using the helm package
2. Service discovery using kubernetes
3. Routed services enable health checks
4. Initiate concurrent requests, no such error message appears
5. Adjust (increase or decrease) upstream nodes, and then initiate concurrent requests, a large number of such error logs appear, and the requester receives a large number of 500 errors
### Environment
- APISIX version (run `apisix version`):2.14.1
- Operating system (run `uname -a`): Linux apisix-58d87884d-l4qkw 5.4.129-63.229.amzn2.x86_64 #1 SMP Tue Jul 20 21:22:08 UTC 2021 x86_64 Linux
- OpenResty / Nginx version (run `openresty -V` or `nginx -V`): nginx version: openresty/1.19.9.1
- etcd version, if relevant (run `curl http://127.0.0.1:9090/v1/server_info`):3.4.0
- APISIX Dashboard version, if relevant:2.13.0
- LuaRocks version, for installation issues (run `luarocks --version`): 3.8.0
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] spacewander commented on issue #7633: bug: config_util.lua:71: attempt to call local 'f' (a nil value)
Posted by GitBox <gi...@apache.org>.
spacewander commented on issue #7633:
URL: https://github.com/apache/apisix/issues/7633#issuecomment-1210226120
Look like calling `cancel_clean_handler` to remove the clean handler in the middle (added by add_clean_handler) and then calling `cancel_clean_handler` may trigger this bug?
For example, we have handlers `[1, 2]`. The first call remove handler 1, then the handlers are `[2]`. Then the second call tries to remove the handler at the index 2, which is nil now.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] fightingcoding commented on issue #7633: bug: config_util.lua:71: attempt to call local 'f' (a nil value)
Posted by "fightingcoding (via GitHub)" <gi...@apache.org>.
fightingcoding commented on issue #7633:
URL: https://github.com/apache/apisix/issues/7633#issuecomment-1595810509
> Look like calling `cancel_clean_handler` to remove the clean handler in the middle (added by add_clean_handler) and then calling `cancel_clean_handler` may trigger this bug?
>
> For example, we have handlers `[1, 2]`. The first call remove handler 1, then the handlers are `[2]`. Then the second call tries to remove the handler at the index 2, which is nil now.
We also encountered a similar problem here, but we look at the code, the length of this clean_handlers should be 0 or 1, and there should be no case where the length is 2, but similar errors do appear during use, I would like to ask you to describe When the length of clean_handlers is 2, what happens? The corresponding calling code block is shown below, which has been marked.
local function create_checker(upstream)
if healthcheck == nil then
healthcheck = require("resty.healthcheck")
end
local healthcheck_parent = upstream.parent
if healthcheck_parent.checker and healthcheck_parent.checker_upstream == upstream then
return healthcheck_parent.checker
end
local checker, err = healthcheck.new({
name = get_healthchecker_name(healthcheck_parent),
shm_name = "upstream-healthcheck",
checks = upstream.checks,
})
if not checker then
core.log.error("fail to create healthcheck instance: ", err)
return nil
end
if healthcheck_parent.checker then
**core.config_util.cancel_clean_handler(healthcheck_parent,
healthcheck_parent.checker_idx, true)**
end
core.log.info("create new checker: ", tostring(checker))
local host = upstream.checks and upstream.checks.active and upstream.checks.active.host
local port = upstream.checks and upstream.checks.active and upstream.checks.active.port
for _, node in ipairs(upstream.nodes) do
local ok, err = checker:add_target(node.host, port or node.port, host)
if not ok then
core.log.error("failed to add new health check target: ", node.host, ":",
port or node.port, " err: ", err)
end
end
healthcheck_parent.checker = checker
healthcheck_parent.checker_upstream = upstream
healthcheck_parent.checker_idx =
**core.config_util.add_clean_handler(healthcheck_parent, release_checker)**
return checker
end
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] BansheeLW commented on issue #7633: bug: config_util.lua:71: attempt to call local 'f' (a nil value)
Posted by GitBox <gi...@apache.org>.
BansheeLW commented on issue #7633:
URL: https://github.com/apache/apisix/issues/7633#issuecomment-1208968022
Service
`{
"name": "go-server",
"upstream": {
"timeout": {
"connect": 6,
"send": 6,
"read": 6
},
"type": "roundrobin",
"checks": {
"active": {
"concurrency": 10,
"healthy": {
"http_statuses": [
200,
302
],
"interval": 1,
"successes": 2
},
"http_path": "/health",
"timeout": 1,
"type": "http",
"unhealthy": {
"http_failures": 5,
"http_statuses": [
429,
404,
500,
501,
502,
503,
504,
505
],
"interval": 1,
"tcp_failures": 2,
"timeouts": 3
}
},
"passive": {
"healthy": {
"http_statuses": [
200,
201,
202,
203,
204,
205,
206,
207,
208,
226,
300,
301,
302,
303,
304,
305,
306,
307,
308
],
"successes": 5
},
"type": "http",
"unhealthy": {
"http_failures": 2,
"http_statuses": [
429,
500,
503
],
"tcp_failures": 2,
"timeouts": 7
}
}
},
"scheme": "http",
"discovery_type": "kubernetes",
"pass_host": "pass",
"service_name": "test2/go-server:http",
"keepalive_pool": {
"idle_timeout": 60,
"requests": 1000,
"size": 320
}
},
"plugins": {
"api-breaker": {
"break_response_code": 502,
"disable": false,
"healthy": {
"http_statuses": [
200
],
"successes": 3
},
"max_breaker_sec": 300,
"unhealthy": {
"failures": 30,
"http_statuses": [
503
]
}
}
}
}`
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] tzssangglass commented on issue #7633: bug: config_util.lua:71: attempt to call local 'f' (a nil value)
Posted by GitBox <gi...@apache.org>.
tzssangglass commented on issue #7633:
URL: https://github.com/apache/apisix/issues/7633#issuecomment-1210106208
Can you set the log to `info` level and then provide more logs?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] BansheeLW commented on issue #7633: bug: config_util.lua:71: attempt to call local 'f' (a nil value)
Posted by GitBox <gi...@apache.org>.
BansheeLW commented on issue #7633:
URL: https://github.com/apache/apisix/issues/7633#issuecomment-1210203234
> And I would like to know: what is the operation of `Adjust (increase or decrease) upstream nodes`? Scaling up and down the service instances in kubernetes?
Scaling up and down upstream nodes
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] spacewander closed issue #7633: bug: config_util.lua:71: attempt to call local 'f' (a nil value)
Posted by GitBox <gi...@apache.org>.
spacewander closed issue #7633: bug: config_util.lua:71: attempt to call local 'f' (a nil value)
URL: https://github.com/apache/apisix/issues/7633
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] tzssangglass commented on issue #7633: bug: config_util.lua:71: attempt to call local 'f' (a nil value)
Posted by GitBox <gi...@apache.org>.
tzssangglass commented on issue #7633:
URL: https://github.com/apache/apisix/issues/7633#issuecomment-1210107404
And I would like to know: what is the operation of `Adjust (increase or decrease) upstream nodes`?
Scaling up and down the service instances in kubernetes?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] BansheeLW commented on issue #7633: bug: config_util.lua:71: attempt to call local 'f' (a nil value)
Posted by GitBox <gi...@apache.org>.
BansheeLW commented on issue #7633:
URL: https://github.com/apache/apisix/issues/7633#issuecomment-1210257177
> Can you set the log to `info` level and then provide more logs?
Of course, this is the log I intercepted and reproduced in the test environment, I hope it can help to troubleshoot the problem
------------------------------------------------------------------
2022/08/10 14:56:06 [info] 44#44: *7623779 [lua] init.lua:378: http_access_phase(): matched route: {"value":{"service_id":"420121832574681939","name":"go-appserver","create_time":1656905377,"update_time":1659947369,"priority":0,"uris":["\/goapp\/gappserv\/*","\/goapp\/apiserver\/*"],"methods":["GET","POST","PUT","DELETE","PATCH","HEAD","OPTIONS","CONNECT","TRACE"],"status":1,"id":"415027685446648601","desc":"go-appserver","plugins":{"prometheus":{"prefer_name":false,"disable":true},"kafka-logger":{"include_req_body":false,"include_resp_body":false,"inactive_timeout":5,"timeout":3,"name":"kafka logger","meta_format":"default","producer_type":"async","batch_max_size":1,"required_acks":1,"cluster_name":1,"kafka_topic":"apisix-logs","disable":true,"retry_delay":1,"buffer_duration":60,"max_retry_count":0,"broker_list":{"xxx":9092,"xxxxxx":9092}},"api-breaker":{"break_response_code":502,"max_breaker_sec":300,"healthy":{"http_statuses":[200],"successes":3},"disable":true,"unhealthy":{"fa
ilures":3,"http_statuses":[500,503]}},"limit-req":{"rejected_code":503,"rejected_msg":"server is reject","allow_degradation":false,"disable":true,"nodelay":false,"key":"server_addr","burst":50,"key_type":"var","rate":200}}},"modifiedIndex":3453,"clean_handlers":{},"key":"\/apisix\/routes\/415027685446648601","has_domain":false,"createdIndex":250,"update_count":0,"orig_modifiedIndex":3453}, client: 172.31.35.155, server: _, request: "GET /goapp/gappserv/configure/quickChatList?__la=zh HTTP/1.1", host: "cloudac4.mildom.jp"
2022/08/10 14:56:06 [warn] 44#44: *7623779 [lua] json.lua:94: failed to encode: Cannot serialise table: excessively sparse array force: true, client: 172.31.35.155, server: _, request: "GET /goapp/gappserv/configure/quickChatList?__la=zh HTTP/1.1", host: "cloudac4.mildom.jp"
2022/08/10 14:56:06 [warn] 44#44: *7623779 [lua] json.lua:94: failed to encode: Cannot serialise table: excessively sparse array force: true, client: 172.31.35.155, server: _, request: "GET /goapp/gappserv/configure/quickChatList?__la=zh HTTP/1.1", host: "cloudac4.mildom.jp"
2022/08/10 14:56:06 [info] 44#44: *7623779 [lua] plugin.lua:480: merge_service_route(): service conf: , client: 172.31.35.155, server: _, request: "GET /goapp/gappserv/configure/quickChatList?__la=zh HTTP/1.1", host: "cloudac4.mildom.jp"
2022/08/10 14:56:06 [info] 44#44: *7623779 [lua] plugin.lua:481: merge_service_route(): route conf: {"value":{"service_id":"420121832574681939","name":"go-appserver","create_time":1656905377,"update_time":1659947369,"priority":0,"uris":["\/goapp\/gappserv\/*","\/goapp\/apiserver\/*"],"methods":["GET","POST","PUT","DELETE","PATCH","HEAD","OPTIONS","CONNECT","TRACE"],"status":1,"id":"415027685446648601","desc":"go-appserver","plugins":{"prometheus":{"prefer_name":false,"disable":true},"kafka-logger":{"include_req_body":false,"include_resp_body":false,"inactive_timeout":5,"timeout":3,"name":"kafka logger","meta_format":"default","producer_type":"async","batch_max_size":1,"required_acks":1,"cluster_name":1,"kafka_topic":"apisix-logs","disable":true,"retry_delay":1,"buffer_duration":60,"max_retry_count":0,"broker_list":{"xxx":9092,"xxxxxx":9092}},"api-breaker":{"break_response_code":502,"max_breaker_sec":300,"healthy":{"http_statuses":[200],"successes":3},"disable":true,"unhealthy":{
"failures":3,"http_statuses":[500,503]}},"limit-req":{"rejected_code":503,"rejected_msg":"server is reject","allow_degradation":false,"disable":true,"nodelay":false,"key":"server_addr","burst":50,"key_type":"var","rate":200}}},"modifiedIndex":3453,"clean_handlers":{},"key":"\/apisix\/routes\/415027685446648601","has_domain":false,"createdIndex":250,"update_count":0,"orig_modifiedIndex":3453}, client: 172.31.35.155, server: _, request: "GET /goapp/gappserv/configure/quickChatList?__la=zh HTTP/1.1", host: "cloudac4.mildom.jp"
2022/08/10 14:56:06 [warn] 44#44: *7623779 [lua] json.lua:94: failed to encode: Cannot serialise table: excessively sparse array force: true, client: 172.31.35.155, server: _, request: "GET /goapp/gappserv/configure/quickChatList?__la=zh HTTP/1.1", host: "cloudac4.mildom.jp"
2022/08/10 14:56:06 [warn] 44#44: *7623779 [lua] json.lua:94: failed to encode: Cannot serialise table: excessively sparse array force: true, client: 172.31.35.155, server: _, request: "GET /goapp/gappserv/configure/quickChatList?__la=zh HTTP/1.1", host: "cloudac4.mildom.jp"
2022/08/10 14:56:06 [info] 44#44: *7623779 [lua] upstream.lua:274: set_upstream(): discover new upstream from test2/go-appserver:http, type kubernetes: , client: 172.31.35.155, server: _, request: "GET /goapp/gappserv/configure/quickChatList?__la=zh HTTP/1.1", host: "cloudac4.mildom.jp"
2022/08/10 14:56:06 [error] 44#44: *7623779 lua entry thread aborted: runtime error: /usr/local/apisix/apisix/core/config_util.lua:71: attempt to call local 'f' (a nil value)
stack traceback:
--
access_by_lua(nginx.conf:256):2: in main chunk, client: 172.31.35.155, server: _, request: "GET /goapp/gappserv/configure/quickChatList?__la=zh HTTP/1.1", host: "cloudac4.mildom.jp"
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] BansheeLW commented on issue #7633: bug: config_util.lua:71: attempt to call local 'f' (a nil value)
Posted by GitBox <gi...@apache.org>.
BansheeLW commented on issue #7633:
URL: https://github.com/apache/apisix/issues/7633#issuecomment-1210262539
> Look like calling `cancel_clean_handler` to remove the clean handler in the middle (added by add_clean_handler) and then calling `cancel_clean_handler` may trigger this bug?
>
> For example, we have handlers `[1, 2]`. The first call remove handler 1, then the handlers are `[2]`. Then the second call tries to remove the handler at the index 2, which is nil now.
Yes, from the log it looks like this part of the processing is wrong which leads to the access to the "f" function which is already a nil value
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] BansheeLW commented on issue #7633: bug: config_util.lua:71: attempt to call local 'f' (a nil value)
Posted by GitBox <gi...@apache.org>.
BansheeLW commented on issue #7633:
URL: https://github.com/apache/apisix/issues/7633#issuecomment-1210260986
> Can you set the log to `info` level and then provide more logs?
Of course, this is the log I intercepted and reproduced in the test environment, I hope it can help to troubleshoot the problem
[apisix-nil.log](https://github.com/apache/apisix/files/9297695/apisix-nil.log)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org