Bug 1630117

Summary: Create Block Volume Build Failed: Server handling too many operations
Product: [Red Hat Storage] Red Hat Gluster Storage Reporter: Mauricio Magnani <mmagnani>
Component: heketiAssignee: John Mulligan <jmulligan>
Status: CLOSED CURRENTRELEASE QA Contact: Prasanth <pprakash>
Severity: low Docs Contact:
Priority: unspecified    
Version: cns-3.10CC: ansverma, charrogruver, dapark, hchiramm, kramdoss, madam, mmagnani, rhs-bugs, rtalur, sankarshan, storage-qa-internal
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-01-23 21:06:37 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
heketi dump
none
log heketi pod
none
pv
none
pv7
none
dump7
none
log7 none

Description Mauricio Magnani 2018-09-18 02:47:17 UTC 
### Description of problem ### 

During the attempt to create only one PVC using gluster-block the following message is displayed:

~~~
Failed to provision volume with StorageClass "glusterfs-storage-block": failed to create volume: heketi block volume creation failed: [heketi] failed to create volume: Server busy. Retry operation later.
~~~

When I checked the pod "heketi-storage-1-HASH" the following message is displayed:

~~~
[negroni] Started POST /blockvolumes
[heketi] WARNING 2018/09/18 02:37:24 temporarily rejecting block volume request: pending block-hosting-volume found
[negroni] Completed 429 Too Many Requests in 611.092µs
[heketi] ERROR 2018/09/18 02:37:24 /src/github.com/heketi/heketi/apps/glusterfs/operations_manage.go:89: Create Block Volume Build Failed: Server handling too many operations
~~~

This is a bit strange because I'm trying to create only one PVC and the server where this Pod is running has 14GB of free RAM.

The "kubernetes.io/glusterfs" storage class works very well in the same cluster.

### Version-Release ### 

ocs 3.10 "independent mode"
glusterfs 3.12.2
openshift v3.10.34
rhel 7.5

registry.access.redhat.com/rhgs3/rhgs-volmanager-rhel7           latest              bf4115f0c8e8        10 days ago         311 MB
registry.access.redhat.com/rhgs3/rhgs-gluster-block-prov-rhel7   latest              377527b85c0b        11 days ago         1.01 GB
registry.access.redhat.com/rhgs3/rhgs-server-rhel7               latest              2603af579f4e        2 weeks ago         299 MB


### Info ###

$ oc describe sc glusterfs-storage
Name:                  glusterfs-storage
IsDefaultClass:        No
Annotations:           <none>
Provisioner:           kubernetes.io/glusterfs
Parameters:            resturl=http://heketi-storage.app-storage.svc:8080,restuser=admin,secretName=heketi-storage-admin-secret,secretNamespace=app-storage
AllowVolumeExpansion:  <unset>
MountOptions:          <none>
ReclaimPolicy:         Delete
VolumeBindingMode:     Immediate
Events:                <none>

$ oc describe pvc storage-demo 
Name:          storage-demo
Namespace:     app-storage
StorageClass:  glusterfs-storage-block
Status:        Pending
Volume:        
Labels:        <none>
Annotations:   control-plane.alpha.kubernetes.io/leader={"holderIdentity":"dc32c5bb-bae7-11e8-b957-0a580a830024","leaseDurationSeconds":15,"acquireTime":"2018-09-18T02:21:48Z","renewTime":"2018-09-18T02:40:56Z","lea...
               volume.beta.kubernetes.io/storage-class=glusterfs-storage-block
               volume.beta.kubernetes.io/storage-provisioner=gluster.org/glusterblock
Finalizers:    [kubernetes.io/pvc-protection]
Capacity:      
Access Modes:  
Events:
  Type     Reason                Age                 From                                                           Message
  ----     ------                ----                ----                                                           -------
  Warning  ProvisioningFailed    18m (x12 over 19m)  gluster.org/glusterblock dc32c5bb-bae7-11e8-b957-0a580a830024  Failed to provision volume with StorageClass "glusterfs-storage-block": failed to create volume: heketi block volume creation failed: [heketi] failed to create volume: Server busy. Retry operation later.
  Normal   ExternalProvisioning  4m (x511 over 19m)  persistentvolume-controller                                    waiting for a volume to be created, either by external provisioner "gluster.org/glusterblock" or manually created by system administrator
  Normal   Provisioning          4m (x42 over 19m)   gluster.org/glusterblock dc32c5bb-bae7-11e8-b957-0a580a830024  External provisioner is provisioning volume for claim "app-storage/storage-demo"

#inventory

openshift_storage_glusterfs_namespace=app-storage
openshift_storage_glusterfs_storageclass=true
openshift_storage_glusterfs_storageclass_default=false
openshift_storage_glusterfs_block_deploy=true
openshift_storage_glusterfs_block_host_vol_size=100
openshift_storage_glusterfs_block_storageclass=true
openshift_storage_glusterfs_block_storageclass_default=false
openshift_storage_glusterfs_is_native=false
openshift_storage_glusterfs_heketi_is_native=true
openshift_storage_glusterfs_heketi_executor=ssh
openshift_storage_glusterfs_heketi_ssh_port=22
openshift_storage_glusterfs_heketi_ssh_user=root
openshift_storage_glusterfs_heketi_ssh_sudo=false
openshift_storage_glusterfs_heketi_ssh_keyfile="/root/.ssh/id_rsa"


[glusterfs]
ocs-0.mmagnani.lab glusterfs_ip=192.168.0.30 glusterfs_devices='[ "/dev/sdb" ]'
ocs-1.mmagnani.lab glusterfs_ip=192.168.0.31 glusterfs_devices='[ "/dev/sdb" ]'
ocs-2.mmagnani.lab glusterfs_ip=192.168.0.32 glusterfs_devices='[ "/dev/sdb" ]'
Comment 2 Mauricio Magnani 2018-09-18 02:50:38 UTC 
***

$ oc describe sc glusterfs-storage-block
Name:                  glusterfs-storage-block
IsDefaultClass:        No
Annotations:           <none>
Provisioner:           gluster.org/glusterblock
Parameters:            chapauthenabled=true,hacount=3,restsecretname=heketi-storage-admin-secret-block,restsecretnamespace=app-storage,resturl=http://heketi-storage.app-storage.svc:8080,restuser=admin
AllowVolumeExpansion:  <unset>
MountOptions:          <none>
ReclaimPolicy:         Delete
VolumeBindingMode:     Immediate
Events:                <none>
Comment 3 Raghavendra Talur 2018-09-19 03:28:44 UTC 
Mauricio,

The provisioner would get the "Server handling too many operations" error if heketi is performing 8 other operations. However, provisioner should retry and eventually succeed in creating the volume.


Thanks for providing the image ids and I have verified that the volmanager and block-provisioner images are the latest OCS 3.10 images.

Provide the following information for us to proceed:

1. tell us if the PV got created eventually, if yes then it is working as expected.
2. oc rsh into heketi pod and get the db dump. You can do so using the command "heketi-cli --user admin --secrete $HEKETI_ADMIN_KEY db dump > db_dump". Use oc rsync or any other command to get the file to a node from where you could attach it to the bug.
Comment 5 Mauricio Magnani 2018-09-23 04:56:45 UTC 
Hi Raghavendra,

sorry for the delay in getting back to you.

>>1. tell us if the PV got created eventually, if yes then it is working as expected.

Currently it is impossible to create any PV using Gluster-block.

>>2. oc rsh into heketi pod and get the db dump. You can do so using the command "heketi-cli --user admin --secrete $HEKETI_ADMIN_KEY db dump > db_dump". Use oc rsync or any other command to get the file to a node from where you could attach it to the bug.

Sure!

Ps: I tested with the openshift v3.10.45 version and the behavior is the same.
Comment 6 Mauricio Magnani 2018-09-23 04:57:12 UTC 
Created attachment 1486129 [details]
heketi dump
Comment 7 Mauricio Magnani 2018-09-23 04:58:57 UTC 
Created attachment 1486130 [details]
log heketi pod
Comment 8 Mauricio Magnani 2018-09-23 05:02:03 UTC 
Created attachment 1486131 [details]
pv
Comment 9 Mauricio Magnani 2018-09-23 12:12:35 UTC 
Hey After seven hours is still in "Pending".
Comment 10 Mauricio Magnani 2018-09-23 12:12:59 UTC 
Created attachment 1486190 [details]
pv7
Comment 11 Mauricio Magnani 2018-09-23 12:13:23 UTC 
Created attachment 1486191 [details]
dump7
Comment 12 Mauricio Magnani 2018-09-23 12:15:09 UTC 
Created attachment 1486192 [details]
log7
Comment 15 Charro 2018-10-02 18:07:46 UTC 
Mauricio,

   I experienced a very similar problem in an OpenShift Origin 3.10 cluster with an Independent Gluster deployment.

  I discovered that during the install, the ansible playbook for deploying Gluster is not starting the gluster-blockd service on the Gluster nodes.

  Check to see if gluster-blockd is running on your Gluster nodes:

systemctl status gluster-blockd

   If it's not installed, you will need to install Gluster-block.

Systemctl enable gluster-blockd
systemctl start gluster-blockd

Then scale Gluster-block-provisioner and Heketi pods down to zero, and then scale back up.

Hopefully it will now be working.
Comment 19 Raghavendra Talur 2019-01-23 21:06:37 UTC 
Closing as suggested in comment 18.