Bug 1549029

Created attachment 1400799 [details]
pod.yaml

Created attachment 1400800 [details]
config.json

I see that -i is passed to the Readiness sh command. Is that required? Can we try w/o the -i? Else we would have to ensure that the exec code sets terminal to true. 

Readiness:  exec [/bin/sh -i -c MYSQL_PWD='YlOSByUhBxOYYK70' mysql -h 127.0.0.1 -u cakephp -D default -e 'SELECT 1'] delay=5s timeout=1s period=10s #success=1 #failure=3

(In reply to Mrunal Patel from comment #3)
> I see that -i is passed to the Readiness sh command. Is that required? Can
> we try w/o the -i? Else we would have to ensure that the exec code sets
> terminal to true. 
> 
> Readiness:  exec [/bin/sh -i -c MYSQL_PWD='YlOSByUhBxOYYK70' mysql -h
> 127.0.0.1 -u cakephp -D default -e 'SELECT 1'] delay=5s timeout=1s
> period=10s #success=1 #failure=3

1) The '-i' is added in our ocp provided template file (https://github.com/openshift/openshift-ansible/blob/master/roles/openshift_examples/files/examples/v3.9/quickstart-templates/cakephp-mysql.json#L393), if you think this need remove, we can let developer experience team update it.

2) I have tried remove it, the readiness still fail. 
[root@ip-172-18-9-9 ~]# oc describe po mysql-2-sczl5
Name:           mysql-2-sczl5
Namespace:      dma
Node:           ip-172-18-9-9.ec2.internal/172.18.9.9
Start Time:     Tue, 27 Feb 2018 02:57:05 -0500
Labels:         deployment=mysql-2
                deploymentconfig=mysql
                name=mysql
Annotations:    openshift.io/deployment-config.latest-version=2
                openshift.io/deployment-config.name=mysql
                openshift.io/deployment.name=mysql-2
                openshift.io/scc=restricted
Status:         Running
IP:             10.129.0.33
Controlled By:  ReplicationController/mysql-2
Containers:
  mysql:
    Container ID:   cri-o://ce8145f7adf89c7bc879957c9854ba312eb7ac9fdace45628003f92fd182b4eb
    Image:          registry.access.redhat.com/rhscl/mysql-57-rhel7@sha256:7638d886370ca1eb3cefcfecf483f8dc4dc1ca05559dd521d1585ae7c4ed668e
    Image ID:       registry.access.redhat.com/rhscl/mysql-57-rhel7@sha256:7638d886370ca1eb3cefcfecf483f8dc4dc1ca05559dd521d1585ae7c4ed668e
    Port:           3306/TCP
    State:          Running
      Started:      Tue, 27 Feb 2018 02:57:12 -0500
    Ready:          False
    Restart Count:  0
    Limits:
      memory:  512Mi
    Requests:
      memory:   512Mi
    Liveness:   tcp-socket :3306 delay=30s timeout=1s period=10s #success=1 #failure=3
    Readiness:  exec [/bin/sh -c MYSQL_PWD='4SPCQRPYjynTYK4S' mysql -h 127.0.0.1 -u cakephp -D default -e 'SELECT 1'] delay=5s timeout=1s period=10s #success=1 #failure=3
    Environment:
      MYSQL_USER:      <set to the key 'database-user' in secret 'cakephp-mysql-example'>      Optional: false
      MYSQL_PASSWORD:  <set to the key 'database-password' in secret 'cakephp-mysql-example'>  Optional: false
      MYSQL_DATABASE:  default
    Mounts:
      /var/lib/mysql/data from data (rw)
      /var/run/secrets/kubernetes.io/serviceaccount from default-token-jhqng (ro)
Conditions:
  Type           Status
  Initialized    True 
  Ready          False 
  PodScheduled   True 
Volumes:
  data:
    Type:    EmptyDir (a temporary directory that shares a pod's lifetime)
    Medium:  
  default-token-jhqng:
    Type:        Secret (a volume populated by a Secret)
    SecretName:  default-token-jhqng
    Optional:    false
QoS Class:       Burstable
Node-Selectors:  <none>
Tolerations:     node.kubernetes.io/memory-pressure:NoSchedule
Events:
  Type     Reason                 Age               From                                 Message
  ----     ------                 ----              ----                                 -------
  Normal   Scheduled              1m                default-scheduler                    Successfully assigned mysql-2-sczl5 to ip-172-18-9-9.ec2.internal
  Normal   SuccessfulMountVolume  1m                kubelet, ip-172-18-9-9.ec2.internal  MountVolume.SetUp succeeded for volume "data"
  Normal   SuccessfulMountVolume  1m                kubelet, ip-172-18-9-9.ec2.internal  MountVolume.SetUp succeeded for volume "default-token-jhqng"
  Normal   Pulled                 1m                kubelet, ip-172-18-9-9.ec2.internal  Container image "registry.access.redhat.com/rhscl/mysql-57-rhel7@sha256:7638d886370ca1eb3cefcfecf483f8dc4dc1ca05559dd521d1585ae7c4ed668e" already present on machine
  Normal   Created                1m                kubelet, ip-172-18-9-9.ec2.internal  Created container
  Normal   Started                1m                kubelet, ip-172-18-9-9.ec2.internal  Started container
  Warning  Unhealthy              7s (x10 over 1m)  kubelet, ip-172-18-9-9.ec2.internal  Readiness probe failed: /bin/sh: mysql: command not found

(In reply to Mrunal Patel from comment #3)
> I see that -i is passed to the Readiness sh command. Is that required? Can
> we try w/o the -i? Else we would have to ensure that the exec code sets
> terminal to true. 
> 
> Readiness:  exec [/bin/sh -i -c MYSQL_PWD='YlOSByUhBxOYYK70' mysql -h
> 127.0.0.1 -u cakephp -D default -e 'SELECT 1'] delay=5s timeout=1s
> period=10s #success=1 #failure=3

How ensure that the exec code sets terminal to true?

That error happens because "/bin/sh" w/o "-i" is not reading from $PATH at all actually:

       When  bash  is  started non-interactively, to run a shell script, for example, it looks for the variable BASH_ENV in
       the environment, expands its value if it appears there, and uses the expanded value as the name of a  file  to  read
       and execute.  Bash behaves as if the following command were executed:
              if [ -n "$BASH_ENV" ]; then . "$BASH_ENV"; fi
       but the value of the PATH variable is not used to search for the filename.


docker behaves the same, that's why we have "-i -c" in /bin/sh :(

docker run busybox /bin/sh ls -la
/bin/sh: can't open 'ls': No such file or directory

Can we give full path to mysql binary in the command?

Should be fixed by https://github.com/kubernetes-incubator/cri-o/pull/1386

The pr inc comment 8 is merged in 1.9.8; but I have test this in ocp, still same error.

openshift v3.9.2
kubernetes v1.9.1+a0ce1bc657
etcd 3.2.16
crio version 1.9.8

[root@ip-172-18-0-131 ~]# openshift version
openshift v3.9.2
kubernetes v1.9.1+a0ce1bc657
etcd 3.2.16
[root@ip-172-18-0-131 ~]# oc describe po mysql-1-sjcdh -n dma
Name:           mysql-1-sjcdh
Namespace:      dma
Node:           ip-172-18-0-131.ec2.internal/172.18.0.131
Start Time:     Mon, 05 Mar 2018 22:02:32 -0500
Labels:         deployment=mysql-1
                deploymentconfig=mysql
                name=mysql
Annotations:    openshift.io/deployment-config.latest-version=1
                openshift.io/deployment-config.name=mysql
                openshift.io/deployment.name=mysql-1
                openshift.io/scc=restricted
Status:         Running
IP:             10.129.0.12
Controlled By:  ReplicationController/mysql-1
Containers:
  mysql:
    Container ID:   cri-o://19fa75129b28ef3642bce38b097bb6bf3a63309651077b19c596aaa08a8ffe21
    Image:          registry.access.redhat.com/rhscl/mysql-57-rhel7@sha256:7638d886370ca1eb3cefcfecf483f8dc4dc1ca05559dd521d1585ae7c4ed668e
    Image ID:       registry.access.redhat.com/rhscl/mysql-57-rhel7@sha256:7638d886370ca1eb3cefcfecf483f8dc4dc1ca05559dd521d1585ae7c4ed668e
    Port:           3306/TCP
    State:          Running
      Started:      Mon, 05 Mar 2018 22:03:47 -0500
    Ready:          True
    Restart Count:  0
    Limits:
      memory:  512Mi
    Requests:
      memory:   512Mi
    Liveness:   tcp-socket :3306 delay=30s timeout=1s period=10s #success=1 #failure=3
    Readiness:  exec [/bin/sh -i -c MYSQL_PWD='QynympECNaaI0I0h' mysql -h 127.0.0.1 -u cakephp -D default -e 'SELECT 1'] delay=5s timeout=1s period=10s #success=1 #failure=3
    Environment:
      MYSQL_USER:      <set to the key 'database-user' in secret 'cakephp-mysql-example'>      Optional: false
      MYSQL_PASSWORD:  <set to the key 'database-password' in secret 'cakephp-mysql-example'>  Optional: false
      MYSQL_DATABASE:  default
    Mounts:
      /var/lib/mysql/data from data (rw)
      /var/run/secrets/kubernetes.io/serviceaccount from default-token-bcxmz (ro)
Conditions:
  Type           Status
  Initialized    True 
  Ready          True 
  PodScheduled   True 
Volumes:
  data:
    Type:    EmptyDir (a temporary directory that shares a pod's lifetime)
    Medium:  
  default-token-bcxmz:
    Type:        Secret (a volume populated by a Secret)
    SecretName:  default-token-bcxmz
    Optional:    false
QoS Class:       Burstable
Node-Selectors:  <none>
Tolerations:     node.kubernetes.io/memory-pressure:NoSchedule
Events:
  Type     Reason                 Age              From                                   Message
  ----     ------                 ----             ----                                   -------
  Normal   Scheduled              6m               default-scheduler                      Successfully assigned mysql-1-sjcdh to ip-172-18-0-131.ec2.internal
  Normal   SuccessfulMountVolume  6m               kubelet, ip-172-18-0-131.ec2.internal  MountVolume.SetUp succeeded for volume "data"
  Normal   SuccessfulMountVolume  6m               kubelet, ip-172-18-0-131.ec2.internal  MountVolume.SetUp succeeded for volume "default-token-bcxmz"
  Normal   Pulling                6m               kubelet, ip-172-18-0-131.ec2.internal  pulling image "registry.access.redhat.com/rhscl/mysql-57-rhel7@sha256:7638d886370ca1eb3cefcfecf483f8dc4dc1ca05559dd521d1585ae7c4ed668e"
  Normal   Pulled                 4m               kubelet, ip-172-18-0-131.ec2.internal  Successfully pulled image "registry.access.redhat.com/rhscl/mysql-57-rhel7@sha256:7638d886370ca1eb3cefcfecf483f8dc4dc1ca05559dd521d1585ae7c4ed668e"
  Normal   Created                4m               kubelet, ip-172-18-0-131.ec2.internal  Created container
  Normal   Started                4m               kubelet, ip-172-18-0-131.ec2.internal  Started container
  Warning  Unhealthy              4m (x3 over 4m)  kubelet, ip-172-18-0-131.ec2.internal  Readiness probe failed: sh: cannot set terminal process group (-1): Inappropriate ioctl for device
sh: no job control in this shell
ERROR 2003 (HY000): Can't connect to MySQL server on '127.0.0.1' (111)

I am unable to reproduce this issue? Can I access the test environment?

I can reproduce this issue with 3.10 crio env:
openshift v3.10.0-0.29.0
kubernetes v1.10.0+b81c8f8
etcd 3.2.16

Normal   Created                11m   kubelet, host-172-16-120-115  Created container
  Normal   Started                11m   kubelet, host-172-16-120-115  Started container
  Warning  Unhealthy              11m   kubelet, host-172-16-120-115  Readiness probe failed: sh: cannot set terminal process group (-1): Inappropriate ioctl for device
sh: no job control in this shell
ERROR 2003 (HY000): Can't connect to MySQL server on '127.0.0.1' (111)

Also met this issue when test with mongodb:
 Warning  Unhealthy              6m    kubelet, host-172-16-120-115  Readiness probe failed: MongoDB shell version: 3.2.10
connecting to: 127.0.0.1:27017/sampledb
2018-04-27T08:51:45.407+0000 I NETWORK  [thread1] Socket recv() errno:104 Connection reset by peer 127.0.0.1:27017
2018-04-27T08:51:45.408+0000 I NETWORK  [thread1] SocketException: remote: (NONE):0 error: 9001 socket exception [RECV_ERROR] server [127.0.0.1:27017] 
2018-04-27T08:51:45.408+0000 E QUERY    [thread1] Error: network error while attempting to run command 'isMaster' on host '127.0.0.1:27017'  :
connect@src/mongo/shell/mongo.js:231:14
@(connect):1:6

sh: cannot set terminal process group (-1): Inappropriate ioctl for device
sh: no job control in this shell
exception: connect failed

Can I try and access the test environment to test this out myself and verify versions?

Wenjing,
Is the the readiness probe consistent? I have seen it fail only once while bring up sometimes while the mysqld is still coming up. Even then subsequent probes are successful and the pod is in Ready state.

Wenjing,
Is the readiness probe failure consistently happening for the same pod? I have seen it fail only once while bring up sometimes while the mysqld is still coming up which could happen if mysql takes time to come up. Even then subsequent probes are successful and the pod is in Ready state.

(In reply to Mrunal Patel from comment #15)
> Wenjing,
> Is the readiness probe failure consistently happening for the same pod? I
> have seen it fail only once while bring up sometimes while the mysqld is
> still coming up which could happen if mysql takes time to come up. Even then
> subsequent probes are successful and the pod is in Ready state.

I cannot reproduce with openshift v3.10.0-0.50.0 now.

Thanks! Can we close the bug then?

As comment 16, move this bug to verified, when reproduce will reopen. Thanks.

This can be reproduced on v3.9, and Red Hat SSO template with PostgreSQL also  was affected by this on OCP.

Does it have workaround except disabling readiness ?

~~~
6m          6m           3         redhat-sso-postgresql-1-wzpfc.1537a79cbe991085    Pod                     spec.containers{redhat-sso-postgresql}   Warning   Unhealthy               kubelet, node1s.ocp39.host.local   Readiness probe failed: sh: cannot set terminal process group (-1): Inappropriate ioctl for device
sh: no job control in this shell
psql: could not connect to server: Connection refused
          Is the server running on host "127.0.0.1" and accepting
          TCP/IP connections on port 5432?

~~~

reopen, as someone reproduce on 3.9

Can you file another BZ for docker and close this one please as it was verified against CRI-O?

Sure I've reported as new BZ[0], and you can close this BZ.

[0][https://bugzilla.redhat.com/show_bug.cgi?id=1590762]