bucketbench icon indicating copy to clipboard operation
bucketbench copied to clipboard

Published 20 hours ago • verified publisher icon estesp

[CRI-O] "name is reserved" errors during testinng

Open rkevin-arch opened this issue 4 years ago • 1 comments

I'm using the following command to test out CRI-O:

sudo ~/go/bin/bucketbench run -b examples/crio.yaml

The first time it runs, there is no problem. On subsequent runs using the same command, I get flooded with errors like these:

ERRO[0016] Error on creating container "bb-ctr-1-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-1-0_bucketbench.test.cri_bucketbench-test-cri_1 for id b421a43db43086a3c98e5ecdc556aa1638359ec2c817a7d742832cf7954242fd: name is reserved 
ERRO[0021] Error on creating container "bb-ctr-1-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-1-0_bucketbench.test.cri_bucketbench-test-cri_1 for id bb5fc18bb43d01b76dde8e8dfb653bad11a618648d99d39e29139efbdd01916e: name is reserved 
ERRO[0027] Error on creating container "bb-ctr-1-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-1-0_bucketbench.test.cri_bucketbench-test-cri_1 for id 5cb4ef38b6567f3e552f8b242b7dbc6035f8375eb613522be53d12e66d0abcad: name is reserved 
ERRO[0027] Error on creating container "bb-ctr-3-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-3-0_bucketbench.test.cri_bucketbench-test-cri_1 for id ee29da5843a30489727770b80aa17c7b43969d14fbd5a1b5125642bc1ed0c4b9: name is reserved 
WARN[0029] Error during container command "run" on "bb-ctr-2-0": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving ctr name k8s_bb-ctr-2-0_podbb-ctr-2-0_bucketbench.test.cri_bucketbench-test-cri_1 for id 1391e8881ec343a77f46597d8a3d6e22126347495ab5ea3152f9736396f2f479: name is reserved
  Output:  
ERRO[0033] Error on creating container "bb-ctr-2-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-2-0_bucketbench.test.cri_bucketbench-test-cri_1 for id 2529661483e31db3de843c219161457366dd17dd295e7b0a563a32e577f57336: name is reserved 
ERRO[0033] Error on creating container "bb-ctr-1-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-1-0_bucketbench.test.cri_bucketbench-test-cri_1 for id a08f4dd4902c6329b9a7bedf17e51ec0655ed8262c6eba87747a45d52e713684: name is reserved 
ERRO[0033] Error on creating container "bb-ctr-3-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-3-0_bucketbench.test.cri_bucketbench-test-cri_1 for id 996d816e6361e42f4c1b2e4041d7c67d4ea5b65f2c95d3eb50b3af918073b323: name is reserved

A reboot fixes this problem temporarily. Sometimes the benchmark is still able to finish, but sometimes it fails entirely:

ERRO[0017] Error on creating container "bb-ctr-0-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-1-0_bucketbench.test.cri_bucketbench-test-cri_1 for id b428d8fe6fee771dc8751a8671bb5fffb46613111dab3a7eb17e793c6947c6ef: name is reserved 
ERRO[0017] Error on creating container "bb-ctr-1-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-1-0_bucketbench.test.cri_bucketbench-test-cri_1 for id be5966d24ce40d482e90c6e0e4b1288c039b580f73e842ed7e2acc83c8dad7ad: name is reserved 
ERRO[0020] Error on creating container "bb-ctr-2-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-2-0_bucketbench.test.cri_bucketbench-test-cri_1 for id 8d0fc61a114aef13db610adc4e99a9c74ea681ec964ea40339c5208de8caaa38: name is reserved 
ERRO[0020] Error on creating container "bb-ctr-1-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-1-0_bucketbench.test.cri_bucketbench-test-cri_1 for id 155978499cf77e15b082ff4d904b64122cc063e19b9d580beeef733f9833d663: name is reserved 
ERRO[0025] Error on creating container "bb-ctr-1-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-1-0_bucketbench.test.cri_bucketbench-test-cri_1 for id f5ce4916ef14caeccad17d47b273a27343561322fb807970b71e39e0940ff754: name is reserved 
ERRO[0025] Error on creating container "bb-ctr-3-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-3-0_bucketbench.test.cri_bucketbench-test-cri_1 for id c443ca475919e8dff31bf9d8daed5fafd604da1fa56034ae8fc7f4b416b74003: name is reserved 
ERRO[0025] Error on creating container "bb-ctr-2-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-2-0_bucketbench.test.cri_bucketbench-test-cri_1 for id ce67e482a6e697e3ee6bfe00a7f830cfb9b83a6f0a10f414e3639f3778917ef7: name is reserved 
ERRO[0031] Error on creating container "bb-ctr-2-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-2-0_bucketbench.test.cri_bucketbench-test-cri_1 for id ea3773c6890a69eed6c569f80f8715885cbf850e576a084c8dd9c1f629cdb193: name is reserved 
ERRO[0031] Error on creating container "bb-ctr-1-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-1-0_bucketbench.test.cri_bucketbench-test-cri_1 for id b4b50853054403918bca6adc4ffa2e0dd7c6cf13c46f8f04d1a5443fbdf3495c: name is reserved 
ERRO[0031] Error on creating container "bb-ctr-4-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-4-0_bucketbench.test.cri_bucketbench-test-cri_1 for id 1e3bc0833ec61f2a977f757a06df0aa70b715437b0ddd04006880c037f01bcb2: name is reserved 
ERRO[0031] Error on creating container "bb-ctr-3-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = Kubelet may be retrying requests that are timing out in CRI-O due to system load: error reserving pod name k8s_podbb-ctr-3-0_bucketbench.test.cri_bucketbench-test-cri_1 for id 948a3f23375865c3713e4e16fcf9056b10081fa422e63d9f3095db51b4968882: name is reserved 

SUMMARY TIMINGS/THREAD RATES

              Iter/Thd    1 thrd   2 thrds   3 thrds   4 thrds   5 thrds   6 thrds   7 thrds   8 thrds   9 thrds  10 thrds 
       Limit      1000   1082.40   3103.82   5074.84   6392.66   6849.29   7243.41   7567.09   7573.90   7572.76   7491.32 
  Custom:CRI         1      0.34    188.81      1.15      1.33      1.60 

DETAILED COMMAND TIMINGS/STATISTICS
panic: runtime error: index out of range [0] with length 0

goroutine 1 [running]:
github.com/estesp/bucketbench/cmd.parseStats(0x0, 0x0, 0x0, 0x28)
	/home/rkevin/go/src/github.com/estesp/bucketbench/cmd/run.go:431 +0xbc5
github.com/estesp/bucketbench/cmd.outputRunDetails(0xa, 0xc000916000, 0x2, 0x2, 0x0)
	/home/rkevin/go/src/github.com/estesp/bucketbench/cmd/run.go:263 +0x15ba
github.com/estesp/bucketbench/cmd.glob..func1(0x190cee0, 0xc0004f6e80, 0x0, 0x2, 0x0, 0x0)
	/home/rkevin/go/src/github.com/estesp/bucketbench/cmd/run.go:129 +0x4cc
github.com/estesp/bucketbench/vendor/github.com/spf13/cobra.(*Command).execute(0x190cee0, 0xc0004f6e00, 0x2, 0x2, 0x190cee0, 0xc0004f6e00)
	/home/rkevin/go/src/github.com/estesp/bucketbench/vendor/github.com/spf13/cobra/command.go:647 +0x405
github.com/estesp/bucketbench/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0x190ccc0, 0xc0002dff78, 0x846885, 0xc00010e058)
	/home/rkevin/go/src/github.com/estesp/bucketbench/vendor/github.com/spf13/cobra/command.go:726 +0x2cf
github.com/estesp/bucketbench/vendor/github.com/spf13/cobra.(*Command).Execute(...)
	/home/rkevin/go/src/github.com/estesp/bucketbench/vendor/github.com/spf13/cobra/command.go:685
main.main()
	/home/rkevin/go/src/github.com/estesp/bucketbench/bucketbench.go:25 +0x31

I can't find a way to replicate the failure consistently other than running the command again and again. System info:

rkevin@redshift:~$ uname -a
Linux redshift 5.9.11-arch2-1 #1 SMP PREEMPT Sat, 28 Nov 2020 02:07:22 +0000 x86_64 GNU/Linux
rkevin@redshift:~$ lsb_release -a
LSB Version:	1.4
Distributor ID:	Arch
Description:	Arch Linux
Release:	rolling
Codename:	n/a
rkevin@redshift:~$ sudo crictl version
Version:  0.1.0
RuntimeName:  cri-o
RuntimeVersion:  1.19.0
RuntimeApiVersion:  v1alpha1

rkevin-arch avatar Dec 05 '20 12:12 rkevin-arch

I haven't had a chance to test cri-o in quite some time. This looks like the cleanup process (that removes all containers/tasks after the benchmark run(s)) is not working properly for cri-o and/or via the CRI API. I will try and see if I have an easy setup where I can validate this.

estesp avatar Dec 07 '20 18:12 estesp

I also enconterd same issue,when i was benchmarking cri-o.

tophac avatar May 29 '23 09:05 tophac

I believe I have identified one of the reasons. During the execution of multiple coroutine tests, there is a possibility that the value of pconfig.Metadata.Name may be overwritten by other Go coroutines. This can occur due to the shallow copy of the global variable pconfigGlobal, while other coroutines have already performed the creation operation on the same Name. Consequently, this leads to a name conflict error: 'name is reserved'.

https://github.com/estesp/bucketbench/blob/022901239071b39ba2ccd3f4f19a8d406055e1b9/driver/cri.go#L172-L178

In my use case, when executing the following test.

drivers:
  -
   type: CRI
   threads: 4
   iterations: 25
   clientpath: /var/run/crio/crio.sock

Occasionally an error will be reported:

ERRO[0241] Error on creating container "bb-ctr-1-0" from image "docker.io/library/alpine:latest": rpc error: code = Unknown desc = kubelet may be retrying requests that are timing out in CRI-O due to system load. Currently at stage sandbox storage creation: waited too long for request to timeout or sandbox k8s_podbb-ctr-3-0_bucketbench.test.cri_bucketbench-test-cri_1 to be created: error reserving pod name k8s_podbb-ctr-3-0_bucketbench.test.cri_bucketbench-test-cri_1 for id 2f287538ba7a4de30964acf1860030b966c69a8958297975f9a1b1bcd2caae90: name is reserved

It is evident that the error name received from CRI-O is 'bb-ctr-3-0,' whereas bucketbench is actually executing as 'bb-ctr-1-0.' This suggests that, due to concurrent operations, the value assigned to 'bb-ctr-1-0' was overwritten by the value of 'bb-ctr-3-0' before it could be created. Consequently, CRI-O reasonably identifies the creation request as a duplication.

whygyc avatar Jun 19 '23 09:06 whygyc

All in all, it is not safe to directly modify global variables in a concurrent environment. We may need to do a deep copy before each assignment to pconfig or cconfig?

whygyc avatar Jun 19 '23 09:06 whygyc