Open sam-sre opened 2 years ago
@anasalloush thanks for creating this issue! Could you also post the vcluster logs in here?
Hi @FabianKramm
k logs vcluster-1-0 -c vcluster -n host-namespace-1
time="2021-10-13T07:42:45Z" level=info msg="Starting k3s v1.22.1-rc1+k3s1 (58315fe1)"
time="2021-10-13T07:42:45Z" level=info msg="Cluster bootstrap already complete"
time="2021-10-13T07:42:45Z" level=info msg="Configuring sqlite3 database connection pooling: maxIdleConns=2, maxOpenConns=0, connMaxLifetime=0s"
time="2021-10-13T07:42:45Z" level=info msg="Configuring database table schema and indexes, this may take a moment..."
time="2021-10-13T07:42:45Z" level=info msg="Database tables and indexes are up to date"
time="2021-10-13T07:42:45Z" level=info msg="Kine listening on unix://kine.sock"
time="2021-10-13T07:42:45Z" level=info msg="Running kube-apiserver --advertise-port=6443 --allow-privileged=true --anonymous-auth=false --api-audiences=https://kubernetes.default.svc.cluster.local,k3s --authorization-mode=Node,RBAC --bind-address=127.0.0.1 --cert-dir=/data/server/tls/temporary-certs --client-ca-file=/data/server/tls/client-ca.crt --enable-admission-plugins=NodeRestriction --etcd-servers=unix://kine.sock --insecure-port=0 --kubelet-certificate-authority=/data/server/tls/server-ca.crt --kubelet-client-certificate=/data/server/tls/client-kube-apiserver.crt --kubelet-client-key=/data/server/tls/client-kube-apiserver.key --profiling=false --proxy-client-cert-file=/data/server/tls/client-auth-proxy.crt --proxy-client-key-file=/data/server/tls/client-auth-proxy.key --requestheader-allowed-names=system:auth-proxy --requestheader-client-ca-file=/data/server/tls/request-header-ca.crt --requestheader-extra-headers-prefix=X-Remote-Extra- --requestheader-group-headers=X-Remote-Group --requestheader-username-headers=X-Remote-User --secure-port=6444 --service-account-issuer=https://kubernetes.default.svc.cluster.local --service-account-key-file=/data/server/tls/service.key --service-account-signing-key-file=/data/server/tls/service.key --service-cluster-ip-range=10.96.0.0/12 --service-node-port-range=30000-32767 --storage-backend=etcd3 --tls-cert-file=/data/server/tls/serving-kube-apiserver.crt --tls-private-key-file=/data/server/tls/serving-kube-apiserver.key"
Flag --insecure-port has been deprecated, This flag has no effect now and will be removed in v1.24.
I1013 07:42:45.087893 1 server.go:581] external host was not specified, using 172.17.0.5
I1013 07:42:45.088102 1 server.go:175] Version: v1.22.1-rc1+k3s1
I1013 07:42:45.092577 1 plugins.go:158] Loaded 12 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,RuntimeClass,DefaultIngressClass,MutatingAdmissionWebhook.
I1013 07:42:45.092606 1 plugins.go:161] Loaded 11 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota.
I1013 07:42:45.092759 1 shared_informer.go:240] Waiting for caches to sync for node_authorizer
I1013 07:42:45.094213 1 plugins.go:158] Loaded 12 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,RuntimeClass,DefaultIngressClass,MutatingAdmissionWebhook.
I1013 07:42:45.094258 1 plugins.go:161] Loaded 11 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota.
W1013 07:42:45.109414 1 genericapiserver.go:455] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources.
I1013 07:42:45.110292 1 instance.go:278] Using reconciler: lease
I1013 07:42:45.149661 1 rest.go:130] the default service ipfamily for this cluster is: IPv4
W1013 07:42:45.503441 1 genericapiserver.go:455] Skipping API authentication.k8s.io/v1beta1 because it has no resources.
W1013 07:42:45.504979 1 genericapiserver.go:455] Skipping API authorization.k8s.io/v1beta1 because it has no resources.
W1013 07:42:45.514261 1 genericapiserver.go:455] Skipping API certificates.k8s.io/v1beta1 because it has no resources.
W1013 07:42:45.515374 1 genericapiserver.go:455] Skipping API coordination.k8s.io/v1beta1 because it has no resources.
W1013 07:42:45.519266 1 genericapiserver.go:455] Skipping API networking.k8s.io/v1beta1 because it has no resources.
W1013 07:42:45.521243 1 genericapiserver.go:455] Skipping API node.k8s.io/v1alpha1 because it has no resources.
W1013 07:42:45.525727 1 genericapiserver.go:455] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.
W1013 07:42:45.525751 1 genericapiserver.go:455] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.
W1013 07:42:45.526779 1 genericapiserver.go:455] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.
W1013 07:42:45.526802 1 genericapiserver.go:455] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources.
W1013 07:42:45.529570 1 genericapiserver.go:455] Skipping API storage.k8s.io/v1alpha1 because it has no resources.
W1013 07:42:45.531153 1 genericapiserver.go:455] Skipping API flowcontrol.apiserver.k8s.io/v1alpha1 because it has no resources.
W1013 07:42:45.534919 1 genericapiserver.go:455] Skipping API apps/v1beta2 because it has no resources.
W1013 07:42:45.534943 1 genericapiserver.go:455] Skipping API apps/v1beta1 because it has no resources.
W1013 07:42:45.536624 1 genericapiserver.go:455] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.
I1013 07:42:45.540135 1 plugins.go:158] Loaded 12 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,RuntimeClass,DefaultIngressClass,MutatingAdmissionWebhook.
I1013 07:42:45.540157 1 plugins.go:161] Loaded 11 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota.
W1013 07:42:45.546512 1 genericapiserver.go:455] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.
time="2021-10-13T07:42:45Z" level=info msg="Running kube-controller-manager --allocate-node-cidrs=true --bind-address=127.0.0.1 --cluster-cidr=10.42.0.0/16 --cluster-signing-kube-apiserver-client-cert-file=/data/server/tls/client-ca.crt --cluster-signing-kube-apiserver-client-key-file=/data/server/tls/client-ca.key --cluster-signing-kubelet-client-cert-file=/data/server/tls/client-ca.crt --cluster-signing-kubelet-client-key-file=/data/server/tls/client-ca.key --cluster-signing-kubelet-serving-cert-file=/data/server/tls/server-ca.crt --cluster-signing-kubelet-serving-key-file=/data/server/tls/server-ca.key --cluster-signing-legacy-unknown-cert-file=/data/server/tls/client-ca.crt --cluster-signing-legacy-unknown-key-file=/data/server/tls/client-ca.key --controllers=*,-nodeipam,-nodelifecycle,-persistentvolume-binder,-attachdetach,-persistentvolume-expander,-cloud-node-lifecycle --kubeconfig=/data/server/cred/controller.kubeconfig --leader-elect=false --profiling=false --root-ca-file=/data/server/tls/server-ca.crt --secure-port=10257 --service-account-private-key-file=/data/server/tls/service.key --use-service-account-credentials=true"
time="2021-10-13T07:42:45Z" level=info msg="Waiting for API server to become available"
time="2021-10-13T07:42:45Z" level=info msg="Node token is available at /data/server/token"
time="2021-10-13T07:42:45Z" level=info msg="To join node to cluster: k3s agent -s https://172.17.0.5:6443 -t ${NODE_TOKEN}"
time="2021-10-13T07:42:45Z" level=info msg="Wrote kubeconfig /k3s-config/kube-config.yaml"
time="2021-10-13T07:42:45Z" level=info msg="Run: k3s kubectl"
I1013 07:42:46.715416 1 dynamic_cafile_content.go:155] "Starting controller" name="request-header::/data/server/tls/request-header-ca.crt"
I1013 07:42:46.715456 1 secure_serving.go:266] Serving securely on 127.0.0.1:6444
I1013 07:42:46.715472 1 dynamic_cafile_content.go:155] "Starting controller" name="client-ca-bundle::/data/server/tls/client-ca.crt"
I1013 07:42:46.715486 1 dynamic_serving_content.go:129] "Starting controller" name="serving-cert::/data/server/tls/serving-kube-apiserver.crt::/data/server/tls/serving-kube-apiserver.key"
I1013 07:42:46.715507 1 tlsconfig.go:240] "Starting DynamicServingCertificateController"
I1013 07:42:46.715534 1 available_controller.go:491] Starting AvailableConditionController
I1013 07:42:46.715538 1 cache.go:32] Waiting for caches to sync for AvailableConditionController controller
I1013 07:42:46.715953 1 apiservice_controller.go:97] Starting APIServiceRegistrationController
I1013 07:42:46.715973 1 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller
I1013 07:42:46.716024 1 autoregister_controller.go:141] Starting autoregister controller
I1013 07:42:46.716030 1 cache.go:32] Waiting for caches to sync for autoregister controller
I1013 07:42:46.716083 1 controller.go:83] Starting OpenAPI AggregationController
I1013 07:42:46.716177 1 customresource_discovery_controller.go:209] Starting DiscoveryController
I1013 07:42:46.716209 1 controller.go:85] Starting OpenAPI controller
I1013 07:42:46.716219 1 naming_controller.go:291] Starting NamingConditionController
I1013 07:42:46.716226 1 establishing_controller.go:76] Starting EstablishingController
I1013 07:42:46.716233 1 nonstructuralschema_controller.go:192] Starting NonStructuralSchemaConditionController
I1013 07:42:46.716264 1 apiapproval_controller.go:186] Starting KubernetesAPIApprovalPolicyConformantConditionController
I1013 07:42:46.716404 1 crd_finalizer.go:266] Starting CRDFinalizer
I1013 07:42:46.717922 1 apf_controller.go:299] Starting API Priority and Fairness config controller
I1013 07:42:46.718265 1 cluster_authentication_trust_controller.go:440] Starting cluster_authentication_trust_controller controller
I1013 07:42:46.718288 1 shared_informer.go:240] Waiting for caches to sync for cluster_authentication_trust_controller
I1013 07:42:46.718334 1 dynamic_serving_content.go:129] "Starting controller" name="aggregator-proxy-cert::/data/server/tls/client-auth-proxy.crt::/data/server/tls/client-auth-proxy.key"
I1013 07:42:46.719087 1 crdregistration_controller.go:111] Starting crd-autoregister controller
I1013 07:42:46.719118 1 shared_informer.go:240] Waiting for caches to sync for crd-autoregister
I1013 07:42:46.721584 1 dynamic_cafile_content.go:155] "Starting controller" name="client-ca-bundle::/data/server/tls/client-ca.crt"
I1013 07:42:46.721632 1 dynamic_cafile_content.go:155] "Starting controller" name="request-header::/data/server/tls/request-header-ca.crt"
W1013 07:42:46.729978 1 controller.go:292] Resetting master service "kubernetes" to &v1.Service{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"kubernetes", GenerateName:"", Namespace:"default", SelfLink:"", UID:"4673ebf3-0137-403c-9d39-3cf0b1221b15", ResourceVersion:"443", Generation:0, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:63769646606, loc:(*time.Location)(0x7fbe9e0)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string{"component":"apiserver", "provider":"kubernetes"}, Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string(nil), ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry{v1.ManagedFieldsEntry{Manager:"vcluster", Operation:"Update", APIVersion:"v1", Time:(*v1.Time)(0xc00334f518), FieldsType:"FieldsV1", FieldsV1:(*v1.FieldsV1)(0xc00334f548), Subresource:""}}}, Spec:v1.ServiceSpec{Ports:[]v1.ServicePort{v1.ServicePort{Name:"https", Protocol:"TCP", AppProtocol:(*string)(nil), Port:443, TargetPort:intstr.IntOrString{Type:0, IntVal:6443, StrVal:""}, NodePort:0}}, Selector:map[string]string(nil), ClusterIP:"10.101.159.59", ClusterIPs:[]string{"10.101.159.59"}, Type:"ClusterIP", ExternalIPs:[]string(nil), SessionAffinity:"None", LoadBalancerIP:"", LoadBalancerSourceRanges:[]string(nil), ExternalName:"", ExternalTrafficPolicy:"", HealthCheckNodePort:0, PublishNotReadyAddresses:false, SessionAffinityConfig:(*v1.SessionAffinityConfig)(nil), IPFamilies:[]v1.IPFamily{"IPv4"}, IPFamilyPolicy:(*v1.IPFamilyPolicyType)(0xc00865be50), AllocateLoadBalancerNodePorts:(*bool)(nil), LoadBalancerClass:(*string)(nil), InternalTrafficPolicy:(*v1.ServiceInternalTrafficPolicyType)(0xc00865be90)}, Status:v1.ServiceStatus{LoadBalancer:v1.LoadBalancerStatus{Ingress:[]v1.LoadBalancerIngress(nil)}, Conditions:[]v1.Condition(nil)}}
W1013 07:42:46.747201 1 lease.go:233] Resetting endpoints for master service "kubernetes" to [172.17.0.5]
I1013 07:42:46.748338 1 controller.go:611] quota admission added evaluator for: endpoints
I1013 07:42:46.752568 1 controller.go:611] quota admission added evaluator for: endpointslices.discovery.k8s.io
E1013 07:42:46.764289 1 controller.go:156] Unable to remove old endpoints from kubernetes service: no master IPs were listed in storage, refusing to erase all endpoints for the kubernetes service
I1013 07:42:46.792920 1 shared_informer.go:247] Caches are synced for node_authorizer
I1013 07:42:46.815977 1 cache.go:39] Caches are synced for AvailableConditionController controller
I1013 07:42:46.816135 1 cache.go:39] Caches are synced for APIServiceRegistrationController controller
I1013 07:42:46.816201 1 cache.go:39] Caches are synced for autoregister controller
I1013 07:42:46.818356 1 shared_informer.go:247] Caches are synced for cluster_authentication_trust_controller
I1013 07:42:46.818465 1 apf_controller.go:304] Running API Priority and Fairness config worker
I1013 07:42:46.819223 1 shared_informer.go:247] Caches are synced for crd-autoregister
I1013 07:42:47.715319 1 controller.go:132] OpenAPI AggregationController: action for item : Nothing (removed from the queue).
I1013 07:42:47.727627 1 storage_scheduling.go:148] all system priority classes are created successfully or already exist.
W1013 07:42:47.993737 1 lease.go:233] Resetting endpoints for master service "kubernetes" to [172.17.0.5]
I1013 07:42:48.153962 1 controller.go:132] OpenAPI AggregationController: action for item k8s_internal_local_delegation_chain_0000000000: Nothing (removed from the queue).
time="2021-10-13T07:42:48Z" level=info msg="Kube API server is now running"
time="2021-10-13T07:42:48Z" level=info msg="k3s is up and running"
time="2021-10-13T07:42:48Z" level=warning msg="Deploy controller node name is empty or too long, and will not be tracked via server side apply field management"
time="2021-10-13T07:42:48Z" level=info msg="Applying CRD addons.k3s.cattle.io"
time="2021-10-13T07:42:48Z" level=info msg="Applying CRD helmcharts.helm.cattle.io"
time="2021-10-13T07:42:48Z" level=info msg="Applying CRD helmchartconfigs.helm.cattle.io"
time="2021-10-13T07:42:48Z" level=info msg="Writing static file: /data/server/static/charts/traefik-10.3.0.tgz"
time="2021-10-13T07:42:48Z" level=info msg="Writing static file: /data/server/static/charts/traefik-crd-10.3.0.tgz"
time="2021-10-13T07:42:48Z" level=info msg="Writing manifest: /data/server/manifests/coredns.yaml"
time="2021-10-13T07:42:48Z" level=info msg="Writing manifest: /data/server/manifests/rolebindings.yaml"
time="2021-10-13T07:42:48Z" level=info msg="Starting k3s.cattle.io/v1, Kind=Addon controller"
time="2021-10-13T07:42:48Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"coredns\", UID:\"32fe4dce-6389-4d44-963e-2b186e5ea0b5\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"225\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/data/server/manifests/coredns.yaml\""
time="2021-10-13T07:42:48Z" level=info msg="Cluster dns configmap already exists"
I1013 07:42:48.946001 1 controller.go:611] quota admission added evaluator for: deployments.apps
time="2021-10-13T07:42:48Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"coredns\", UID:\"32fe4dce-6389-4d44-963e-2b186e5ea0b5\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"225\", FieldPath:\"\"}): type: 'Warning' reason: 'ApplyManifestFailed' Applying manifest at \"/data/server/manifests/coredns.yaml\" failed: failed to update kube-system/kube-dns /v1, Kind=Service for kube-system/coredns: Service \"kube-dns\" is invalid: spec.clusterIPs[0]: Invalid value: []string{\"10.96.0.10\"}: may not change once set"
time="2021-10-13T07:42:48Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"rolebindings\", UID:\"2e1b7d72-bf81-48b6-a38c-adc37b735d33\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"235\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/data/server/manifests/rolebindings.yaml\""
time="2021-10-13T07:42:48Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"rolebindings\", UID:\"2e1b7d72-bf81-48b6-a38c-adc37b735d33\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"235\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/data/server/manifests/rolebindings.yaml\""
I1013 07:42:48.974171 1 controller.go:611] quota admission added evaluator for: addons.k3s.cattle.io
time="2021-10-13T07:42:48Z" level=error msg="Failed to process config: failed to process /data/server/manifests/coredns.yaml: failed to update kube-system/kube-dns /v1, Kind=Service for kube-system/coredns: Service \"kube-dns\" is invalid: spec.clusterIPs[0]: Invalid value: []string{\"10.96.0.10\"}: may not change once set"
time="2021-10-13T07:42:49Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChart controller"
time="2021-10-13T07:42:49Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChartConfig controller"
time="2021-10-13T07:42:49Z" level=info msg="Starting apps/v1, Kind=DaemonSet controller"
time="2021-10-13T07:42:49Z" level=info msg="Starting apps/v1, Kind=Deployment controller"
time="2021-10-13T07:42:49Z" level=info msg="Starting rbac.authorization.k8s.io/v1, Kind=ClusterRoleBinding controller"
time="2021-10-13T07:42:49Z" level=info msg="Starting batch/v1, Kind=Job controller"
time="2021-10-13T07:42:49Z" level=info msg="Starting /v1, Kind=Node controller"
time="2021-10-13T07:42:49Z" level=info msg="Starting /v1, Kind=ConfigMap controller"
time="2021-10-13T07:42:49Z" level=info msg="Starting /v1, Kind=ServiceAccount controller"
time="2021-10-13T07:42:49Z" level=info msg="Starting /v1, Kind=Pod controller"
time="2021-10-13T07:42:49Z" level=info msg="Starting /v1, Kind=Service controller"
time="2021-10-13T07:42:49Z" level=info msg="Starting /v1, Kind=Endpoints controller"
I1013 07:42:49.175145 1 serving.go:354] Generated self-signed cert in-memory
time="2021-10-13T07:42:49Z" level=info msg="Starting /v1, Kind=Secret controller"
W1013 07:42:49.363726 1 requestheader_controller.go:193] Unable to get configmap/extension-apiserver-authentication in kube-system. Usually fixed by 'kubectl create rolebinding -n kube-system ROLEBINDING_NAME --role=extension-apiserver-authentication-reader --serviceaccount=YOUR_NS:YOUR_SA'
unable to load configmap based request-header-client-ca-file: configmaps "extension-apiserver-authentication" is forbidden: User "system:serviceaccount:host-namespace-1:vc-vcluster-1" cannot get resource "configmaps" in API group "" in the namespace "kube-system"
Hi,
On my other issue I had the same problems, the environment was Kubernetes v1.20 (kubeadm) cluster running within Vagrant boxes
I wanted to check if the environment is causing these problems, so I changed to Minikube running within a VM.
Environment:
Outputs and Logs