rancher: panic: creating CRD store resource name may not be empty seen on startup

What kind of request is this (question/bug/enhancement/feature request): bug

Steps to reproduce (least amount of steps as possible): Run Rancher:

docker run -d --restart=unless-stopped -p 80:80 -p 443:443 -v /root/rancher:/var/lib/rancher rancher/rancher:master --debug

Result:

2019/03/07 11:16:41 [INFO] Running in single server mode, will not peer connections
2019/03/07 11:16:41 [DEBUG] Inspecting schema subscribe for subscribe.Subscribe
2019/03/07 11:16:41 [DEBUG] Inspecting field subscribe.resourceTypes for {ResourceTypes  []string  0 [0] false}
2019/03/07 11:16:41 [DEBUG] Setting field subscribe.resourceTypes: types.Field{Type:"array[string]", Default:interface {}(nil), Nullable:true, Create:true, WriteOnly:false, Required:false, Update:true, MinLength:(*int64)(nil), MaxLength:(*int64)(nil), Min:(*int64)(nil), Max:(*i
nt64)(nil), Options:[]string(nil), ValidChars:"", InvalidChars:"", Description:"", CodeName:"ResourceTypes", DynamicField:false}
2019/03/07 11:16:41 [DEBUG] Inspecting field subscribe.apiVersions for {APIVersions  []string  24 [1] false}
2019/03/07 11:16:41 [DEBUG] Setting field subscribe.apiVersions: types.Field{Type:"array[string]", Default:interface {}(nil), Nullable:true, Create:true, WriteOnly:false, Required:false, Update:true, MinLength:(*int64)(nil), MaxLength:(*int64)(nil), Min:(*int64)(nil), Max:(*int
64)(nil), Options:[]string(nil), ValidChars:"", InvalidChars:"", Description:"", CodeName:"APIVersions", DynamicField:false}
2019/03/07 11:16:41 [DEBUG] Inspecting field subscribe.projectId for {ProjectID  string norman:"type=reference[/v3/schemas/project]" 48 [2] false}                                                                                                                                   
2019/03/07 11:16:41 [DEBUG] Setting field subscribe.projectId: types.Field{Type:"reference[/v3/schemas/project]", Default:interface {}(nil), Nullable:true, Create:true, WriteOnly:false, Required:false, Update:true, MinLength:(*int64)(nil), MaxLength:(*int64)(nil), Min:(*int64)(
nil), Max:(*int64)(nil), Options:[]string(nil), ValidChars:"", InvalidChars:"", Description:"", CodeName:"ProjectID", DynamicField:false}
2019/03/07 11:16:41 [DEBUG] Inspecting schema subscribe for subscribe.Subscribe
2019/03/07 11:16:41 [DEBUG] Inspecting field subscribe.resourceTypes for {ResourceTypes  []string  0 [0] false}
2019/03/07 11:16:41 [DEBUG] Setting field subscribe.resourceTypes: types.Field{Type:"array[string]", Default:interface {}(nil), Nullable:true, Create:true, WriteOnly:false, Required:false, Update:true, MinLength:(*int64)(nil), MaxLength:(*int64)(nil), Min:(*int64)(nil), Max:(*i
nt64)(nil), Options:[]string(nil), ValidChars:"", InvalidChars:"", Description:"", CodeName:"ResourceTypes", DynamicField:false}
2019/03/07 11:16:41 [DEBUG] Inspecting field subscribe.apiVersions for {APIVersions  []string  24 [1] false}
2019/03/07 11:16:41 [DEBUG] Setting field subscribe.apiVersions: types.Field{Type:"array[string]", Default:interface {}(nil), Nullable:true, Create:true, WriteOnly:false, Required:false, Update:true, MinLength:(*int64)(nil), MaxLength:(*int64)(nil), Min:(*int64)(nil), Max:(*int
64)(nil), Options:[]string(nil), ValidChars:"", InvalidChars:"", Description:"", CodeName:"APIVersions", DynamicField:false}
2019/03/07 11:16:41 [DEBUG] Inspecting field subscribe.projectId for {ProjectID  string norman:"type=reference[/v3/schemas/project]" 48 [2] false}                                                                                                                                   
2019/03/07 11:16:41 [DEBUG] Setting field subscribe.projectId: types.Field{Type:"reference[/v3/schemas/project]", Default:interface {}(nil), Nullable:true, Create:true, WriteOnly:false, Required:false, Update:true, MinLength:(*int64)(nil), MaxLength:(*int64)(nil), Min:(*int64)(
nil), Max:(*int64)(nil), Options:[]string(nil), ValidChars:"", InvalidChars:"", Description:"", CodeName:"ProjectID", DynamicField:false}
2019/03/07 11:16:41 [DEBUG] Inspecting schema subscribe for subscribe.Subscribe
2019/03/07 11:16:41 [DEBUG] Inspecting field subscribe.resourceTypes for {ResourceTypes  []string  0 [0] false}
2019/03/07 11:16:41 [DEBUG] Setting field subscribe.resourceTypes: types.Field{Type:"array[string]", Default:interface {}(nil), Nullable:true, Create:true, WriteOnly:false, Required:false, Update:true, MinLength:(*int64)(nil), MaxLength:(*int64)(nil), Min:(*int64)(nil), Max:(*i
nt64)(nil), Options:[]string(nil), ValidChars:"", InvalidChars:"", Description:"", CodeName:"ResourceTypes", DynamicField:false}
2019/03/07 11:16:41 [DEBUG] Inspecting field subscribe.apiVersions for {APIVersions  []string  24 [1] false}
2019/03/07 11:16:41 [DEBUG] Setting field subscribe.apiVersions: types.Field{Type:"array[string]", Default:interface {}(nil), Nullable:true, Create:true, WriteOnly:false, Required:false, Update:true, MinLength:(*int64)(nil), MaxLength:(*int64)(nil), Min:(*int64)(nil), Max:(*int
64)(nil), Options:[]string(nil), ValidChars:"", InvalidChars:"", Description:"", CodeName:"APIVersions", DynamicField:false}
2019/03/07 11:16:41 [DEBUG] Inspecting field subscribe.projectId for {ProjectID  string norman:"type=reference[/v3/schemas/project]" 48 [2] false}                                                                                                                                   
2019/03/07 11:16:41 [DEBUG] Setting field subscribe.projectId: types.Field{Type:"reference[/v3/schemas/project]", Default:interface {}(nil), Nullable:true, Create:true, WriteOnly:false, Required:false, Update:true, MinLength:(*int64)(nil), MaxLength:(*int64)(nil), Min:(*int64)(
nil), Max:(*int64)(nil), Options:[]string(nil), ValidChars:"", InvalidChars:"", Description:"", CodeName:"ProjectID", DynamicField:false}
2019/03/07 11:16:41 [DEBUG] Inspecting schema subscribe for subscribe.Subscribe
2019/03/07 11:16:41 [DEBUG] Inspecting field subscribe.resourceTypes for {ResourceTypes  []string  0 [0] false}
2019/03/07 11:16:41 [DEBUG] Setting field subscribe.resourceTypes: types.Field{Type:"array[string]", Default:interface {}(nil), Nullable:true, Create:true, WriteOnly:false, Required:false, Update:true, MinLength:(*int64)(nil), MaxLength:(*int64)(nil), Min:(*int64)(nil), Max:(*i
nt64)(nil), Options:[]string(nil), ValidChars:"", InvalidChars:"", Description:"", CodeName:"ResourceTypes", DynamicField:false}
2019/03/07 11:16:41 [DEBUG] Inspecting field subscribe.apiVersions for {APIVersions  []string  24 [1] false}
2019/03/07 11:16:41 [DEBUG] Setting field subscribe.apiVersions: types.Field{Type:"array[string]", Default:interface {}(nil), Nullable:true, Create:true, WriteOnly:false, Required:false, Update:true, MinLength:(*int64)(nil), MaxLength:(*int64)(nil), Min:(*int64)(nil), Max:(*int
64)(nil), Options:[]string(nil), ValidChars:"", InvalidChars:"", Description:"", CodeName:"APIVersions", DynamicField:false}
2019/03/07 11:16:41 [DEBUG] Inspecting field subscribe.projectId for {ProjectID  string norman:"type=reference[/v3/schemas/project]" 48 [2] false}                                                                                                                                   
2019/03/07 11:16:41 [DEBUG] Setting field subscribe.projectId: types.Field{Type:"reference[/v3/schemas/project]", Default:interface {}(nil), Nullable:true, Create:true, WriteOnly:false, Required:false, Update:true, MinLength:(*int64)(nil), MaxLength:(*int64)(nil), Min:(*int64)(
nil), Max:(*int64)(nil), Options:[]string(nil), ValidChars:"", InvalidChars:"", Description:"", CodeName:"ProjectID", DynamicField:false}
2019/03/07 11:16:41 [INFO] Creating CRD globalroles.management.cattle.io
2019/03/07 11:16:41 [INFO] Waiting for CRD  to become available
2019/03/07 11:16:42 [INFO] Done waiting for CRD  to become available
panic: creating CRD store resource name may not be empty

goroutine 2832 [running]:
github.com/rancher/rancher/vendor/github.com/rancher/norman/store/crd.(*Factory).BatchCreateCRDs.func1(0xc0042195c0, 0xc004194e00, 0x34, 0x34, 0xc0036ace60, 0x6a298e0, 0x4182600, 0xc0012f5740, 0x3a64338, 0x4)                                                                     
        /go/src/github.com/rancher/rancher/vendor/github.com/rancher/norman/store/crd/init.go:65 +0x2d9
created by github.com/rancher/rancher/vendor/github.com/rancher/norman/store/crd.(*Factory).BatchCreateCRDs
        /go/src/github.com/rancher/rancher/vendor/github.com/rancher/norman/store/crd/init.go:50 +0xce

Other details that may be helpful: Not always reproducible

Environment information

Rancher version (rancher/rancher/rancher/server image tag or shown bottom left in the UI): master 3/7
Installation option (single install/HA): single

gzrancher/rancher#6658

About this issue

Original URL
State: closed
Created 5 years ago
Reactions: 14
Comments: 45 (5 by maintainers)

Most upvoted comments

I encountered the same problem.

Environment

Operation System: CentOS Linux release 7.6.1810 Docker: 17.03.2-ce Rancher: v2.2.1

Step to reproduce:

docker run -d --restart=unless-stopped -p 80:80 -p 443:443 rancher/rancher:v2.2.1

Result:

Rancher was keeping restart, show the logs below

aaronwng on Apr 2, 2019

I can confirm this is a slow disk issue and that could potentially be a problem given how slow some cloud virtual disks can be.

I have a SATA II drive I like to store my VM disks on and had to move this one to my SSD to get the container to start.

tburnett80 on Jul 22, 2019

@superseb you can rm -rf /var/lib/rancher/management-state or mv to other path

CoderPoet on Apr 14, 2019

Hello, I have the same issue from v2.2.0 version, if I downgrade to v2.1.8. This is work again. I’m using rancher-04 4.14.85-rancher OS

processor : 0 vendor_id : GenuineIntel cpu family : 6 model : 92 model name : Intel® Celeron® CPU J3455 @ 1.50GHz stepping : 9 microcode : 0x1 cpu MHz : 1497.610 cache size : 1024 KB physical id : 0 siblings : 1 core id : 0 cpu cores : 1 apicid : 0 initial apicid : 0 fpu : yes fpu_exception : yes cpuid level : 13 wp : yes flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon rep_good nopl cpuid tsc_known_freq pni pclmulqdq ssse3 cx16 sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes rdrand hypervisor lahf_lm 3dnowprefetch pti fsgsbase tsc_adjust smep erms mpx rdseed smap clflushopt bugs : cpu_meltdown spectre_v1 spectre_v2 spec_store_bypass bogomips : 2995.22 clflush size : 64 cache_alignment : 64 address sizes : 40 bits physical, 48 bits virtual power management:

jtisserand on Apr 6, 2019

Thanks @izaac.

As this issue is running on a much older issue and bigger changes made around startup might have gotten this fixed.

I’ll be closing this issue until someone can hit this in v2.4.8+ or 2.5.x

deniseschannon on Oct 15, 2020

Yeah, that looks like a sporadic issue and is likely IO related. I’ve also got this with v2.2.4 as soon as I’ve started Rancher on a server with slow HDD disks. (100 %util in iostat, ~600-900ms disk sync duration (WAL/DB fsync) [Etcd prometheus->grafana metrics] whereas on my laptop with SSD I’ve got this value 10x times better - ~30-80ms disk sync)

Logs https://gist.github.com/arno01/9c64069175b75d22a52be2fc0a8b84ef

shortly before the panic there also was this error, not sure if that helps.

F0612 12:52:24.738311       6 controllermanager.go:184] error building controller context: failed to wait for apiserver being healthy: timed out waiting for the condition: failed to get apiserver /healthz status: an error on the server ("[+]ping ok\n[+]log ok\n[+]etcd ok\n[+]poststarthook/generic-apiserver-start-informers ok\n[+]poststarthook/start-apiextensions-informers ok\n[+]poststarthook/start-apiextensions-controllers ok\n[+]poststarthook/bootstrap-controller ok\n[-]poststarthook/rbac/bootstrap-roles failed: reason withheld\n[+]poststarthook/scheduling/bootstrap-system-priority-classes ok\n[+]poststarthook/start-kube-apiserver-informers ok\n[+]poststarthook/start-kube-apiserver-admission-initializer ok\nhealthz check failed") has prevented the request from succeeding

arno01 on Jun 12, 2019

@jmreicha et al, if you don’t mount the volume to a specific location you’re still writing to the physical disk, albeit in a temporary volume that gets destroyed along with the removal of the container. This is not recommended, because you can lose data.

What I recommended is to mount to a ramdisk-backed directory, which has no I/O bottleneck, and then, once the boostrap finishes, stop and remove the container, move the data from the ramdisk-backed directory to a physical hard-drive-backed directory, and start the container back again with the new mount.

isavcic on Jun 6, 2019

The issue seems to be sporadic as I am seeing it in v2.2.4 still. Tried with and without volume mounts.

On my first attempt after downloading the new image, I got the initial error message and the container died a few times starting up, but eventually all of the resources get created and etcd mellowed out and Rancher came up.

However, I tried stopping the container, blowing out the data and recreating again and I started seeing the panic errors again and it continuously restarts.

Panic error:

panic: creating CRD store resource name may not be empty

goroutine 2847 [running]:
github.com/rancher/rancher/vendor/github.com/rancher/norman/store/crd.(*Factory).BatchCreateCRDs.func1(0xc004012ce0, 0xc003f97c00, 0x34, 0x34, 0xc00357a0a0, 0x6ac3540, 0x41f1ba0, 0xc000f19300, 0x3aa7d01, 0x4)
        /go/src/github.com/rancher/rancher/vendor/github.com/rancher/norman/store/crd/init.go:65 +0x2d9
created by github.com/rancher/rancher/vendor/github.com/rancher/norman/store/crd.(*Factory).BatchCreateCRDs
        /go/src/github.com/rancher/rancher/vendor/github.com/rancher/norman/store/crd/init.go:50 +0xce

jmreicha on Jun 6, 2019

I’ve had the same problem, found a workaround that works for me.

The problem occurred on Ubuntu 19.04, fresh install, btrfs on “/” mount, docker 18.09.5 (e8ff056), decent machine with 24 cores, 32GB RAM. Same “panic: creating CRD store resource name may not be empty seen on startup” on multiple tries with rancher:v2.2.2. Mounting volume on /dev/shm as @isavcic suggested worked for me but it had an obvious drawback of not persisting the configuration on server restart.

Inspired by the fact that @isavcic managed to make it work on shm and by the fact that Canonical Distribution of Kubernetes (CDK) instructs not to use btrfs on the underlying lxd (what whatever reason), I’ve decided to mount /var/lib/rancher on an ext4 filesystem. And that works for me. I can’t explain it, so it might be purely coincidental.

wnaumienko on May 14, 2019