Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Be more agressive acquiring the iptables lock #85771

Merged
merged 1 commit into from Dec 17, 2019

Conversation

@aojea
Copy link
Member

aojea commented Dec 1, 2019

What type of PR is this?

Uncomment only one /kind <> line, hit enter to put that in a new line, and remove leading whitespace from that line:

/kind api-change
/kind bug
/kind cleanup
/kind deprecation
/kind design
/kind documentation
/kind failing-test
/kind feature

/kind flake

What this PR does / why we need it:

if kube-proxy is not able to get the lock it means a maximum penalty of 35 sec, 5 secs waiting to get the lock and 30 secs to retry

2019-11-30T16:47:27.528166227Z stderr F I1130 16:47:27.526891       1 proxier.go:784] Sync failed; retrying in 30s
2019-11-30T16:47:32.576137313Z stderr F E1130 16:47:32.574934       1 proxier.go:792] Failed to ensure that filter chain KUBE-EXTERNAL-SERVICES exists: error creating chain "KUBE-EXTERNAL-SERVICES": exit status 4: Another app is currently holding the xtables lock. Stopped waiting after 5s.

Currently, kubernetes uses the iptables -w 5 option, waiting 5 seconds to acquire the lock

  --wait        -w [seconds]    maximum wait to acquire xtables lock before give up
  --wait-interval -W [usecs]    wait time to try to acquire xtables lock
                                interval to wait for xtables lock
                                default is 1 second

We can be more aggressive trying to acquire the lock using an smaller interval

We can reproduce this situation using flock to hold the lock

acquire the lock in iptables

exec 3> /run/xtables.lock
flock -x 3

observe iptables behaviour with -W = 100000

root@kind-worker:/# ip6tables -L -w 5 -W 100000
Another app is currently holding the xtables lock; still 4s 100000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 3s 100000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 2s 100000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 1s 100000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 0s 100000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock. Stopped waiting after 5s.

observe iptables behaviour with -W = 10000


root@kind-worker:/# ip6tables -L -w 5 -W 10000
Another app is currently holding the xtables lock; still 4s 910000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 4s 810000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 4s 710000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 4s 610000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 4s 510000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 4s 410000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 4s 310000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 4s 210000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 4s 110000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 4s 10000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 3s 910000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 3s 810000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 3s 710000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 3s 610000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 3s 510000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 3s 410000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 3s 310000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 3s 210000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 3s 110000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 3s 10000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 2s 910000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 2s 810000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 2s 710000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 2s 610000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 2s 510000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 2s 410000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 2s 310000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 2s 210000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 2s 110000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 2s 10000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 1s 910000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 1s 810000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 1s 710000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 1s 610000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 1s 510000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 1s 410000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 1s 310000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 1s 210000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 1s 110000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 1s 10000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 0s 910000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 0s 810000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 0s 710000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 0s 610000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 0s 510000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 0s 410000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 0s 310000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 0s 210000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 0s 110000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock; still 0s 10000us time ahead to have a chance to grab the lock...
Another app is currently holding the xtables lock. Stopped waiting after 5s.

remove the lock

exec 3>&-

Which issue(s) this PR fixes:

Fixes #

Special notes for your reviewer:

Seems this was the previous behaviour based on

if err := wait.PollImmediate(200*time.Millisecond, 2*time.Second, func() (bool, error) {

and the one implemented for flushing the chains

const (
// Max time we wait for an iptables flush to complete after we notice it has started
iptablesFlushTimeout = 5 * time.Second
// How often we poll while waiting for an iptables flush to complete
iptablesFlushPollTime = 100 * time.Millisecond
)

Does this PR introduce a user-facing change?:

kubernetes will try to acquire the iptables lock every 100 msec during 5 seconds instead of every second. This specially useful for environments using kube-proxy in iptables mode with a high churn rate of services.

Additional documentation e.g., KEPs (Kubernetes Enhancement Proposals), usage docs, etc.:


pkg/util/iptables/iptables.go Outdated Show resolved Hide resolved
@k8s-ci-robot k8s-ci-robot requested review from dcbw and thockin Dec 1, 2019
@k8s-ci-robot k8s-ci-robot added sig/network and removed needs-sig labels Dec 1, 2019
@aojea

This comment has been minimized.

Copy link
Member Author

aojea commented Dec 1, 2019

/test pull-kubernetes-e2e-kind-ipv6
/test pull-kubernetes-conformance-kind-ipv6
/sig network
/assign @thockin @danwinship

@aojea aojea force-pushed the aojea:iptables_lock branch from 9f1cb05 to 2f32462 Dec 1, 2019
@aojea

This comment has been minimized.

Copy link
Member Author

aojea commented Dec 1, 2019

/test pull-kubernetes-e2e-kind-ipv6
/test pull-kubernetes-conformance-kind-ipv6

@aojea aojea force-pushed the aojea:iptables_lock branch from 2f32462 to 0804499 Dec 1, 2019
@aojea

This comment has been minimized.

Copy link
Member Author

aojea commented Dec 1, 2019

/test pull-kubernetes-e2e-kind-ipv6
/test pull-kubernetes-conformance-kind-ipv6

@danwinship

This comment has been minimized.

Copy link
Contributor

danwinship commented Dec 2, 2019

in the original PR you noted:

I wasn't able to reproduce the error and I was thinking that this have fixed it, but 🤔 is still happening with this change
#85727 (comment)

Don't know if this make sense now, just let me know if you consider it useful and I'll reopen it

So what changed?

As I said before, I don't think the kind problem is actually a timeout getting the lock, particularly given that kubelet reliably always acquires the lock successfully and kube-proxy reliably hits the timeout. Something else is going on there. (eg like with #82587 where pkg/util/iptables was grabbing the lock itself and then calling the iptable binary which also tried to grab the lock but was guaranteed to fail since we had already grabbed it).

@aojea

This comment has been minimized.

Copy link
Member Author

aojea commented Dec 2, 2019

So what changed?

I was investigating more the kind issue #85727 and as you say has to be something different ... However, I could observe that the values used in this PR are similar to the previous values used in kube-proxy when it didn't have the -w option, so I thought that it can make sense to have them again.

@aojea aojea force-pushed the aojea:iptables_lock branch from 0804499 to 073564a Dec 2, 2019
Copy link
Member

thockin left a comment

That looks more palatable to me - @danwinship has the final LGTM

/approve

@k8s-ci-robot

This comment has been minimized.

Copy link
Contributor

k8s-ci-robot commented Dec 3, 2019

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: aojea, thockin

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@aojea

This comment has been minimized.

Copy link
Member Author

aojea commented Dec 3, 2019

/test pull-kubernetes-integration
failed only 1 test that seems unrelated "TestPreemption"
/test pull-kubernetes-e2e-g
failed 6 storage tests that seems unrelated too

@aojea

This comment has been minimized.

Copy link
Member Author

aojea commented Dec 3, 2019

/test pull-kubernetes-e2e-gce

iptables has two options to modify the behaviour trying to
acquire the lock.

--wait  -w [seconds]    maximum wait to acquire xtables lock
                        before give up
--wait-interval -W [usecs]  wait time to try to acquire xtables
                            lock
                            interval to wait for xtables lock
                            default is 1 second

Kubernetes uses -w 5 that means that wait 5 seconds to try to
acquire the lock. If we are not able to acquire it, kube-proxy
fails and retries in 30 seconds, that is an important penalty
on sensitive applications.
We can be a bit more aggresive and try to acquire the lock every
100 msec, that means that we have to fail 50 times to not being
able to succeed.
@aojea aojea force-pushed the aojea:iptables_lock branch from 073564a to 51814ae Dec 3, 2019
@k8s-ci-robot k8s-ci-robot removed the size/S label Dec 3, 2019
@k8s-ci-robot k8s-ci-robot added the size/M label Dec 3, 2019
@aojea

This comment has been minimized.

Copy link
Member Author

aojea commented Dec 3, 2019

/test pull-kubernetes-e2e-kind-ipv6
/test pull-kubernetes-conformance-kind-ipv6

@aojea

This comment has been minimized.

Copy link
Member Author

aojea commented Dec 3, 2019

/retest

@aojea

This comment has been minimized.

Copy link
Member Author

aojea commented Dec 3, 2019

/test pull-kubernetes-e2e-kind-ipv6

@thockin

This comment has been minimized.

Copy link
Member

thockin commented Dec 16, 2019

@danwinship this is green - you hold LGTM

@danwinship

This comment has been minimized.

Copy link
Contributor

danwinship commented Dec 17, 2019

/lgtm

@k8s-ci-robot k8s-ci-robot added the lgtm label Dec 17, 2019
@k8s-ci-robot k8s-ci-robot merged commit d0e9018 into kubernetes:master Dec 17, 2019
17 checks passed
17 checks passed
cla/linuxfoundation aojea authorized
Details
pull-kubernetes-bazel-build Job succeeded.
Details
pull-kubernetes-bazel-test Job succeeded.
Details
pull-kubernetes-conformance-kind-ipv6 Job succeeded.
Details
pull-kubernetes-dependencies Job succeeded.
Details
pull-kubernetes-e2e-gce Job succeeded.
Details
pull-kubernetes-e2e-gce-100-performance Job succeeded.
Details
pull-kubernetes-e2e-gce-device-plugin-gpu Job succeeded.
Details
pull-kubernetes-e2e-kind Job succeeded.
Details
pull-kubernetes-e2e-kind-ipv6 Job succeeded.
Details
pull-kubernetes-integration Job succeeded.
Details
pull-kubernetes-kubemark-e2e-gce-big Job succeeded.
Details
pull-kubernetes-node-e2e Job succeeded.
Details
pull-kubernetes-node-e2e-containerd Job succeeded.
Details
pull-kubernetes-typecheck Job succeeded.
Details
pull-kubernetes-verify Job succeeded.
Details
tide In merge pool.
Details
@k8s-ci-robot k8s-ci-robot added this to the v1.18 milestone Dec 17, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.