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

rawResources failed to read Resources and secret truststore not found on getting started #653

Closed
wtfiwtz opened this issue Nov 4, 2020 · 21 comments

Comments

@wtfiwtz
Copy link

wtfiwtz commented Nov 4, 2020

Hi there,
I came across a few issues following the instructions on Mac OS 10.15.7 with kubectl on v1.19.3:

bin/config.sh -v 7.0 init
minikube ip
skaffold dev

... failed with...

WARN[0427] deployer cleanup: reading manifests: kustomize build: running [kubectl --context minikube kustomize ./kustomize/overlay/7.0/all]
 - stdout: ""
 - stderr: "Error: rawResources failed to read Resources: Load from path ../../../base/kustomizeConfig failed: '../../../base/kustomizeConfig' must be a file (got d='/Users/nigelss/Developer/allianz/forgeops/kustomize/base/kustomizeConfig')\n\n"
 - cause: exit status 1
exiting dev mode because first deploy failed: reading manifests: kustomize build: running [kubectl --context minikube kustomize ./kustomize/overlay/7.0/all]
 - stdout: ""
 - stderr: "Error: rawResources failed to read Resources: Load from path ../../../base/kustomizeConfig failed: '../../../base/kustomizeConfig' must be a file (got d='/Users/nigelss/Developer/allianz/forgeops/kustomize/base/kustomizeConfig')\n\n"
 - cause: exit status 1

I solved this with brew install kustomize to get v3.8.6 instead of the bundled 2.0.3 with kubectl. Here's some related issues:
kubernetes-sigs/kustomize#1424
kubernetes/kubernetes#82905
kubernetes/kubernetes#89887
kubernetes/kubectl#818
kubernetes-sigs/kustomize#1500
kubernetes-sigs/kustomize#1647
kubernetes-sigs/kustomize#1648 (comment)
kubernetes-sigs/kustomize#776
kubernetes-sigs/kustomize#1556

Then I got stuck with...

 - Warning: extensions/v1beta1 Ingress is deprecated in v1.14+, unavailable in v1.22+; use networking.k8s.io/v1 Ingress
 - unable to recognize "STDIN": no matches for kind "SecretAgentConfiguration" in version "secret-agent.secrets.forgerock.io/v1alpha1"
WARN[0009] deployer cleanup: delete: kubectl delete: exit status 1
exiting dev mode because first deploy failed: running [kubectl --context minikube get -f - --ignore-not-found -ojson]
 - stdout: ""
 - stderr: "Warning: extensions/v1beta1 Ingress is deprecated in v1.14+, unavailable in v1.22+; use networking.k8s.io/v1 Ingress\nerror: unable to recognize \"STDIN\": no matches for kind \"SecretAgentConfiguration\" in version \"secret-agent.secrets.forgerock.io/v1alpha1\"\n"
 - cause: exit status 1

... which I solved by running bin/quickstart.sh.

It's getting further along, but I'm now getting trustStore issues too.

Waiting for deployments to stabilize...
 - deployment/admin-ui: creating container admin-ui
    - pod/admin-ui-7c6944b48b-9lxg4: creating container admin-ui
 - deployment/am: FailedMount: MountVolume.SetUp failed for volume "truststore" : secret "truststore" not found
    - pod/am-5b76c7bdfd-b4fxv: FailedMount: MountVolume.SetUp failed for volume "truststore" : secret "truststore" not found
 - deployment/end-user-ui: creating container end-user-ui
    - pod/end-user-ui-87c65467f-4fsbj: creating container end-user-ui
 - deployment/login-ui: creating container login-ui
    - pod/login-ui-7b4fc4c544-7v4gf: creating container login-ui
 - deployment/login-ui is ready. [3/4 deployment(s) still pending]
 - deployment/end-user-ui: waiting for rollout to finish: 0 of 1 updated replicas are available...
 - deployment/admin-ui is ready. [2/4 deployment(s) still pending]
 - deployment/end-user-ui is ready. [1/4 deployment(s) still pending]
 - deployment/am: FailedMount: MountVolume.SetUp failed for volume "truststore" : secret "truststore" not found
    - pod/am-5b76c7bdfd-b4fxv: FailedMount: MountVolume.SetUp failed for volume "truststore" : secret "truststore" not found
 - deployment/am failed. Error: FailedMount: MountVolume.SetUp failed for volume "truststore" : secret "truststore" not found.

Any suggestions? I'll see if I can find the issue.

Cheers,
Nigel

@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 4, 2020

I ran skaffold dev a few more times, and perhaps also bin/config.sh -v 7.0 init again. It seems to be working now as it seems like some of the Docker containers are running.

Cheers!
Nigel

@wtfiwtz wtfiwtz closed this as completed Nov 4, 2020
@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 4, 2020

Forgive me as I've not run Kubernetes before, although I have done work with Docker in the past...

docker/forgeops-secrets/forgeops-secrets-image/getset.sh seems to call kubectl get secret and kubectl create secret.

https://kubernetes.io/docs/concepts/configuration/secret/

Does that mean there is an issue with the forgeops-secrets-image container if the truststore secrets have not been created correctly?

I am able to get bin/print-secrets.sh to run and print the secrets there but the https://default.iam.example.com/am page doesn't load yet.

Cheers,
Nigel

@wtfiwtz wtfiwtz reopened this Nov 4, 2020
@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 4, 2020

minikube logs gives me:

==> container status <==
CONTAINER           IMAGE               CREATED             STATE               NAME                      ATTEMPT             POD ID
d91fadba71714       fde36ae0e4bce       7 minutes ago       Running             openam                    1                   d096a9c3ea853
445722f3afb10       9210468cbb05e       8 minutes ago       Running             manager                   8                   1ab022cda92f9
f472a8a4f413c       7fc4bb5249ac3       9 minutes ago       Running             ds                        0                   87e9741c0e1d8
dd7aa77007a3b       96939e3daaa10       9 minutes ago       Running             ds                        0                   f93436b77bac0
bfcabb60bdd39       fde36ae0e4bce       9 minutes ago       Exited              openam                    0                   d096a9c3ea853
759d23751d25c       fde36ae0e4bce       9 minutes ago       Exited              fbc-init                  0                   d096a9c3ea853
f76e9332df8e5       b8167415c4b66       9 minutes ago       Exited              amster                    0                   1e3bdc4072c6a
434866ec3d1c8       bad58561c4be7       9 minutes ago       Running             storage-provisioner       6                   e67ad6fb1f654
0688ec40ef16b       9210468cbb05e       10 minutes ago      Exited              manager                   7                   1ab022cda92f9
99b904ba18f55       80ef592a1a3cc       10 minutes ago      Exited              ldif-importer             0                   89c96e3fb15c1
d2a8303adaac0       96939e3daaa10       10 minutes ago      Exited              initialize                3                   f93436b77bac0
a5b3371040e6f       7fc4bb5249ac3       11 minutes ago      Exited              initialize                2                   87e9741c0e1d8
a49c57b1dbef9       bad58561c4be7       11 minutes ago      Exited              storage-provisioner       5                   e67ad6fb1f654
bd39d15880d69       84e3dadf45f2a       11 minutes ago      Running             end-user-ui               0                   da8a59ad7fa83
75560962179ed       44dce61b49e0f       12 minutes ago      Running             login-ui                  0                   b4fbff0915d70
1d62426b7c552       a2d84f77bcf59       12 minutes ago      Running             admin-ui                  0                   c61c52345ee4d
1d68f6134d649       bfe3a36ebd252       17 hours ago        Running             coredns                   0                   e163287f28582
ddae2464e6251       d373dd5a8593a       17 hours ago        Running             kube-proxy                0                   7449b3d30fa8a
3574420a0b477       0369cf4303ffd       17 hours ago        Running             etcd                      0                   b575a4064df77
9f00a2e42be5a       2f32d66b884f8       17 hours ago        Running             kube-scheduler            0                   fbd33725df1e0
a49eef47071ca       607331163122e       17 hours ago        Running             kube-apiserver            0                   b883e66159568
0b08ddf636f3c       8603821e1a7a5       17 hours ago        Running             kube-controller-manager   0                   73f1c50f15de9

Looks like some serious errors in the kube-scheduler:

==> kube-scheduler [9f00a2e42be5] <==
I1104 04:51:26.708299       1 registry.go:173] Registering SelectorSpread plugin
I1104 04:51:26.708896       1 registry.go:173] Registering SelectorSpread plugin
I1104 04:51:28.712292       1 serving.go:331] Generated self-signed cert in-memory
W1104 04:51:33.250391       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'
W1104 04:51:33.250438       1 authentication.go:294] Error looking up in-cluster authentication configuration: configmaps "extension-apiserver-authentication" is forbidden: User "system:kube-scheduler" cannot get resource "configmaps" in API group "" in the namespace "kube-system"
W1104 04:51:33.250448       1 authentication.go:295] Continuing without authentication configuration. This may treat all requests as anonymous.
W1104 04:51:33.250453       1 authentication.go:296] To require authentication configuration lookup to succeed, set --authentication-tolerate-lookup-failure=false
I1104 04:51:33.298650       1 registry.go:173] Registering SelectorSpread plugin
I1104 04:51:33.298769       1 registry.go:173] Registering SelectorSpread plugin
I1104 04:51:33.307701       1 secure_serving.go:197] Serving securely on 127.0.0.1:10259
E1104 04:51:33.337239       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.StorageClass: failed to list *v1.StorageClass: storageclasses.storage.k8s.io is forbidden: User "system:kube-scheduler" cannot list resource "storageclasses" in API group "storage.k8s.io" at the cluster scope
E1104 04:51:33.337935       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.Service: failed to list *v1.Service: services is forbidden: User "system:kube-scheduler" cannot list resource "services" in API group "" at the cluster scope
E1104 04:51:33.338023       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.StatefulSet: failed to list *v1.StatefulSet: statefulsets.apps is forbidden: User "system:kube-scheduler" cannot list resource "statefulsets" in API group "apps" at the cluster scope
E1104 04:51:33.338112       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.PersistentVolume: failed to list *v1.PersistentVolume: persistentvolumes is forbidden: User "system:kube-scheduler" cannot list resource "persistentvolumes" in API group "" at the cluster scope
E1104 04:51:33.338225       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.PersistentVolumeClaim: failed to list *v1.PersistentVolumeClaim: persistentvolumeclaims is forbidden: User "system:kube-scheduler" cannot list resource "persistentvolumeclaims" in API group "" at the cluster scope
I1104 04:51:33.338248       1 tlsconfig.go:240] Starting DynamicServingCertificateController
I1104 04:51:33.340032       1 configmap_cafile_content.go:202] Starting client-ca::kube-system::extension-apiserver-authentication::client-ca-file
I1104 04:51:33.342681       1 shared_informer.go:240] Waiting for caches to sync for client-ca::kube-system::extension-apiserver-authentication::client-ca-file
E1104 04:51:33.349468       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.Pod: failed to list *v1.Pod: pods is forbidden: User "system:kube-scheduler" cannot list resource "pods" in API group "" at the cluster scope
E1104 04:51:33.349652       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.CSINode: failed to list *v1.CSINode: csinodes.storage.k8s.io is forbidden: User "system:kube-scheduler" cannot list resource "csinodes" in API group "storage.k8s.io" at the cluster scope
E1104 04:51:33.349901       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.ReplicationController: failed to list *v1.ReplicationController: replicationcontrollers is forbidden: User "system:kube-scheduler" cannot list resource "replicationcontrollers" in API group "" at the cluster scope
E1104 04:51:33.350100       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.ReplicaSet: failed to list *v1.ReplicaSet: replicasets.apps is forbidden: User "system:kube-scheduler" cannot list resource "replicasets" in API group "apps" at the cluster scope
E1104 04:51:33.350236       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.Node: failed to list *v1.Node: nodes is forbidden: User "system:kube-scheduler" cannot list resource "nodes" in API group "" at the cluster scope
E1104 04:51:33.350532       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1beta1.PodDisruptionBudget: failed to list *v1beta1.PodDisruptionBudget: poddisruptionbudgets.policy is forbidden: User "system:kube-scheduler" cannot list resource "poddisruptionbudgets" in API group "policy" at the cluster scope
E1104 04:51:33.351579       1 reflector.go:127] k8s.io/kubernetes/cmd/kube-scheduler/app/server.go:188: Failed to watch *v1.Pod: failed to list *v1.Pod: pods is forbidden: User "system:kube-scheduler" cannot list resource "pods" in API group "" at the cluster scope
E1104 04:51:33.351974       1 reflector.go:127] k8s.io/apiserver/pkg/server/dynamiccertificates/configmap_cafile_content.go:206: Failed to watch *v1.ConfigMap: failed to list *v1.ConfigMap: configmaps "extension-apiserver-authentication" is forbidden: User "system:kube-scheduler" cannot list resource "configmaps" in API group "" in the namespace "kube-system"
E1104 04:51:34.191779       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.Node: failed to list *v1.Node: nodes is forbidden: User "system:kube-scheduler" cannot list resource "nodes" in API group "" at the cluster scope
E1104 04:51:34.263317       1 reflector.go:127] k8s.io/apiserver/pkg/server/dynamiccertificates/configmap_cafile_content.go:206: Failed to watch *v1.ConfigMap: failed to list *v1.ConfigMap: configmaps "extension-apiserver-authentication" is forbidden: User "system:kube-scheduler" cannot list resource "configmaps" in API group "" in the namespace "kube-system"
E1104 04:51:34.266902       1 reflector.go:127] k8s.io/kubernetes/cmd/kube-scheduler/app/server.go:188: Failed to watch *v1.Pod: failed to list *v1.Pod: pods is forbidden: User "system:kube-scheduler" cannot list resource "pods" in API group "" at the cluster scope
E1104 04:51:34.331903       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.ReplicaSet: failed to list *v1.ReplicaSet: replicasets.apps is forbidden: User "system:kube-scheduler" cannot list resource "replicasets" in API group "apps" at the cluster scope
E1104 04:51:34.422802       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.PersistentVolume: failed to list *v1.PersistentVolume: persistentvolumes is forbidden: User "system:kube-scheduler" cannot list resource "persistentvolumes" in API group "" at the cluster scope
E1104 04:51:34.428217       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.Pod: failed to list *v1.Pod: pods is forbidden: User "system:kube-scheduler" cannot list resource "pods" in API group "" at the cluster scope
E1104 04:51:34.428652       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.ReplicationController: failed to list *v1.ReplicationController: replicationcontrollers is forbidden: User "system:kube-scheduler" cannot list resource "replicationcontrollers" in API group "" at the cluster scope
E1104 04:51:34.488623       1 reflector.go:127] k8s.io/client-go/informers/factory.go:134: Failed to watch *v1.StatefulSet: failed to list *v1.StatefulSet: statefulsets.apps is forbidden: User "system:kube-scheduler" cannot list resource "statefulsets" in API group "apps" at the cluster scope
I1104 04:51:36.943332       1 shared_informer.go:247] Caches are synced for client-ca::kube-system::extension-apiserver-authentication::client-ca-file 

... and also the kubelet:

==> kubelet <==
-- Logs begin at Wed 2020-11-04 04:50:53 UTC, end at Wed 2020-11-04 22:09:55 UTC. --
Nov 04 21:59:35 minikube kubelet[3708]: E1104 21:59:35.711194    3708 pod_workers.go:191] Error syncing pod f654bb76-3fe2-4e71-88c6-e8a78bb9a2a5 ("storage-provisioner_kube-system(f654bb76-3fe2-4e71-88c6-e8a78bb9a2a5)"), skipping: failed to "StartContainer" for "storage-provisioner" with CrashLoopBackOff: "back-off 10s restarting failed container=storage-provisioner pod=storage-provisioner_kube-system(f654bb76-3fe2-4e71-88c6-e8a78bb9a2a5)"
Nov 04 21:59:41 minikube kubelet[3708]: E1104 21:59:41.465489    3708 kubelet.go:1594] Unable to attach or mount volumes for pod "am-7468ff6c8b-nj8lp_default(ce551c12-5718-4e4b-acc8-40254230fbaa)": unmounted volumes=[am-secrets amster-key], unattached volumes=[fbc default-token-dpmmh truststore am-secrets amster-key]: timed out waiting for the condition; skipping pod
Nov 04 21:59:41 minikube kubelet[3708]: E1104 21:59:41.465582    3708 pod_workers.go:191] Error syncing pod ce551c12-5718-4e4b-acc8-40254230fbaa ("am-7468ff6c8b-nj8lp_default(ce551c12-5718-4e4b-acc8-40254230fbaa)"), skipping: unmounted volumes=[am-secrets amster-key], unattached volumes=[fbc default-token-dpmmh truststore am-secrets amster-key]: timed out waiting for the condition
Nov 04 21:59:42 minikube kubelet[3708]: E1104 21:59:42.069675    3708 kubelet.go:1594] Unable to attach or mount volumes for pod "amster-bqdzf_default(e59fea36-b297-41cd-9ff1-9a244c28ef26)": unmounted volumes=[amster-secrets], unattached volumes=[amster-secrets default-token-dpmmh]: timed out waiting for the condition; skipping pod
Nov 04 21:59:42 minikube kubelet[3708]: E1104 21:59:42.069763    3708 pod_workers.go:191] Error syncing pod e59fea36-b297-41cd-9ff1-9a244c28ef26 ("amster-bqdzf_default(e59fea36-b297-41cd-9ff1-9a244c28ef26)"), skipping: unmounted volumes=[amster-secrets], unattached volumes=[amster-secrets default-token-dpmmh]: timed out waiting for the condition
Nov 04 21:59:46 minikube kubelet[3708]: I1104 21:59:46.929628    3708 topology_manager.go:219] [topologymanager] RemoveContainer - Container ID: afe81d6dead83478ec07adce6ee1c9ec676b518e2c63c13c085f384904c9d1cf
Nov 04 21:59:47 minikube kubelet[3708]: W1104 21:59:47.927625    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for secret-agent-system/secret-agent-controller-manager-68b74bfd4c-zr6jq through plugin: invalid network status for
Nov 04 21:59:48 minikube kubelet[3708]: I1104 21:59:48.929691    3708 topology_manager.go:219] [topologymanager] RemoveContainer - Container ID: a49c57b1dbef9190f5c64838544047810db28980ea1261f8ca6e3625518bc076
Nov 04 21:59:54 minikube kubelet[3708]: W1104 21:59:54.695029    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/amster-bqdzf through plugin: invalid network status for
Nov 04 21:59:54 minikube kubelet[3708]: W1104 21:59:54.697379    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/amster-bqdzf through plugin: invalid network status for
Nov 04 21:59:54 minikube kubelet[3708]: W1104 21:59:54.705873    3708 pod_container_deletor.go:79] Container "1e3bdc4072c6a658b4378754062e37f9d17cfdce427d5370586e6844558e475e" not found in pod's containers
Nov 04 21:59:55 minikube kubelet[3708]: W1104 21:59:55.805141    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/amster-bqdzf through plugin: invalid network status for
Nov 04 21:59:56 minikube kubelet[3708]: W1104 21:59:56.255734    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/am-7468ff6c8b-nj8lp through plugin: invalid network status for
Nov 04 21:59:56 minikube kubelet[3708]: W1104 21:59:56.270691    3708 pod_container_deletor.go:79] Container "d096a9c3ea8530a72c2399357a6536fe5e92847d9baeeff0370803c9b33da58f" not found in pod's containers
Nov 04 21:59:57 minikube kubelet[3708]: W1104 21:59:57.332973    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/am-7468ff6c8b-nj8lp through plugin: invalid network status for
Nov 04 22:00:02 minikube kubelet[3708]: W1104 22:00:02.470805    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/am-7468ff6c8b-nj8lp through plugin: invalid network status for
Nov 04 22:00:03 minikube kubelet[3708]: W1104 22:00:03.504277    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/am-7468ff6c8b-nj8lp through plugin: invalid network status for
Nov 04 22:00:07 minikube kubelet[3708]: W1104 22:00:07.605296    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/ds-cts-0 through plugin: invalid network status for
Nov 04 22:00:07 minikube kubelet[3708]: I1104 22:00:07.637641    3708 topology_manager.go:219] [topologymanager] RemoveContainer - Container ID: 2b796ee4dad313eda2b83abd85502bfcced3e536ce79d6f31ecf95486373b92c
Nov 04 22:00:07 minikube kubelet[3708]: I1104 22:00:07.639009    3708 topology_manager.go:219] [topologymanager] RemoveContainer - Container ID: 2b796ee4dad313eda2b83abd85502bfcced3e536ce79d6f31ecf95486373b92c
Nov 04 22:00:07 minikube kubelet[3708]: E1104 22:00:07.666171    3708 remote_runtime.go:291] RemoveContainer "2b796ee4dad313eda2b83abd85502bfcced3e536ce79d6f31ecf95486373b92c" from runtime service failed: rpc error: code = Unknown desc = failed to remove container "2b796ee4dad313eda2b83abd85502bfcced3e536ce79d6f31ecf95486373b92c": Error response from daemon: removal of container 2b796ee4dad313eda2b83abd85502bfcced3e536ce79d6f31ecf95486373b92c is already in progress
Nov 04 22:00:07 minikube kubelet[3708]: E1104 22:00:07.666543    3708 kuberuntime_container.go:704] failed to remove pod init container "initialize": rpc error: code = Unknown desc = failed to remove container "2b796ee4dad313eda2b83abd85502bfcced3e536ce79d6f31ecf95486373b92c": Error response from daemon: removal of container 2b796ee4dad313eda2b83abd85502bfcced3e536ce79d6f31ecf95486373b92c is already in progress; Skipping pod "ds-cts-0_default(78a39b00-afcb-41b0-bb0c-dfcb06fbc070)"
Nov 04 22:00:08 minikube kubelet[3708]: E1104 22:00:08.220663    3708 controller.go:178] failed to update node lease, error: Put "https://control-plane.minikube.internal:8443/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/minikube?timeout=10s": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
Nov 04 22:00:08 minikube kubelet[3708]: W1104 22:00:08.676401    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/ds-cts-0 through plugin: invalid network status for
Nov 04 22:00:13 minikube kubelet[3708]: E1104 22:00:13.207292    3708 controller.go:178] failed to update node lease, error: Operation cannot be fulfilled on leases.coordination.k8s.io "minikube": the object has been modified; please apply your changes to the latest version and try again
Nov 04 22:00:13 minikube kubelet[3708]: W1104 22:00:13.831043    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/ds-idrepo-0 through plugin: invalid network status for
Nov 04 22:00:13 minikube kubelet[3708]: I1104 22:00:13.859702    3708 topology_manager.go:219] [topologymanager] RemoveContainer - Container ID: a4f291fbdc99347919c50e2ff4d47ca771e89693bb364006522abe3429151088
Nov 04 22:00:13 minikube kubelet[3708]: I1104 22:00:13.860239    3708 topology_manager.go:219] [topologymanager] RemoveContainer - Container ID: a4f291fbdc99347919c50e2ff4d47ca771e89693bb364006522abe3429151088
Nov 04 22:00:13 minikube kubelet[3708]: E1104 22:00:13.888666    3708 remote_runtime.go:291] RemoveContainer "a4f291fbdc99347919c50e2ff4d47ca771e89693bb364006522abe3429151088" from runtime service failed: rpc error: code = Unknown desc = failed to remove container "a4f291fbdc99347919c50e2ff4d47ca771e89693bb364006522abe3429151088": Error response from daemon: removal of container a4f291fbdc99347919c50e2ff4d47ca771e89693bb364006522abe3429151088 is already in progress
Nov 04 22:00:13 minikube kubelet[3708]: E1104 22:00:13.888752    3708 kuberuntime_container.go:704] failed to remove pod init container "initialize": rpc error: code = Unknown desc = failed to remove container "a4f291fbdc99347919c50e2ff4d47ca771e89693bb364006522abe3429151088": Error response from daemon: removal of container a4f291fbdc99347919c50e2ff4d47ca771e89693bb364006522abe3429151088 is already in progress; Skipping pod "ds-idrepo-0_default(304fa84d-4338-41cb-9be0-33e09dc28417)"
Nov 04 22:00:14 minikube kubelet[3708]: W1104 22:00:14.886850    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/ds-idrepo-0 through plugin: invalid network status for
Nov 04 22:00:41 minikube kubelet[3708]: W1104 22:00:41.501916    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for secret-agent-system/secret-agent-controller-manager-68b74bfd4c-zr6jq through plugin: invalid network status for
Nov 04 22:00:41 minikube kubelet[3708]: I1104 22:00:41.523590    3708 topology_manager.go:219] [topologymanager] RemoveContainer - Container ID: afe81d6dead83478ec07adce6ee1c9ec676b518e2c63c13c085f384904c9d1cf
Nov 04 22:00:41 minikube kubelet[3708]: I1104 22:00:41.524112    3708 topology_manager.go:219] [topologymanager] RemoveContainer - Container ID: 0688ec40ef16b61e5adaaabd81330b87c7b216a30235795cee1bb5e99c392cf5
Nov 04 22:00:41 minikube kubelet[3708]: E1104 22:00:41.524770    3708 pod_workers.go:191] Error syncing pod a05a642e-d9a7-44b2-9896-43755ab277e4 ("secret-agent-controller-manager-68b74bfd4c-zr6jq_secret-agent-system(a05a642e-d9a7-44b2-9896-43755ab277e4)"), skipping: failed to "StartContainer" for "manager" with CrashLoopBackOff: "back-off 20s restarting failed container=manager pod=secret-agent-controller-manager-68b74bfd4c-zr6jq_secret-agent-system(a05a642e-d9a7-44b2-9896-43755ab277e4)"
Nov 04 22:00:42 minikube kubelet[3708]: W1104 22:00:42.545184    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for secret-agent-system/secret-agent-controller-manager-68b74bfd4c-zr6jq through plugin: invalid network status for
Nov 04 22:00:55 minikube kubelet[3708]: I1104 22:00:55.929103    3708 topology_manager.go:219] [topologymanager] RemoveContainer - Container ID: 0688ec40ef16b61e5adaaabd81330b87c7b216a30235795cee1bb5e99c392cf5
Nov 04 22:00:55 minikube kubelet[3708]: E1104 22:00:55.929561    3708 pod_workers.go:191] Error syncing pod a05a642e-d9a7-44b2-9896-43755ab277e4 ("secret-agent-controller-manager-68b74bfd4c-zr6jq_secret-agent-system(a05a642e-d9a7-44b2-9896-43755ab277e4)"), skipping: failed to "StartContainer" for "manager" with CrashLoopBackOff: "back-off 20s restarting failed container=manager pod=secret-agent-controller-manager-68b74bfd4c-zr6jq_secret-agent-system(a05a642e-d9a7-44b2-9896-43755ab277e4)"
Nov 04 22:01:09 minikube kubelet[3708]: I1104 22:01:09.929742    3708 topology_manager.go:219] [topologymanager] RemoveContainer - Container ID: 0688ec40ef16b61e5adaaabd81330b87c7b216a30235795cee1bb5e99c392cf5
Nov 04 22:01:10 minikube kubelet[3708]: W1104 22:01:10.208973    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for secret-agent-system/secret-agent-controller-manager-68b74bfd4c-zr6jq through plugin: invalid network status for
Nov 04 22:01:11 minikube kubelet[3708]: W1104 22:01:11.436418    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for secret-agent-system/secret-agent-controller-manager-68b74bfd4c-zr6jq through plugin: invalid network status for
Nov 04 22:01:54 minikube kubelet[3708]: W1104 22:01:54.253329    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/am-7468ff6c8b-nj8lp through plugin: invalid network status for
Nov 04 22:03:12 minikube kubelet[3708]: W1104 22:03:12.225247    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/ldif-importer-jsgxm through plugin: invalid network status for
Nov 04 22:03:12 minikube kubelet[3708]: I1104 22:03:12.233852    3708 topology_manager.go:219] [topologymanager] RemoveContainer - Container ID: 99b904ba18f5528bceb3496692730c862eea9919c19ce4e7ecd3a82fd6796246
Nov 04 22:03:12 minikube kubelet[3708]: I1104 22:03:12.326667    3708 reconciler.go:196] operationExecutor.UnmountVolume started for volume "passwords" (UniqueName: "kubernetes.io/secret/e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c-passwords") pod "e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c" (UID: "e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c")
Nov 04 22:03:12 minikube kubelet[3708]: I1104 22:03:12.326985    3708 reconciler.go:196] operationExecutor.UnmountVolume started for volume "default-token-dpmmh" (UniqueName: "kubernetes.io/secret/e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c-default-token-dpmmh") pod "e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c" (UID: "e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c")
Nov 04 22:03:12 minikube kubelet[3708]: I1104 22:03:12.336725    3708 operation_generator.go:788] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c-passwords" (OuterVolumeSpecName: "passwords") pod "e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c" (UID: "e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c"). InnerVolumeSpecName "passwords". PluginName "kubernetes.io/secret", VolumeGidValue ""
Nov 04 22:03:12 minikube kubelet[3708]: I1104 22:03:12.337044    3708 operation_generator.go:788] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c-default-token-dpmmh" (OuterVolumeSpecName: "default-token-dpmmh") pod "e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c" (UID: "e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c"). InnerVolumeSpecName "default-token-dpmmh". PluginName "kubernetes.io/secret", VolumeGidValue ""
Nov 04 22:03:12 minikube kubelet[3708]: I1104 22:03:12.427680    3708 reconciler.go:319] Volume detached for volume "default-token-dpmmh" (UniqueName: "kubernetes.io/secret/e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c-default-token-dpmmh") on node "minikube" DevicePath ""
Nov 04 22:03:12 minikube kubelet[3708]: I1104 22:03:12.427744    3708 reconciler.go:319] Volume detached for volume "passwords" (UniqueName: "kubernetes.io/secret/e7ae6b4a-3380-47c4-85bf-c5cd551d2b5c-passwords") on node "minikube" DevicePath ""
Nov 04 22:03:13 minikube kubelet[3708]: W1104 22:03:13.284106    3708 pod_container_deletor.go:79] Container "89c96e3fb15c1ba3b1fe688da4a5db3b6d50e6e355ea5397a983e0b568c57512" not found in pod's containers
Nov 04 22:05:16 minikube kubelet[3708]: W1104 22:05:16.306714    3708 docker_sandbox.go:402] failed to read pod IP from plugin/docker: Couldn't find network status for default/amster-bqdzf through plugin: invalid network status for
Nov 04 22:05:16 minikube kubelet[3708]: I1104 22:05:16.316154    3708 topology_manager.go:219] [topologymanager] RemoveContainer - Container ID: f76e9332df8e51db98b785d210786d5fa64462a8c9e1271f75946c5332659fe7
Nov 04 22:05:16 minikube kubelet[3708]: I1104 22:05:16.574040    3708 reconciler.go:196] operationExecutor.UnmountVolume started for volume "default-token-dpmmh" (UniqueName: "kubernetes.io/secret/e59fea36-b297-41cd-9ff1-9a244c28ef26-default-token-dpmmh") pod "e59fea36-b297-41cd-9ff1-9a244c28ef26" (UID: "e59fea36-b297-41cd-9ff1-9a244c28ef26")
Nov 04 22:05:16 minikube kubelet[3708]: I1104 22:05:16.574134    3708 reconciler.go:196] operationExecutor.UnmountVolume started for volume "amster-secrets" (UniqueName: "kubernetes.io/secret/e59fea36-b297-41cd-9ff1-9a244c28ef26-amster-secrets") pod "e59fea36-b297-41cd-9ff1-9a244c28ef26" (UID: "e59fea36-b297-41cd-9ff1-9a244c28ef26")
Nov 04 22:05:16 minikube kubelet[3708]: I1104 22:05:16.586010    3708 operation_generator.go:788] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/e59fea36-b297-41cd-9ff1-9a244c28ef26-amster-secrets" (OuterVolumeSpecName: "amster-secrets") pod "e59fea36-b297-41cd-9ff1-9a244c28ef26" (UID: "e59fea36-b297-41cd-9ff1-9a244c28ef26"). InnerVolumeSpecName "amster-secrets". PluginName "kubernetes.io/secret", VolumeGidValue ""
Nov 04 22:05:16 minikube kubelet[3708]: I1104 22:05:16.602613    3708 operation_generator.go:788] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/e59fea36-b297-41cd-9ff1-9a244c28ef26-default-token-dpmmh" (OuterVolumeSpecName: "default-token-dpmmh") pod "e59fea36-b297-41cd-9ff1-9a244c28ef26" (UID: "e59fea36-b297-41cd-9ff1-9a244c28ef26"). InnerVolumeSpecName "default-token-dpmmh". PluginName "kubernetes.io/secret", VolumeGidValue ""
Nov 04 22:05:16 minikube kubelet[3708]: I1104 22:05:16.674690    3708 reconciler.go:319] Volume detached for volume "amster-secrets" (UniqueName: "kubernetes.io/secret/e59fea36-b297-41cd-9ff1-9a244c28ef26-amster-secrets") on node "minikube" DevicePath ""
Nov 04 22:05:16 minikube kubelet[3708]: I1104 22:05:16.674991    3708 reconciler.go:319] Volume detached for volume "default-token-dpmmh" (UniqueName: "kubernetes.io/secret/e59fea36-b297-41cd-9ff1-9a244c28ef26-default-token-dpmmh") on node "minikube" DevicePath ""
Nov 04 22:05:17 minikube kubelet[3708]: W1104 22:05:17.339687    3708 pod_container_deletor.go:79] Container "1e3bdc4072c6a658b4378754062e37f9d17cfdce427d5370586e6844558e475e" not found in pod's containers

@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 4, 2020

Based on some hints here: https://stackoverflow.com/questions/59055244/kube8s-pod-unable-to-connect-to-scheduler

forgeops % kubectl get pods
NAME                           READY   STATUS      RESTARTS   AGE
admin-ui-969ffd794-nbm2n       1/1     Running     0          25m
am-7468ff6c8b-nj8lp            1/1     Running     1          25m
amster-bqdzf                   0/1     Completed   0          25m
ds-cts-0                       1/1     Running     0          25m
ds-idrepo-0                    1/1     Running     0          25m
end-user-ui-6859b5dc47-r66rr   1/1     Running     0          25m
idm-0                          0/1     Pending     0          25m
ldif-importer-jsgxm            0/1     Completed   0          25m
login-ui-96cdb6788-m5d5t       1/1     Running     0          25m

The amster-bqdzf container seems to have been waiting for a while, but has loaded and completed successfully.

I got a few errors in the am-* container though...

kubectl logs am-7468ff6c8b-nj8lp | less
...
{"timestamp":"2020-11-04T22:03:02.633Z","level":"ERROR","thread":"pool-3-thread-1","logger":"org.forgerock.openam.entitlement.indextree.IndexChangeManagerImpl","messag
e":"Error attempting to initiate index change monitor.","context":"default","exception":"org.forgerock.openam.entitlement.indextree.ChangeMonitorException: Failed crea
ting persistent search.\n\tat org.forgerock.openam.entitlement.indextree.IndexChangeMonitorImpl.start(IndexChangeMonitorImpl.java:89)\n\tat org.forgerock.openam.entitl
ement.indextree.IndexChangeManagerImpl$MonitorTask.run(IndexChangeManagerImpl.java:151)\n\tat org.forgerock.openam.entitlement.indextree.IndexChangeManagerImpl$TryAgai
nTask.run(IndexChangeManagerImpl.java:201)\n\tat java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)\n\tat java.base/java.util.concurrent
.FutureTask.run(FutureTask.java:264)\n\tat java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)\n\t
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadP
oolExecutor.java:628)\n\tat java.base/java.lang.Thread.run(Thread.java:834)\nCaused by: org.forgerock.opendj.ldap.ConnectionException: Connect Error: No operational co
nnection factories available\n\tat org.forgerock.opendj.ldap.LdapException.newLdapException(LdapException.java:230)\n\tat org.forgerock.opendj.ldap.LdapException.newLd
apException(LdapException.java:145)\n\tat org.forgerock.opendj.ldap.LdapException.newLdapException(LdapException.java:114)\n\tat org.forgerock.opendj.ldap.LdapExceptio
n.newLdapException(LdapException.java:72)\n\tat org.forgerock.opendj.ldap.LoadBalancer.noOperationalConnectionFactoriesException(LoadBalancer.java:761)\n\tat org.forge
rock.opendj.ldap.LoadBalancer.connect0(LoadBalancer.java:322)\n\tat io.reactivex.internal.operators.single.SingleFromCallable.subscribeActual(SingleFromCallable.java:4
4)\n\tat io.reactivex.Single.subscribe(Single.java:3666)\n\tat io.reactivex.internal.operators.single.SingleMap.subscribeActual(SingleMap.java:34)\n\tat io.reactivex.S
ingle.subscribe(Single.java:3666)\n\tat io.reactivex.internal.operators.single.SingleObserveOn.subscribeActual(SingleObserveOn.java:35)\n\tat io.reactivex.Single.subsc
ribe(Single.java:3666)\n\tat io.reactivex.internal.operators.single.SingleDoFinally.subscribeActual(SingleDoFinally.java:44)\n\tat io.reactivex.Single.subscribe(Single
.java:3666)\n\tat io.reactivex.Single.subscribe(Single.java:3652)\n\tat org.forgerock.opendj.ldap.LdapConnectionFactory.getConnectionAsync(LdapConnectionFactory.java:3
57)\n\tat org.forgerock.opendj.ldap.LdapConnectionFactory.getConnection(LdapConnectionFactory.java:364)\n\tat org.forgerock.openam.service.datastore.LdapDataStoreServi
ce$ManagedConnectionFactory.getConnection(LdapDataStoreService.java:337)\n\tat org.forgerock.openam.entitlement.indextree.IndexChangeMonitorImpl.start(IndexChangeMonit
orImpl.java:78)\n\t... 8 common frames omitted\n"}
...
{"timestamp":"2020-11-04T22:03:05.492Z","level":"ERROR","thread":"CTSWorkerPool-14","mdc":{"transactionId":"3598c364-2f72-4d43-9370-6b6abd759aa4-1"},"logger":"org.forg
erock.openam.sm.datalayer.impl.SimpleTaskExecutor","message":"CTS Async: Task Processor Error: processing task","context":"default","exception":"org.forgerock.am.cts.a
pi.DataLayerException: \nError during partial query\n\tat org.forgerock.openam.cts.impl.LdapAdapter.partialQuery(LdapAdapter.java:325)\n\tat org.forgerock.openam.sm.da
talayer.impl.tasks.PartialQueryTask.performTask(PartialQueryTask.java:61)\n\tat org.forgerock.openam.sm.datalayer.api.AbstractTask.execute(AbstractTask.java:58)\n\tat
org.forgerock.openam.sm.datalayer.impl.SeriesTaskExecutor$TaskDecorator.execute(SeriesTaskExecutor.java:261)\n\tat org.forgerock.openam.sm.datalayer.impl.SimpleTaskExe
cutor.execute(SimpleTaskExecutor.java:55)\n\tat org.forgerock.openam.sm.datalayer.impl.SeriesTaskExecutorThread.run(SeriesTaskExecutorThread.java:85)\n\tat org.forgero
ck.openam.audit.context.AuditRequestContextPropagatingRunnable.run(AuditRequestContextPropagatingRunnable.java:34)\n\tat java.base/java.util.concurrent.Executors$Runna
bleAdapter.call(Executors.java:515)\n\tat java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor.ru
nWorker(ThreadPoolExecutor.java:1128)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)\n\tat java.base/java.lang.Thread.
run(Thread.java:834)\nCaused by: org.forgerock.openam.sm.datalayer.api.DataLayerRuntimeException: \nCould not get entries from connection\n\tat org.forgerock.openam.sm
.datalayer.impl.ldap.LdapQueryBuilder$EntryIterator.next(LdapQueryBuilder.java:321)\n\tat org.forgerock.openam.sm.datalayer.impl.ldap.LdapQueryBuilder$EntryIterator.ne
xt(LdapQueryBuilder.java:287)\n\tat org.forgerock.openam.cts.impl.LdapAdapter.hydrateResults(LdapAdapter.java:334)\n\tat org.forgerock.openam.cts.impl.LdapAdapter.part
ialQuery(LdapAdapter.java:323)\n\t... 11 common frames omitted\nCaused by: org.forgerock.openam.cts.exceptions.QueryFailedException: \nCTS: Failed to complete query:\n
      DN: ou=tokens\n    Conn: AffinityRequestLoadBalancerSocket\n  Filter: (&(&(!(coreTokenTtlDate=*))(coreTokenExpirationDate<=20201104215805.461Z))(objectClass=frCo
reToken))\n\tat org.forgerock.openam.sm.datalayer.impl.ldap.LdapSearchHandler.performSearch(LdapSearchHandler.java:61)\n\tat org.forgerock.openam.sm.datalayer.impl.lda
p.LdapQueryBuilder.getEntries(LdapQueryBuilder.java:168)\n\tat org.forgerock.openam.sm.datalayer.impl.ldap.LdapQueryBuilder$EntryIterator.next(LdapQueryBuilder.java:31
9)\n\t... 14 common frames omitted\nCaused by: org.forgerock.opendj.ldap.AuthenticationException: Invalid Credentials\n\tat org.forgerock.opendj.ldap.LdapException.new
LdapException(LdapException.java:217)\n\tat org.forgerock.opendj.ldap.LdapClientImpl$LdapClientSocketImpl.throwOnFailedResult(LdapClientImpl.java:596)\n\tat org.forger
ock.opendj.ldap.LdapClientImpl$LdapClientSocketImpl.extractResponse(LdapClientImpl.java:589)\n\tat io.reactivex.internal.operators.flowable.FlowableMap$MapSubscriber.o
nNext(FlowableMap.java:63)\n\tat io.reactivex.internal.operators.flowable.FlowableTakeUntilPredicate$InnerSubscriber.onNext(FlowableTakeUntilPredicate.java:57)\n\tat i
o.reactivex.internal.operators.flowable.FlowableTakeWhile$TakeWhileSubscriber.onNext(FlowableTakeWhile.java:79)\n\tat io.reactivex.internal.operators.flowable.Flowable
FlatMap$MergeSubscriber.tryEmit(FlowableFlatMap.java:282)\n\tat io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onNext(FlowableFlatMap.java:66
3)\n\tat io.reactivex.internal.operators.mixed.CompletableAndThenPublisher$AndThenPublisherSubscriber.onNext(CompletableAndThenPublisher.java:71)\n\tat io.reactivex.in
ternal.operators.single.SingleFlatMapPublisher$SingleFlatMapPublisherObserver.onNext(SingleFlatMapPublisher.java:112)\n\tat io.reactivex.internal.operators.flowable.Fl
owableGroupBy$State.drainNormal(FlowableGroupBy.java:634)\n\tat io.reactivex.internal.operators.flowable.FlowableGroupBy$State.drain(FlowableGroupBy.java:558)\n\tat io
.reactivex.internal.operators.flowable.FlowableGroupBy$State.subscribe(FlowableGroupBy.java:529)\n\tat io.reactivex.internal.operators.flowable.FlowableGroupBy$Grouped
Unicast.subscribeActual(FlowableGroupBy.java:462)\n\tat io.reactivex.Flowable.subscribe(Flowable.java:14936)\n\tat io.reactivex.Flowable.subscribe(Flowable.java:14883)
\n\tat io.reactivex.internal.operators.single.SingleFlatMapPublisher$SingleFlatMapPublisherObserver.onSuccess(SingleFlatMapPublisher.java:102)\n\tat io.reactivex.subje
cts.SingleSubject.onSuccess(SingleSubject.java:141)\n\tat org.forgerock.opendj.ldap.LdapClientImpl$LdapClientSocketImpl.setResponseStream(LdapClientImpl.java:381)\n\tat io.reactivex.internal.subscribers.LambdaSubscriber.onNext(LambdaSubscriber.java:65)\n\tat io.reactivex.internal.operators.flowable.FlowableGroupBy$GroupBySubscriber.drainNormal(FlowableGroupBy.java:350)\n\tat io.reactivex.internal.operators.flowable.FlowableGroupBy$GroupBySubscriber.drain(FlowableGroupBy.java:279)\n\tat io.reactivex.internal.operators.flowable.FlowableGroupBy$GroupBySubscriber.onNext(FlowableGroupBy.java:186)\n\tat io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.tryEmit(FlowableFlatMap.java:282)\n\tat io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onNext(FlowableFlatMap.java:663)\n\tat io.reactivex.internal.operators.flowable.FlowableConcatArray$ConcatArraySubscriber.onNext(FlowableConcatArray.java:77)\n\tat io.reactivex.internal.operators.flowable.FlowableOnErrorNext$OnErrorNextSubscriber.onNext(FlowableOnErrorNext.java:80)\n\tat io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onNext(FlowableDoOnEach.java:92)\n\tat org.forgerock.opendj.grizzly.GrizzlyLdapSocketFilter$GrizzlyReader.handleRead(GrizzlyLdapSocketFilter.java:318)\n\tat org.forgerock.opendj.grizzly.GrizzlyLdapSocketFilter.handleRead(GrizzlyLdapSocketFilter.java:138)\n\tat org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)\n\tat org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:284)\n\tat org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:201)\n\tat org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:133)\n\tat org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:112)\n\tat org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)\n\tat org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:539)\n\tat org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:112)\n\tat org.glassfish.grizzly.strategies.SameThreadIOStrategy.executeIoEvent(SameThreadIOStrategy.java:103)\n\tat org.glassfish.grizzly.strategies.AbstractIOStrategy.executeIoEvent(AbstractIOStrategy.java:89)\n\tat org.glassfish.grizzly.nio.SelectorRunner.iterateKeyEvents(SelectorRunner.java:415)\n\tat org.glassfish.grizzly.nio.SelectorRunner.iterateKeys(SelectorRunner.java:384)\n\tat org.glassfish.grizzly.nio.SelectorRunner.doSelect(SelectorRunner.java:348)\n\tat org.glassfish.grizzly.nio.SelectorRunner.run(SelectorRunner.java:279)\n\tat org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:593)\n\tat org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:573)\n\t... 1 common frames omitted\n"}
172.17.0.1 - - [04/Nov/2020:22:03:05 +0000] "GET /am/json/health/ready HTTP/1.1" 200 - 7ms

@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 4, 2020

Following the instructions here for troubleshooting: https://github.com/ForgeRock/forgeops#troubleshooting-tips

kubectl describe pod am-7468ff6c8b-nj8lp gave me:

Events:
  Type     Reason       Age                From               Message
  ----     ------       ----               ----               -------
  Normal   Scheduled    41m                default-scheduler  Successfully assigned default/am-7468ff6c8b-nj8lp to minikube
  Warning  FailedMount  41m                kubelet            MountVolume.SetUp failed for volume "truststore" : failed to sync secret cache: timed out waiting for the condition
  Warning  FailedMount  41m                kubelet            MountVolume.SetUp failed for volume "default-token-dpmmh" : failed to sync secret cache: timed out waiting for the condition
  Warning  FailedMount  41m (x2 over 41m)  kubelet            MountVolume.SetUp failed for volume "amster-key" : failed to sync secret cache: timed out waiting for the condition
  Warning  FailedMount  41m (x2 over 41m)  kubelet            MountVolume.SetUp failed for volume "am-secrets" : [secret "am-passwords" not found, failed to sync secret cache: timed out waiting for the condition]
  Warning  FailedMount  41m                kubelet            MountVolume.SetUp failed for volume "am-secrets" : [secret "am-passwords" not found, secret "am-keystore" not found]
  Warning  FailedMount  40m (x6 over 41m)  kubelet            MountVolume.SetUp failed for volume "amster-key" : secret "amster" not found
  Warning  FailedMount  40m (x5 over 41m)  kubelet            MountVolume.SetUp failed for volume "am-secrets" : secret "am-keystore" not found
  Warning  FailedMount  39m                kubelet            Unable to attach or mount volumes: unmounted volumes=[am-secrets amster-key], unattached volumes=[fbc default-token-dpmmh truststore am-secrets amster-key]: timed out waiting for the condition
  Normal   Pulled       39m                kubelet            Container image "am:fde36ae0e4bce97d06620f8e974fc6db1aaec941b2e1b2b25e5c0c54588c6d74" already present on machine
  Normal   Created      39m                kubelet            Created container fbc-init
  Normal   Started      39m                kubelet            Started container fbc-init
  Normal   Pulled       39m                kubelet            Container image "am:fde36ae0e4bce97d06620f8e974fc6db1aaec941b2e1b2b25e5c0c54588c6d74" already present on machine
  Normal   Created      39m                kubelet            Created container openam
  Normal   Started      39m                kubelet            Started container openam
  Warning  Unhealthy    36m (x4 over 37m)  kubelet            Readiness probe failed: Get "http://172.17.0.11:8080/am/json/health/ready": context deadline exceeded (Client.Timeout exceeded while awaiting headers)

... so it looks like the secrets are definitely not set up correctly.

Cheers,
Nigel

@wstrange
Copy link
Contributor

wstrange commented Nov 4, 2020 via email

@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 5, 2020

Looks like this is due to the secret-agent changes (21 days ago in master)

2dc5fd5

Details of the secrets management:
https://github.com/ForgeRock/forgeops#secrets
https://github.com/ForgeRock/secret-agent/blob/master/README.md

forgeops-secrets-image is the previous method of configuring secrets but contains a list of what secrets are required:
https://github.com/ForgeRock/forgeops/blob/master/docker/forgeops-secrets/forgeops-secrets-image/README.md

@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 5, 2020

minikube stop
minikube delete
git checkout 2020.08.07-ZucchiniRicotta.1
bin/config.sh -v 7.0 init
minikube start
skaffold dev

Then I get this:

forgeops % kubectl get pods
NAME                           READY   STATUS      RESTARTS   AGE
admin-ui-545d6bccf5-t8vzd      1/1     Running     0          9m46s
am-6db56cf7c6-h5k98            1/1     Running     2          9m46s
amster-5fv7b                   1/1     Running     0          43s
amster-rghpz                   0/1     Error       0          9m45s
ds-cts-0                       1/1     Running     0          9m45s
ds-idrepo-0                    1/1     Running     0          9m45s
end-user-ui-85c655599d-tn9p6   1/1     Running     0          9m46s
forgeops-secrets-6pqqx         0/1     Completed   0          9m44s
idm-0                          1/1     Running     1          9m45s
ldif-importer-lz7zc            0/1     Completed   0          9m44s
login-ui-8477c6b75c-trqsp      1/1     Running     0          9m46s

After waiting a few minutes, the Admin page still doesn't appear (it times out a few times).
https://default.iam.example.com/am

Here's the key errors I can see:

kubectl logs am-6db56cf7c6-h5k98
...
Starting up OpenAM at Nov 5, 2020, 12:41:01 AM
{"timestamp":"2020-11-05T00:41:09.648Z","level":"WARN","thread":"main","mdc":{"transactionId":"418f6818-d461-47af-97ad-c2cd3facd3ea-1"},"logger":"org.forgerock.opendj.ldap.LoadBalancer","message":"Connection factory 'CachedConnectionPool(size=0[in:0 + out:0 + pending:0], maxSize=10, blocked=0, ldapClient=org.forgerock.opendj.ldap.LdapClientImpl@e6500f5)' is no longer operational: Connect Error: UNUSED.IN.FBC","context":"default"}
{"timestamp":"2020-11-05T00:41:10.069Z","level":"ERROR","thread":"Thread-5","logger":"org.forgerock.openam.services.push.PushNotificationServiceConfigHelperFactory","message":"Unable to retrieve instance of the ServiceConfig for realm /.","context":"default"}
{"timestamp":"2020-11-05T00:41:10.116Z","level":"WARN","thread":"Thread-5","logger":"org.forgerock.openam.services.push.PushNotificationService","message":"Unable to read config for PushNotificationConfig in realm /","context":"default"}
...

Cheers,
Nigel

@wstrange
Copy link
Contributor

wstrange commented Nov 5, 2020 via email

@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 5, 2020

I got the Kubernetes dashboard running, which makes life a bit easier to see what is going on: https://github.com/kubernetes/dashboard

kubectl exec am-7c4665cc6d-x7ldz -- cat /usr/local/tomcat/logs/localhost.2020-11-05.log | less got me...

05-Nov-2020 02:23:32.933 SEVERE [http-nio-8080-exec-4] org.apache.catalina.core.ApplicationContext.log Servlet.init() for servlet [OpenAM] threw exception
        org.forgerock.api.DuplicateDescriptionException: Trying to redefine version 0.0 for path
                at org.forgerock.api.models.Paths$Builder.merge(Paths.java:155)
                at org.forgerock.api.CrestApiProducer.merge(CrestApiProducer.java:118)
                at org.forgerock.api.CrestApiProducer.merge(CrestApiProducer.java:38)
                at org.forgerock.services.routing.AbstractRouter.buildApi(AbstractRouter.java:361)
                at org.forgerock.services.routing.AbstractRouter.notifyDescriptorChange(AbstractRouter.java:334)
                at org.forgerock.services.routing.AbstractRouter.api(AbstractRouter.java:282)
                at org.forgerock.openam.core.rest.sms.tree.SmsRouteTree.api(SmsRouteTree.java:457)
                at org.forgerock.openam.core.rest.sms.tree.SmsRouteTree.api(SmsRouteTree.java:103)
                at org.forgerock.services.routing.AbstractRouter.buildApi(AbstractRouter.java:353)
                at org.forgerock.services.routing.AbstractRouter.notifyDescriptorChange(AbstractRouter.java:334)
                at org.forgerock.services.routing.AbstractRouter.api(AbstractRouter.java:282)
                at org.forgerock.openam.core.rest.sms.tree.SmsRouteTree.api(SmsRouteTree.java:457)
...

Not sure what this means but there's some suggestions in this article:
https://backstage.forgerock.com/knowledge/kb/article/a82899089

For the idm-0 pod... kubectl exec idm-0 -- ls -la /opt/openidm/logs shows there is no logs yet. kubectl exec idm-0 -- /opt/openidm/startup.sh gives:

Executing /opt/openidm/startup.sh...
/opt/jdk/bin/java
Using OPENIDM_HOME:   /opt/openidm
Using PROJECT_HOME:   /opt/openidm
Using OPENIDM_OPTS:   -Xmx2048m -Xms2048m
Using LOGGING_CONFIG: -Djava.util.logging.config.file=/opt/openidm/conf/logging.properties
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.apache.felix.framework.ext.ClassPathExtenderFactory$DefaultClassLoaderExtender (file:/opt/openidm/bin/felix.jar) to method java.net.URLClassLoader.addURL(java.net.URL)
WARNING: Please consider reporting this to the maintainers of org.apache.felix.framework.ext.ClassPathExtenderFactory$DefaultClassLoaderExtender
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
ShellTUI: No standard input...exiting.
->

[38] Nov 05, 2020 3:19:01.944 AM org.forgerock.openidm.config.enhanced.JSONEnhancedConfig getConfiguration
SEVERE: Missing config properties: [openidm.node.id] for config: org.forgerock.openidm.cluster
org.forgerock.config.resolvers.SubstitutionException: Can't substitute source value: unresolved variables ([openidm.node.id]) or cycles detected ([])
	at org.forgerock.config.resolvers.SubstitutionService.substitute(SubstitutionService.java:121)
	at org.forgerock.config.util.JsonValuePropertyEvaluator.evaluateProperties(JsonValuePropertyEvaluator.java:409)
	at org.forgerock.config.util.JsonValuePropertyEvaluator.lambda$evaluate$12(JsonValuePropertyEvaluator.java:390)
	at org.forgerock.json.JsonValue.as(JsonValue.java:530)
	at org.forgerock.json.JsonValueTraverseFunction.traverse(JsonValueTraverseFunction.java:51)
...
SEVERE: Bundle: org.forgerock.openidm.infoservice [116] FrameworkEvent ERROR
org.apache.felix.log.LogException: org.osgi.framework.ServiceException: Service factory returned null. (Component: org.forgerock.openidm.cluster (136))
	at org.apache.felix.framework.ServiceRegistrationImpl.getFactoryUnchecked(ServiceRegistrationImpl.java:381)
	at org.apache.felix.framework.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:248)
	at org.apache.felix.framework.ServiceRegistry.getService(ServiceRegistry.java:350)
	at org.apache.felix.framework.Felix.getService(Felix.java:3954)
	at org.apache.felix.framework.BundleContextImpl.getService(BundleContextImpl.java:450)
	at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:86)
	at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47)
	at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:664)
...
org.apache.felix.log.LogException: org.forgerock.openidm.config.enhanced.InvalidException: Missing config properties: [openidm.node.id] for config: org.forgerock.openidm.cluster
	at org.forgerock.openidm.config.enhanced.JSONEnhancedConfig.getConfiguration(JSONEnhancedConfig.java:107)
	at org.forgerock.openidm.config.enhanced.JSONEnhancedConfig.getConfiguration(JSONEnhancedConfig.java:92)
	at org.forgerock.openidm.config.enhanced.JSONEnhancedConfig.getConfigurationAsJson(JSONEnhancedConfig.java:86)
	at org.forgerock.openidm.cluster.ClusterManager.activate(ClusterManager.java:194)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
...

/opt/openidm/shutdown.sh doesn't work because /bin/ps is missing.

Cheers,
Nigel

@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 5, 2020

Seems to be an issue with the nginx-ingress routing in a standalone (non-EKS/AKS/GCS) configuration with minikube and either Docker or hyperkit on Mac OS...

kustomize/base/7.0/ingress/ingress.yaml contains lots of references to nginx.ingress.kubernetes.io but I can't see the namespace configuration:
https://kubernetes.github.io/ingress-nginx/user-guide/exposing-tcp-udp-services/

There are also ingress errors such as endpoints "default-http-backend" not found but that may not be an critical error: nginxinc/kubernetes-ingress#966

forgeops % kubectl describe ing
Warning: extensions/v1beta1 Ingress is deprecated in v1.14+, unavailable in v1.22+; use networking.k8s.io/v1 Ingress
Name:             end-user-ui
Namespace:        default
Address:
Default backend:  default-http-backend:80 (<error: endpoints "default-http-backend" not found>)
TLS:
  sslcert terminates default.iam.example.com
Rules:
  Host                     Path  Backends
  ----                     ----  --------
  default.iam.example.com
                           /enduser/?(.*)   end-user-ui:8080   172.17.0.5:8080)
Annotations:               cert-manager.io/cluster-issuer: default-issuer
                           nginx.ingress.kubernetes.io/configuration-snippet: rewrite ^(/enduser)$ $1/ redirect;
                           nginx.ingress.kubernetes.io/rewrite-target: /$1
Events:                    <none>


Name:             forgerock
Namespace:        default
Address:
Default backend:  default-http-backend:80 (<error: endpoints "default-http-backend" not found>)
TLS:
  sslcert terminates default.iam.example.com
Rules:
  Host                     Path  Backends
  ----                     ----  --------
  default.iam.example.com
                           /am        am:80    172.17.0.4:8080)
                           /openidm   idm:80   172.17.0.12:8080)
                           /upload    idm:80   172.17.0.12:8080)
                           /export    idm:80   172.17.0.12:8080)
                           /admin     idm:80   172.17.0.12:8080)
                           /openicf   idm:80   172.17.0.12:8080)

@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 5, 2020

Looks like https://github.com/csovant/forgeops/tree/bf28af969cbea80b59feb020b1b274d4f3da0646/helm#tls was the last commit to support Helm. csovant@471e93e removes the helm/ folder.

There was major changes in v7.0 for PR #540, documented here:
https://docs.google.com/document/d/1s4UVJ2RcuRIO3GEXm9FQ5aESsJNrh2bWIT_rcsUBq3w/edit

Is minikube still a supported configuration?

Cheers,
Nigel

@wstrange
Copy link
Contributor

wstrange commented Nov 5, 2020

Nigel
This is defintely supported on minikube, and I just tested on the latest 1.19.2. release of Kubernetes.

I think some of your issues may stem from reading documentation that does not match the branch/tag that you are trying to deploy.

If you'd like to try the latest release, we have a "quickstart.sh" script that you can deploy on minikube.

curl -LO https://github.com/ForgeRock/forgeops/releases/download/2020.10.28-AlSugoDiNoci/quickstart.sh
chmod +x quickstart.sh
./quickstart.sh -n mynamespace     #installs our platform in the provided namespace
#./quickstart.sh -u -n mynamespace #to uninstall the CDQ
#./quickstart.sh -h                #for more help

Caveat: There is a race condition that we sometimes see when creating the secrets. I had to kill the ds-cts-0 and ds-idrepo-0 pods to get them to correctly mount the secrets. We are working on a fix for that issue.

Also - if you do want to view matching docs for release, we are now bunlding those up as a zip file as part of the release. This is a good way to ensure the doc you are reading matches the release.

@dgoldssfo
Copy link
Contributor

dgoldssfo commented Nov 5, 2020

Nigel, to elaborate on what Warren said, consider using one of these releases:

https://github.com/ForgeRock/forgeops/releases/tag/2020.10.28-AlSugoDiNoci - an unsupported interim release just issued last week. There's a zip file containing the docs for the release at https://github.com/ForgeRock/forgeops/releases/download/2020.10.28-AlSugoDiNoci/forgeops-docs.zip.

https://github.com/ForgeRock/forgeops/releases/tag/2020.08.07-ZucchiniRicotta.1 - our official, supported release. Docs at https://backstage.forgerock.com/docs/forgeops/7/index-forgeops.html

If you want to use the master branch, feel free to do so, but docs are not available for it. However, since the interim release is so new, almost everything in the doc for the interim release currently applies to the master branch.

Some of our readmes have gotten a little stale; it might be a better approach to go with the published doc.

Hope this helps get you up and running.

@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 5, 2020

Thanks @wstrange and @dgoldssfo, I think I missed one specific configuration required for Mac OS:

minikube start --vm=true
minikube addons enable ingress

... which was in your DevOps guides (PDF, v6.5, and probably v7 as well).

I'm still having trouble with some secrets but I feel confident I should be able to get it sorted today.

Thanks for your help!

Nigel

@dgoldssfo
Copy link
Contributor

Could you post your minikube start command here?

Couple of gotcha - (1) the Docker driver on macOS does not support the Minikube ingress plugin, so you have to use a hypervisor (we suggest VBox but others will work, too); (2) we recommend --kubernetes-version=1.17.4; just haven't tested on later versions, and 1.17.4 is known to work.

@maxres-fr
Copy link
Contributor

Also I'd suggest you make sure you delete EVERYTHING. e.g. ./bin/clean.sh

Also you shouldn't have forgeops-secrets deployed at all. So make sure you're using the release git tag.

@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 5, 2020

Ok looking much better now... Switched to 2020.08.07-ZucchiniRicotta.1...

git checkout 2020.08.07-ZucchiniRicotta.1

Ensure all the secrets are cleaned up and re-created by the job.batch/forgeops-secrets job in the forgeops-secrets-image docker container during the initial build phase:

kubectl delete secrets --all
minikube stop
minikube delete
skaffold delete
# optional: rm -Rf ~/.minikube/cache ~/.docker/cache etc etc
minikube start --vm=true
minikube addons enable ingress 
bin/config.sh init
skaffold dev
... (wait until "[openam] ... GET /am/isAlive.jsp HTTP/1.1 200" status checks appears in logs)

Then in a separate window/console:

minikube get pods        => to check status
minikube addons enable ingress     => make sure the add-in is enabled
minikube ip                    => to update /etc/hosts, as the IP address can move around a bit sometimes

Then I visited https://default.iam.example.com/am/ and the login page appears after I accept the SSL/TLS certificate!

Thanks for all your tips and especially the gotchas.

I'll see if I can get the newer (unofficial) release running too shortly... 2020.10.28-AlSugoDiNoci ... with the new secret agent (https://github.com/ForgeRock/secret-agent).

Best regards,
Nigel

@wtfiwtz wtfiwtz closed this as completed Nov 5, 2020
@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 6, 2020

I think the minikube default of 4Gb of RAM is not enough, so I had to do this when starting Kubernetes, prior to skaffold dev - due to some pods being in the pending state:

minikube start --vm=true --memory 8196

It looks like I can get into the Access Manager successfully, and I'll work on getting the Identity Gateway working now too - that was what I needed to test out (reverse proxy).

Cheers,
Nigel

@maxres-fr
Copy link
Contributor

maxres-fr commented Nov 6, 2020 via email

@wtfiwtz
Copy link
Author

wtfiwtz commented Nov 6, 2020

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

No branches or pull requests

4 participants