Bug 1490980 - Heketi pod stops working when beging restarted or deleted
Summary: Heketi pod stops working when beging restarted or deleted
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Gluster Storage
Classification: Red Hat Storage
Component: heketi
Version: rhgs-3.0
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
: CNS 3.6
Assignee: Michael Adam
QA Contact: Prasanth
URL:
Whiteboard:
Depends On:
Blocks: 1445448
TreeView+ depends on / blocked
 
Reported: 2017-09-12 16:33 UTC by Hongkai Liu
Modified: 2017-10-12 16:58 UTC (History)
10 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1494339 (view as bug list)
Environment:
Last Closed: 2017-10-11 07:09:46 UTC
Embargoed:


Attachments (Terms of Use)
node log and pod log (61.62 KB, application/zip)
2017-09-12 16:33 UTC, Hongkai Liu
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Red Hat Bugzilla 1494339 0 urgent CLOSED Heketi pod stops working when being restarted or deleted 2021-02-22 00:41:40 UTC
Red Hat Bugzilla 1500955 0 unspecified CLOSED heketi.db in read-only when heketi pod is rescheduled 2021-02-22 00:41:40 UTC
Red Hat Product Errata RHEA-2017:2879 0 normal SHIPPED_LIVE heketi bug fix and enhancement update 2017-10-11 11:07:06 UTC

Internal Links: 1494339 1500955

Description Hongkai Liu 2017-09-12 16:33:20 UTC
Created attachment 1324971 [details]
node log and pod log

Description of problem:
Heketi pod stops working when beging restarted or deleted.
We cannot provision pvc based on glusterfs any more.

Version-Release number of selected component (if applicable):
tried with both versions of cns:
openshift_storage_glusterfs_image=registry.access.redhat.com/rhgs3/rhgs-server-rhel7
openshift_storage_glusterfs_version=latest
openshift_storage_glusterfs_heketi_image=registry.access.redhat.com/rhgs3/rhgs-volmanager-rhel7
openshift_storage_glusterfs_heketi_version=latest

openshift_storage_glusterfs_image=brew-pulp-docker01.web.prod.ext.phx2.redhat.com:8888/rhgs3/rhgs-server-rhel7
openshift_storage_glusterfs_version=3.3.0-12
openshift_storage_glusterfs_heketi_image=brew-pulp-docker01.web.prod.ext.phx2.redhat.com:8888/rhgs3/rhgs-volmanager-rhel7
openshift_storage_glusterfs_heketi_version=3.3.0-9

How reproducible:

Steps to Reproduce:
1. deploy cns via openshift ansible playbook.
2. oc delete pod -n heketi-storage-2-dwsn5
3. wait until heketi pod is recreated and ready
4. create a pvc, for example,
	oc create -f https://raw.githubusercontent.com/hongkailiu/svt-case-doc/master/files/pvc_gluster.yaml
5. the pvc is pending for ever.

Actual results:
PVC stuck in pending status.

Expected results:
PVC is in bound status.

Master Log:

Node Log (of failed PODs):

PV Dump:

PVC Dump:

StorageClass Dump (if StorageClass used by PV/PVC):

Additional info:
Heketi pod log and node log where heketi pod runs are in the attachment.

+ oc version
oc v3.6.172.0.0
kubernetes v1.6.1+5115d708d7
features: Basic-Auth GSSAPI Kerberos SPNEGO

Server https://ip-172-31-8-170.us-west-2.compute.internal:8443
openshift v3.6.172.0.0
kubernetes v1.6.1+5115d708d7
+ openshift version
openshift v3.6.172.0.0
kubernetes v1.6.1+5115d708d7
etcd 3.2.1
+ docker version
Client:
 Version:         1.12.6
 API version:     1.24
 Package version: docker-1.12.6-48.git0fdc778.el7.x86_64
 Go version:      go1.8.3
 Git commit:      0fdc778/1.12.6
 Built:           Thu Jul 20 00:06:39 2017
 OS/Arch:         linux/amd64

Server:
 Version:         1.12.6
 API version:     1.24
 Package version: docker-1.12.6-48.git0fdc778.el7.x86_64
 Go version:      go1.8.3
 Git commit:      0fdc778/1.12.6
 Built:           Thu Jul 20 00:06:39 2017
 OS/Arch:         linux/amd64

Comment 1 Hongkai Liu 2017-09-12 16:36:37 UTC
The heketi pod will work again if we do:
# oc scale --replicas=0 -n glusterfs dc/heketi-storage
# #wait until the heketi pod is deleted
# oc scale --replicas=1 -n glusterfs dc/heketi-storage
However, it would be better if it can survive of pod-deletion.

Comment 2 Humble Chirammal 2017-09-12 17:35:09 UTC
This is because "heketi" service is runnning in READONLY mode. Either gluster volume lost quorum or something wrong happened to the disks hosting heketi DB bricks. 

Whats the status of Gluster pods ?


Heketi 5.0.0
[heketi] INFO 2017/09/12 15:52:38 Loaded kubernetes executor
[heketi] WARNING 2017/09/12 15:52:41 Unable to open database.  Retrying using read only mode



Sep 12 11:52:39 ip-172-31-60-3 atomic-openshift-node: I0912 11:52:39.471693   28519 operation_generator.go:609] MountVolume.SetUp succeeded for volume "kubernetes.io/secret/6412cd33-97d2-11e7-8c0b-02e10845fe38-heketi-storage-service-account-token-xpgp7" (spec.Name: "heketi-storage-service-account-token-xpgp7") pod "6412cd33-97d2-11e7-8c0b-02e10845fe38" (UID: "6412cd33-97d2-11e7-8c0b-02e10845fe38").
Sep 12 11:52:39 ip-172-31-60-3 atomic-openshift-node: I0912 11:52:39.471702   28519 operation_generator.go:609] MountVolume.SetUp succeeded for volume "kubernetes.io/secret/6412cd33-97d2-11e7-8c0b-02e10845fe38-config" (spec.Name: "config") pod "6412cd33-97d2-11e7-8c0b-02e10845fe38" (UID: "6412cd33-97d2-11e7-8c0b-02e10845fe38").
Sep 12 11:52:41 ip-172-31-60-3 journal: [heketi] WARNING 2017/09/12 15:52:41 Unable to open database.  Retrying using read only mode

Comment 3 Hongkai Liu 2017-09-12 17:52:03 UTC
Before I try to create pvc:

# oc get pod -o wide
NAME                      READY     STATUS    RESTARTS   AGE       IP             NODE
glusterfs-storage-7t416   1/1       Running   0          18m       172.31.35.72   ip-172-31-35-72.us-west-2.compute.internal
glusterfs-storage-81n1p   1/1       Running   0          18m       172.31.60.3    ip-172-31-60-3.us-west-2.compute.internal
glusterfs-storage-b15p6   1/1       Running   0          18m       172.31.55.21   ip-172-31-55-21.us-west-2.compute.internal
heketi-storage-2-bg2hx    1/1       Running   0          1m        172.20.4.4     ip-172-31-60-3.us-west-2.compute.internal

Comment 5 Humble Chirammal 2017-09-14 11:44:00 UTC
Can you also attach glusterfs logs from all three nodes which host gluster nodes ? 

The logs are available at /var/log/glusterfs directory.

Comment 7 Humble Chirammal 2017-09-17 06:44:22 UTC
Can you try this image and let me know the result?

    Image:		rhgs3/rhgs-volmanager-rhel7:3.3.0-15
    Image ID:		docker-pullable://brew-pulp-docker01.web.prod.ext.phx2.redhat.com:8888/rhgs3/rhgs-volmanager-rhel7@sha256:48519fa6d7c9e52a4b5197b082a80f889b9d6f1304f22a59dcd3a10f4f54945f

Comment 10 Humble Chirammal 2017-09-18 08:08:29 UTC
The fix is in above mentioned image which is part of cns-deploy-5.0.0-43.el7rhgs

Comment 15 Prasanth 2017-09-20 19:46:23 UTC
(In reply to Humble Chirammal from comment #14)
> Can you please try to delete the pod with --now option and see the result ?
> Or were you already doing that ?
> 
> Because in various setups we have below result:
> 
> 1) Node reboot always brings up heketi server pod in RW mode
> 2) oc delete pod with --now option work always.
> 
> In case even with --now option if you are facing issue, 

I've seen this issue atleast once even with the latest builds and once i tried the --now option as suggested by Humble here, I haven't hit this issue. That said, even without this option, it worked when i tried on a couple of other setups as well. 

But, if I understand it correctly, this is due to the heketi pod termination taking more than 15 sec in some setups and so we may have to increase this delay even further later, if required.

With that, i'm moving this bug to verified.

Comment 16 Hongkai Liu 2017-09-21 00:04:27 UTC
I will do the verification first thing tomorrow morning.
Sorry for the late reply.

Comment 17 Humble Chirammal 2017-09-21 07:58:07 UTC
(In reply to Prasanth from comment #15)
> (In reply to Humble Chirammal from comment #14)
> > Can you please try to delete the pod with --now option and see the result ?
> > Or were you already doing that ?
> > 
> > Because in various setups we have below result:
> > 
> > 1) Node reboot always brings up heketi server pod in RW mode
> > 2) oc delete pod with --now option work always.
> > 
> > In case even with --now option if you are facing issue, 
> 
> I've seen this issue atleast once even with the latest builds and once i
> tried the --now option as suggested by Humble here, I haven't hit this
> issue. That said, even without this option, it worked when i tried on a
> couple of other setups as well. 
> 
> But, if I understand it correctly, this is due to the heketi pod termination
> taking more than 15 sec in some setups and so we may have to increase this
> delay even further later, if required.
> 
> With that, i'm moving this bug to verified.

Exactly thats what is happening , in most of the setups it works but its subjective to the time Gluster is taking to establish quorum to FUSE servers and the time the previous heketi pod is taking to terminate. 


With --now option it should work and I tried mainly --now option as it was listed in BZ description.

Any way, we can also work on a seperate fix which check the 'real' status of the underlying volume or increase the delay to start the heketi process somemore for safer side. 


We are on it and will provide the update soon.

Comment 18 Hongkai Liu 2017-09-21 15:19:57 UTC
Did some verification:

released version:
glusterfs: 3.2.0-7
heketi: 3.2.0-11
oc delete pod with --now: works fine after pod get recreated.
It seems that even older version is happy with the "--now" flag.

pre-released version
glusterfs: 3.3.0-12
heketi: 3.3.0-9
Case 1
oc delete pod with --now: works fine after pod get recreated.
Case 2
Kill the keheti process in the pod: works fine after pod get restarted.

So I believe that --now flag is the workaround for the moment if delete.
When it got restarted for some reason, read-only should not be occurring.

Looking forward to solution without --now.

I am fine with "VERIFIED".

Thanks.

Comment 19 Humble Chirammal 2017-09-21 16:36:02 UTC
(In reply to Hongkai Liu from comment #18)
> Did some verification:
> 
> released version:
> glusterfs: 3.2.0-7
> heketi: 3.2.0-11
> oc delete pod with --now: works fine after pod get recreated.
> It seems that even older version is happy with the "--now" flag.
> 
> pre-released version
> glusterfs: 3.3.0-12
> heketi: 3.3.0-9
> Case 1
> oc delete pod with --now: works fine after pod get recreated.
> Case 2
> Kill the keheti process in the pod: works fine after pod get restarted.
> 
> So I believe that --now flag is the workaround for the moment if delete.
> When it got restarted for some reason, read-only should not be occurring.
> 
> Looking forward to solution without --now.
> 
> I am fine with "VERIFIED".
> 
> Thanks.

Thanks for the verification !! yeah, we will have a more concrete fix soon!

Comment 21 errata-xmlrpc 2017-10-11 07:09:46 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2017:2879


Note You need to log in before you can comment on or make changes to this bug.