search

retroryan / istio-workshop

Istio Workshop
Apache License 2.0
416 stars 257 forks source link

guestbook-ui in CrashLoopBackOff state (Cannot get Jedis connection) #40

Closed gamina closed 5 years ago

gamina commented 6 years ago

Hi,

Thank you for a comprehensible and insightful workshop.

Everything has been smooth, until I got blocked on exercise 6. Specifically, during the Deploy Guestbook Services step.

I dutifully waited until all of the MySQL, Redis, and guestbook microservice Deployments were successful, and then attempted to deploy the guestbook-ui Service:

$ kubectl apply -f guestbook/guestbook-ui-deployment.yaml -f guestbook/guestbook-ui-service.yaml

As I wasn't able to connect to the advertised External IP, I saw its state with:

$ kubectl get pods
NAME                                     READY     STATUS             RESTARTS   AGE
guestbook-service-76b8bffc64-vn6sk       2/2       Running            0          37m
guestbook-ui-7bdd6677dd-8dx7b            1/2       CrashLoopBackOff   11         37m
helloworld-service-v1-fd94c8576-s54x2    2/2       Running            0          38m
helloworld-service-v2-744696b8cb-2p959   2/2       Running            0          38m
mysql-7b877b4cf4-rz7gv                   2/2       Running            0          38m
redis-848b98bc8b-hztz5                   2/2       Running            0          38m

Inspecting the logs from the container:

$ kubectl logs --previous guestbook-ui-7bdd6677dd-76ljf -c guestbook-ui

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v1.5.3.RELEASE)

2018-06-03 04:14:44.004  INFO 1 --- [           main] c.e.guestbook.HelloworldUiApplication    : Starting HelloworldUiApplication v0.0.1-SNAPSHOT on guestbook-ui-7bdd6677dd-76ljf with PID 1 (/app/app.jar started by root in /)
2018-06-03 04:14:44.007  INFO 1 --- [           main] c.e.guestbook.HelloworldUiApplication    : No active profile set, falling back to default profiles: default
2018-06-03 04:14:44.477  INFO 1 --- [           main] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@3d36e4cd: startup date [Sun Jun 03 04:14:44 GMT 2018]; root of context hierarchy
2018-06-03 04:14:45.989  INFO 1 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!
2018-06-03 04:14:47.387  INFO 1 --- [           main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat initialized with port(s): 8080 (http)
2018-06-03 04:14:47.420  INFO 1 --- [           main] o.apache.catalina.core.StandardService   : Starting service Tomcat
2018-06-03 04:14:47.422  INFO 1 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet Engine: Apache Tomcat/8.5.14
2018-06-03 04:14:47.543  INFO 1 --- [ost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2018-06-03 04:14:47.544  INFO 1 --- [ost-startStop-1] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 3077 ms
2018-06-03 04:14:48.212  INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'metricsFilter' to: [/*]
2018-06-03 04:14:48.213  INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'characterEncodingFilter' to: [/*]
2018-06-03 04:14:48.214  INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'springSessionRepositoryFilter' to: [/*]
2018-06-03 04:14:48.214  INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]
2018-06-03 04:14:48.214  INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'httpPutFormContentFilter' to: [/*]
2018-06-03 04:14:48.215  INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'requestContextFilter' to: [/*]
2018-06-03 04:14:48.215  INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'webRequestLoggingFilter' to: [/*]
2018-06-03 04:14:48.215  INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'delegatingFilterProxy' to urls: [/*]
2018-06-03 04:14:48.216  INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'headerPropagationRequestFilter' to: [/*]
2018-06-03 04:14:48.216  INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'applicationContextIdFilter' to: [/*]
2018-06-03 04:14:48.217  INFO 1 --- [ost-startStop-1] o.s.b.w.servlet.ServletRegistrationBean  : Mapping servlet: 'dispatcherServlet' to [/]
2018-06-03 04:14:48.716  WARN 1 --- [           main] ationConfigEmbeddedWebApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'enableRedisKeyspaceNotificationsInitializer' defined in class path resource [org/springframework/session/data/redis/config/annotation/web/http/RedisHttpSessionConfiguration.class]: Invocation of init method failed; nested exception is org.springframework.data.redis.RedisConnectionFailureException: Cannot get Jedis connection; nested exception is redis.clients.jedis.exceptions.JedisConnectionException: Could not get a resource from the pool
2018-06-03 04:14:48.731  INFO 1 --- [           main] o.apache.catalina.core.StandardService   : Stopping service Tomcat
2018-06-03 04:14:48.772  INFO 1 --- [           main] utoConfigurationReportLoggingInitializer : 

Error starting ApplicationContext. To display the auto-configuration report re-run your application with 'debug' enabled.
2018-06-03 04:14:49.080 ERROR 1 --- [           main] o.s.boot.SpringApplication               : Application startup failed

org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'enableRedisKeyspaceNotificationsInitializer' defined in class path resource [org/springframework/session/data/redis/config/annotation/web/http/RedisHttpSessionConfiguration.class]: Invocation of init method failed; nested exception is org.springframework.data.redis.RedisConnectionFailureException: Cannot get Jedis connection; nested exception is redis.clients.jedis.exceptions.JedisConnectionException: Could not get a resource from the pool
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1628) ~[spring-beans-4.3.8.RELEASE.jar:4.3.8.RELEASE]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:555) ~[spring-beans-4.3.8.RELEASE.jar:4.3.8.RELEASE]
[... TRUNCATED ...]

State of the guestbook-ui Pod:

$ kubectl describe pod guestbook-ui
Name:           guestbook-ui-7bdd6677dd-76ljf
Namespace:      default
Node:           gke-guestbook-default-pool-5e18ca9f-dsw3/10.128.0.2
Start Time:     Sat, 02 Jun 2018 21:13:34 -0700
Labels:         app=guestbook-ui
                layer=frontend
                pod-template-hash=3688223388
                serving=true
                version=latest
                visualize=true
Annotations:    kubernetes.io/limit-ranger=LimitRanger plugin set: cpu request for container guestbook-ui
                sidecar.istio.io/status={"version":"c21ef16976597100ea323655a5b90a1e770d70abee7fe3a5fb1a40cd29eb87af","initContainers":["istio-init"],"containers":["istio-proxy"],"volumes":["istio-envoy","istio-certs...
                visualizer/uses=helloworld-service,guestbook-service,redis
Status:         Running
IP:             10.28.1.14
Controlled By:  ReplicaSet/guestbook-ui-7bdd6677dd
Init Containers:
  istio-init:
    Container ID:  docker://9bd2ed70d4e9323e590b9d12dd7d464ef2c7210d3180395b7eb42f52c334460d
    Image:         docker.io/istio/proxy_init:0.7.1
    Image ID:      docker-pullable://istio/proxy_init@sha256:b86f246170274ef869623eff65dc82b3de8fed39174436bc7f8e0892e239ffd7
    Port:          <none>
    Args:
      -p
      15001
      -u
      1337
    State:          Terminated
      Reason:       Completed
      Exit Code:    0
      Started:      Sat, 02 Jun 2018 21:13:35 -0700
      Finished:     Sat, 02 Jun 2018 21:13:35 -0700
    Ready:          True
    Restart Count:  0
    Environment:    <none>
    Mounts:         <none>
Containers:
  guestbook-ui:
    Container ID:   docker://5d9f87fd91146f51e78640125a2c9f70c654b1ede8aeca04d3a09916a7b8bc09
    Image:          retroryan/guestbook-ui-istio:java-1.0
    Image ID:       docker-pullable://retroryan/guestbook-ui-istio@sha256:ea956bd574d06d2191259a4864e6f97bceb2851c11bab1369c090702f8d2994c
    Port:           8080/TCP
    State:          Waiting
      Reason:       CrashLoopBackOff
    Last State:     Terminated
      Reason:       Error
      Exit Code:    1
      Started:      Sat, 02 Jun 2018 21:15:32 -0700
      Finished:     Sat, 02 Jun 2018 21:15:38 -0700
    Ready:          False
    Restart Count:  4
    Requests:
      cpu:        100m
    Environment:  <none>
    Mounts:
      /var/run/secrets/kubernetes.io/serviceaccount from default-token-5shpn (ro)
  istio-proxy:
    Container ID:  docker://a4a8795081608e03db608cf402b2d25cac2897545c2a9b7f3aedfc0c7c94be13
    Image:         docker.io/istio/proxy:0.7.1
    Image ID:      docker-pullable://istio/proxy@sha256:07e4d40d46944c8bf06d7f35637339d217d82908e53a9b73e37888d4452c3a88
    Port:          <none>
    Args:
      proxy
      sidecar
      --configPath
      /etc/istio/proxy
      --binaryPath
      /usr/local/bin/envoy
      --serviceCluster
      guestbook-ui
      --drainDuration
      45s
      --parentShutdownDuration
      1m0s
      --discoveryAddress
      istio-pilot.istio-system:8080
      --discoveryRefreshDelay
      1s
      --zipkinAddress
      zipkin.istio-system:9411
      --connectTimeout
      10s
      --statsdUdpAddress
      istio-mixer.istio-system:9125
      --proxyAdminPort
      15000
      --controlPlaneAuthPolicy
      NONE
    State:          Running
      Started:      Sat, 02 Jun 2018 21:13:37 -0700
    Ready:          True
    Restart Count:  0
    Environment:
      POD_NAME:       guestbook-ui-7bdd6677dd-76ljf (v1:metadata.name)
      POD_NAMESPACE:  default (v1:metadata.namespace)
      INSTANCE_IP:     (v1:status.podIP)
    Mounts:
      /etc/certs/ from istio-certs (ro)
      /etc/istio/proxy from istio-envoy (rw)
Conditions:
  Type           Status
  Initialized    True 
  Ready          False 
  PodScheduled   True 
Volumes:
  default-token-5shpn:
    Type:        Secret (a volume populated by a Secret)
    SecretName:  default-token-5shpn
    Optional:    false
  istio-envoy:
    Type:    EmptyDir (a temporary directory that shares a pod's lifetime)
    Medium:  Memory
  istio-certs:
    Type:        Secret (a volume populated by a Secret)
    SecretName:  istio.default
    Optional:    true
QoS Class:       Burstable
Node-Selectors:  <none>
Tolerations:     node.kubernetes.io/not-ready:NoExecute for 300s
                 node.kubernetes.io/unreachable:NoExecute for 300s
Events:
  Type     Reason                 Age              From                                               Message
  ----     ------                 ----             ----                                               -------
  Normal   Scheduled              2m               default-scheduler                                  Successfully assigned guestbook-ui-7bdd6677dd-76ljf to gke-guestbook-default-pool-5e18ca9f-dsw3
  Normal   SuccessfulMountVolume  2m               kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  MountVolume.SetUp succeeded for volume "default-token-5shpn"
  Normal   SuccessfulMountVolume  2m               kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  MountVolume.SetUp succeeded for volume "istio-certs"
  Normal   SuccessfulMountVolume  2m               kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  MountVolume.SetUp succeeded for volume "istio-envoy"
  Normal   Pulled                 2m               kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  Container image "docker.io/istio/proxy_init:0.7.1" already present on machine
  Normal   Created                2m               kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  Created container
  Normal   Started                2m               kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  Started container
  Normal   Started                2m               kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  Started container
  Normal   Pulled                 2m               kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  Container image "docker.io/istio/proxy:0.7.1" already present on machine
  Normal   Created                2m               kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  Created container
  Normal   Created                2m (x3 over 2m)  kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  Created container
  Normal   Started                2m (x3 over 2m)  kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  Started container
  Normal   Pulled                 2m (x3 over 2m)  kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  Successfully pulled image "retroryan/guestbook-ui-istio:java-1.0"
  Warning  BackOff                1m (x3 over 2m)  kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  Back-off restarting failed container
  Normal   Pulling                1m (x4 over 2m)  kubelet, gke-guestbook-default-pool-5e18ca9f-dsw3  pulling image "retroryan/guestbook-ui-istio:java-1.0"

I deleted all Services/Deployments, started over, and got the same issue again.

Redis seems fine:

 $ kubectl exec -it redis-848b98bc8b-hztz5 redis-cli
Defaulting container name to redis.
Use 'kubectl describe pod/redis-848b98bc8b-hztz5 -n default' to see all of the containers in this pod.
127.0.0.1:6379>

Environment details:

 $ kubectl version -o yaml
clientVersion:
  buildDate: 2018-04-19T00:05:56Z
  compiler: gc
  gitCommit: dd5e1a2978fd0b97d9b78e1564398aeea7e7fe92
  gitTreeState: clean
  gitVersion: v1.9.7
  goVersion: go1.9.3
  major: "1"
  minor: "9"
  platform: linux/amd64
serverVersion:
  buildDate: 2018-04-07T22:06:59Z
  compiler: gc
  gitCommit: cb151369f60073317da686a6ce7de36abe2bda8d
  gitTreeState: clean
  gitVersion: v1.9.6-gke.1
  goVersion: go1.9.3b4
  major: "1"
  minor: 9+
  platform: linux/amd64

It seems it is encountering issues connecting to Redis? However Redis seems to be running properly?

Do you have any advice?

Thank you

retroryan commented 5 years ago

This is fixed with Istio 1.0.2 . Thank you for reporting the issue!