fix: the problem of high cpu and memory usage (#9015) by juststillthinking · Pull Request #9016 · apache/apisix

juststillthinking · 2023-03-06T11:14:25Z

Description

cocurrent requests after reload or service discovery will cause high cpu and memory usage, the checker created by healthcheck.new in create_checker won't be released if the program crashes after cancel_clean_handler failed

Fixes #9015

Checklist

I have explained the need for this PR and the problem it solves
I have explained the changes or the new features added to this PR
I have added tests corresponding to this change
I have updated the documentation to reflect this change
I have verified that this change is backward compatible (If not, please discuss on the APISIX mailing list first)

cocurrent requests after reload or update the upstream nodes will cause high cpu and memory usage, the checker created by healthcheck.new in create_checker won't be released if the program crashes after cancel_clean_handler failed

moonming · 2023-03-07T01:25:09Z

please add test cases for this PR

spacewander · 2023-03-07T01:25:12Z

It seems this fix breaks the CI
https://github.com/apache/apisix/actions/runs/4342798805/jobs/7584062794

kingluo

A healthcheck_parent.create_checker = true guard is enough. And I suggest removing obsolete code.

kingluo · 2023-03-06T11:56:04Z


    if healthcheck_parent.checker then
-        core.config_util.cancel_clean_handler(healthcheck_parent,
+        local ok, err = pcall(core.config_util.cancel_clean_handler, healthcheck_parent,


Since we add create_checker guard, cancel_clean_handler will not fail anymore, so no need to do pcall?

Just for code robustness

Just for code robustness

It's not necessary.

kingluo · 2023-03-06T11:57:39Z


    core_tab.remove(item.clean_handlers, pos)
-    if fire then
+    if not fire then


Since we add create_checker guard, fire will not be nil, so no need to check nil here?

Just for code robustness

Just for code robustness

ditto.

kingluo · 2023-03-06T12:05:33Z

@@ -115,8 +122,11 @@ local function create_checker(upstream)
    end

    if healthcheck_parent.checker then


Except for this parallel checker creation bug (due to the non-atomic fact of checker new() and add_target()), each resource update from etcd will replace the old value with a brand new one, here healthcheck_parent (the resource itself) will have only one checker at most anytime, so should we delete the obsolete code of checker conditions handling?

each resource update from etcd will replace the old value with a brand new one

I checked the code, updating the resource won't replace the old value with a brand new one
https://github.com/apache/apisix/blob/master/apisix/core/config_etcd.lua#L472

@monkeyDluffy6017 You're wrong. Sometimes reading code is not enough, and you need to debug it to guarantee your point.

apisix/apisix/core/config_etcd.lua

Line 472 in d8fd367

self.values[pre_index] = res

Set up a breakpoint:

cat > /usr/local/apisix/plugin_inspect_hooks.lua <<EOF dbg.set_hook("apisix/core/config_etcd.lua", 472, nil, function(info) core.log.warn("res: ", tostring(info.vals.res)) return false end) EOF

error.log:

2023/03/07 16:19:33 [warn] 2472696#2472696: *110 [lua] init.lua:68: setup_hooks(): set hooks: err: true, hooks: ["apisix/core/config_etcd.lua#472"], context: ngx.timer

Create a test upstream:

update_upstream() { curl http://127.0.0.1:9180/apisix/admin/upstreams/1 \ -H 'X-API-KEY: edd1c9f034335f136f87ad84b625c8f1' -X PUT -d ' { "nodes":[ { "host":"httpbin.org", "port":80, "weight":1 }, { "host":"postman-echo.com", "port":80, "weight":1 } ] }' } update_upstream

Override:

update_upstream

error.log:

2023/03/07 16:20:09 [warn] 2472696#2472696: *35 [lua] [string "local dbg = require("apisix.inspect.dbg")..."]:256: res: table: 0x7f5c62fede28, context: ngx.timer

Override again:

update_upstream

error.log:

2023/03/07 16:20:25 [warn] 2472696#2472696: *35 [lua] [string "local dbg = require("apisix.inspect.dbg")..."]:256: res: table: 0x7f5c680bbe88, context: ngx.timer

Note that the table is different: old: 0x7f5c62fede28, new: 0x7f5c680bbe88.

The parent of an upstream is itself,

apisix/apisix/upstream.lua

Line 564 in d8fd367

filter_upstream(upstream.value, upstream)

apisix/apisix/upstream.lua

Line 510 in d8fd367

value.parent = parent

So, each time the upstream gets updated, the parent is new, so it's impossible to enter into cases where the parent is the same but with a different checker, except this parallel create_checker bug, and since we do the bugfix, then no need to keep such code anymore. It works for all cases, including route with inline upstream or service with inline upstream.

@spacewander @moonming @membphis I think we should remove such obsolete code to make our code base lint.

I see what you mean, except for this concurrent scenario, because the upstream object changes every time, so there can't be a healthcheck_parent.checker

Removing this code will result in a lot of ci errors, consider dealing with it in a separate PR

@monkeyDluffy6017 @spacewander @moonming @membphis
I take back what I concluded. That code is not dead code, although it's not for concurrent checker creation guard, it's necessary for service discovery.
Each time the discovery result changes, the upstream (inlined in route/service or separate upstream) will do a shallow copy and reserves its parent, so the parent (route/service/upstream) may have a previous checker.

apisix/apisix/upstream.lua

Lines 272 to 284 in c159f04

local new_up_conf = core.table.clone(up_conf)

core.log.info("discover new upstream from ", up_conf.service_name, ", type ",

up_conf.discovery_type, ": ",

core.json.delay_encode(new_up_conf, true))

local parent = up_conf.parent

if parent.value.upstream then

-- the up_conf comes from route or service

parent.value.upstream = new_up_conf

else

parent.value = new_up_conf

end

up_conf = new_up_conf

It looks like that the ci has covered this, so after removed this code, the ci failed:

apisix/t/node/healthcheck-discovery.t

Line 110 in c159f04

=== TEST 2: create new checker when nodes change

Yes, so keep that code, although it's only for service discovery but not for normal upstream configuration update from etcd.

juststillthinking · 2023-03-07T07:17:55Z

please add test cases for this PR

It is difficult to reproduce this issue and may not be suitable for integration into CI @moonming

moonming · 2023-03-07T07:35:13Z

please add test cases for this PR

It is difficult to reproduce this issue and may not be suitable for integration into CI @moonming

How do you ensure the fix is correct if you can not reproduce it?

juststillthinking · 2023-03-07T08:06:00Z

please add test cases for this PR

It is difficult to reproduce this issue and may not be suitable for integration into CI @moonming

How do you ensure the fix is correct if you can not reproduce it?

We can see the error logs through a long test, but the CI also needs to focus on efficiency, as it may not be suitable for this type of test

moonming

We first reproduce a problem before we can fix it. So, without a test case, I don't think the bug is fixed

juststillthinking · 2023-03-09T00:10:37Z

@moonming The test is case is added

moonming · 2023-03-09T01:26:05Z

+    if f then
        f(item)
+    else
+        log.error("call cancel_clean_handler error, f is nil")


Can there be a more clear error message?

This reverts commit b937f1c.

spacewander · 2023-03-10T02:18:25Z

    healthcheck_parent.checker_idx =
        core.config_util.add_clean_handler(healthcheck_parent, release_checker)

+    upstream.is_creating_checker = nil


We should also reset it when this function exits with nil

spacewander · 2023-03-10T02:20:15Z

+
+
+=== TEST 20: set route(two healthy upstream nodes)
+--- config


When the test file is too large, for example > 800 lines, you should split it to a new file. Please take a look at t/plugin/limit-conn.t and t/plugin/limit-conn2.t.

https://github.com/apache/apisix/blob/master/CONTRIBUTING.md#check-code-style-and-test-case-style

juststillthinking · 2023-03-22T10:24:19Z

@moonming test case is added, please check

juststillthinking added 2 commits March 6, 2023 19:05

Merge branch 'master' into fix-high-cpu-and-memory-usage

e813590

juststillthinking added 2 commits March 7, 2023 14:07

Merge branch 'master' into fix-high-cpu-and-memory-usage

bee8201

ci: make ci pass

b33c88b

kingluo reviewed Mar 7, 2023

View reviewed changes

moonming requested changes Mar 7, 2023

View reviewed changes

juststillthinking added 2 commits March 9, 2023 01:19

test: add test case

b051d2d

refactor: remove useless code

b937f1c

test: remove useless code

ab7b8b9

moonming reviewed Mar 9, 2023

View reviewed changes

juststillthinking added 3 commits March 9, 2023 09:35

Revert "refactor: remove useless code"

ce40b55

This reverts commit b937f1c.

refactor: more detailed log info

ac51fa4

refactor: more detailed log info

866eac4

spacewander reviewed Mar 10, 2023

View reviewed changes

juststillthinking added 2 commits March 10, 2023 16:49

refactor: minor tweaks

24dbe92

refactor: minor tweaks

805aa39

spacewander approved these changes Mar 14, 2023

View reviewed changes

soulbird approved these changes Mar 15, 2023

View reviewed changes

moonming approved these changes Mar 22, 2023

View reviewed changes

spacewander merged commit 8197e03 into apache:master Mar 23, 2023

		@@ -115,8 +122,11 @@ local function create_checker(upstream)
		end

		if healthcheck_parent.checker then

	local new_up_conf = core.table.clone(up_conf)
	core.log.info("discover new upstream from ", up_conf.service_name, ", type ",
	up_conf.discovery_type, ": ",
	core.json.delay_encode(new_up_conf, true))

	local parent = up_conf.parent
	if parent.value.upstream then
	-- the up_conf comes from route or service
	parent.value.upstream = new_up_conf
	else
	parent.value = new_up_conf
	end
	up_conf = new_up_conf



		=== TEST 20: set route(two healthy upstream nodes)
		--- config

Uh oh!

Conversation

juststillthinking commented Mar 6, 2023

Description

Checklist

Uh oh!

moonming commented Mar 7, 2023

Uh oh!

spacewander commented Mar 7, 2023

Uh oh!

kingluo left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

juststillthinking Mar 7, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

kingluo Mar 7, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

juststillthinking commented Mar 7, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

moonming commented Mar 7, 2023

Uh oh!

juststillthinking commented Mar 7, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

moonming left a comment

Choose a reason for hiding this comment

Uh oh!

juststillthinking commented Mar 9, 2023

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

juststillthinking commented Mar 22, 2023

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

kingluo left a comment •

edited

Loading

juststillthinking Mar 7, 2023 •

edited

Loading

kingluo Mar 7, 2023 •

edited

Loading

juststillthinking commented Mar 7, 2023 •

edited

Loading

juststillthinking commented Mar 7, 2023 •

edited

Loading