Bug 1511302

Description of problem:
When gluster-block volume failed to provision, as end user I could only see error 'No space'. We need more detailed information testing why/how gluster block failed to provision.

Version-Release number of selected component (if applicable):
cns-deploy-5.0.0-54.el7rhgs.x86_64
heketi-client-5.0.0-16.el7rhgs.x86_64

How reproducible:
Always

Steps to Reproduce:
1. Deploy CNS on OpenShift v3.7
# oc get pods
NAME                                  READY     STATUS    RESTARTS   AGE
glusterblock-provisioner-dc-1-x5bpq   1/1       Running   0          11m
glusterfs-24n7s                       1/1       Running   0          1h
glusterfs-lpxmk                       1/1       Running   0          1h
glusterfs-tzh2n                       1/1       Running   0          1h
heketi-1-8vqr8                        1/1       Running   0          1h
storage-project-router-1-2gn9k        1/1       Running   0          2h

# oc export sc gluster-block
Parameters:
  chapauthenabled: "true"
  clusterids: 142594694ec86269d98b4d0156d88f70
  restauthenabled: "false"
  resturl: http://heketi-storage-project.1102-8ym.qe.rhcloud.com:80
  restuser: admin
Provisioner: gluster.org/glusterblock
creationTimestamp: null
name: gluster-block

# curl http://heketi-storage-project.1102-8ym.qe.rhcloud.com:80/hello
Hello from Heketi

# heketi-cli --server http://heketi-storage-project.1102-8ym.qe.rhcloud.com:80 cluster info 142594694ec86269d98b4d0156d88f70
Cluster id: 142594694ec86269d98b4d0156d88f70
Nodes:
082482a4c0897d63c9fc094e39c2203a
2cf9bed3bacc9fbdef51cb5bfdc2b03a
7e090b75e0937ca5e471e2788e31b000
Volumes:
02519edf6ad361e5977bb034f719148e
Block: true

File: true

2. Create PVC
# cat glusterfs-block-pvc-claim.yaml 
kind: PersistentVolumeClaim
apiVersion: v1
metadata:
  name: c1
  annotations:
    volume.beta.kubernetes.io/storage-class: gluster-block
spec:
  accessModes:
    - ReadWriteOnce
  resources:
    requests:
      storage: 1


Actual results:
After step 2, PVC remained pending. The problem is, as an end user, I can not tell what went wrong and how to fix it. The 'No space' error in the log doesn't help.

# oc describe pvc c1
Name:           c1
Namespace:      storage-project
StorageClass:   gluster-block
Status:         Pending
Volume:
Labels:         <none>
Annotations:    control-plane.alpha.kubernetes.io/leader={"holderIdentity":"fc61447e-c50d-11e7-89da-0a580a83002d","leaseDurationSeconds":15,"acquireTime":"2017-11-09T05:27:39Z","renewTime":"2017-11-09T05:35:32Z","lea...
                volume.beta.kubernetes.io/storage-class=gluster-block
                volume.beta.kubernetes.io/storage-provisioner=gluster.org/glusterblock
Capacity:
Access Modes:
Events:
  FirstSeen     LastSeen        Count   From                                                            SubObjectPath   Type            Reason                  Message
  ---------     --------        -----   ----                                                            -------------   --------        ------                  -------
  8m            3m              82      persistentvolume-controller                                                     Normal          ExternalProvisioning    waiting for a volume to be created, either by external provisioner "gluster.org/glusterblock" or manually created by system administrator
  8m            15s             11      gluster.org/glusterblock fc61447e-c50d-11e7-89da-0a580a83002d                   Normal          Provisioning            External provisioner is provisioning volume for claim "storage-project/c1"
  8m            14s             11      gluster.org/glusterblock fc61447e-c50d-11e7-89da-0a580a83002d                   Warning         ProvisioningFailed      Failed to provision volume with StorageClass "gluster-block":  failed to create volume: [heketi] error creating volume No space

# oc logs heketi-1-8vqr8
[negroni] Started POST /blockvolumes
[negroni] Completed 202 Accepted in 403.855µs
[asynchttp] INFO 2017/11/09 05:35:46 asynchttp.go:125: Started job 2f914cf62c34aa5a9de0f648ed90f69d
[heketi] INFO 2017/11/09 05:35:46 Creating block volume c06d7b91e13bb9037b38f8d564e3093f
[negroni] Started GET /queue/2f914cf62c34aa5a9de0f648ed90f69d
[negroni] Completed 200 OK in 35.784µs
[heketi] INFO 2017/11/09 05:35:46 No block hosting volumes found in the cluster list
[heketi] INFO 2017/11/09 05:35:46 brick_num: 0
[heketi] INFO 2017/11/09 05:35:46 brick_num: 0
[heketi] INFO 2017/11/09 05:35:46 brick_num: 0
[heketi] INFO 2017/11/09 05:35:46 brick_num: 0
[heketi] ERROR 2017/11/09 05:35:46 /src/github.com/heketi/heketi/apps/glusterfs/block_volume_entry.go:58: Failed to create Block Hosting Volume: No space
[asynchttp] INFO 2017/11/09 05:35:46 asynchttp.go:129: Completed job 2f914cf62c34aa5a9de0f648ed90f69d in 107.402803ms
[heketi] ERROR 2017/11/09 05:35:46 /src/github.com/heketi/heketi/apps/glusterfs/app_block_volume.go:83: Failed to create block volume: No space
[negroni] Started GET /queue/2f914cf62c34aa5a9de0f648ed90f69d
[negroni] Completed 500 Internal Server Error in 77.032µs

# oc logs glusterblock-provisioner-dc-1-x5bpq 
E1109 05:36:01.815188       1 controller.go:1080] Error scheduling operaion "provision-storage-project/c1[b38aa87a-c50e-11e7-b960-0050569f42d9]": Failed to create operation with name "provision-storage-project/c1[b38aa87a-c50e-11e7-b960-0050569f42d9]". An operation with that name failed at 2017-11-09 05:35:47.812360621 +0000 UTC. No retries permitted until 2017-11-09 05:37:49.812360621 +0000 UTC (2m2s). Last error: " failed to create volume: [heketi] error creating volume No space".
I1109 05:36:16.775582       1 controller.go:1073] scheduleOperation[provision-storage-project/c1[b38aa87a-c50e-11e7-b960-0050569f42d9]]
E1109 05:36:16.775614       1 controller.go:1080] Error scheduling operaion "provision-storage-project/c1[b38aa87a-c50e-11e7-b960-0050569f42d9]": Failed to create operation with name "provision-storage-project/c1[b38aa87a-c50e-11e7-b960-0050569f42d9]". An operation with that name failed at 2017-11-09 05:35:47.812360621 +0000 UTC. No retries permitted until 2017-11-09 05:37:49.812360621 +0000 UTC (2m2s). Last error: " failed to create volume: [heketi] error creating volume No space".
I1109 05:36:31.776550       1 controller.go:1073] scheduleOperation[provision-storage-project/c1[b38aa87a-c50e-11e7-b960-0050569f42d9]]
E1109 05:36:31.776579       1 controller.go:1080] Error scheduling operaion "provision-storage-project/c1[b38aa87a-c50e-11e7-b960-0050569f42d9]": Failed to create operation with name "provision-storage-project/c1[b38aa87a-c50e-11e7-b960-0050569f42d9]". An operation with that name failed at 2017-11-09 05:35:47.812360621 +0000 UTC. No retries permitted until 2017-11-09 05:37:49.812360621 +0000 UTC (2m2s). Last error: " failed to create volume: [heketi] error creating volume No space".
I1109 05:36:32.107905       1 leaderelection.go:204] stopped trying to renew lease to provision for pvc storage-project/c1, timeout reached
I1109 05:36:46.776792       1 controller.go:1073] scheduleOperation[provision-storage-project/c1[b38aa87a-c50e-11e7-b960-0050569f42d9]]
E1109 05:36:46.776830       1 controller.go:1080] Error scheduling operaion "provision-storage-project/c1[b38aa87a-c50e-11e7-b960-0050569f42d9]": Failed to create operation with name "provision-storage-project/c1[b38aa87a-c50e-11e7-b960-0050569f42d9]". An operation with that name failed at 2017-11-09 05:35:47.812360621 +0000 UTC. No retries permitted until 2017-11-09 05:37:49.812360621 +0000 UTC (2m2s). Last error: " failed to create volume: [heketi] error creating volume No space".


Expected results:
Block volume successfully created, or the log could tell what caused the failure.

Additional info:
Meanwhile, using the same cns deployment, I could successfully provision glusterfs volumes.

# oc export sc glusterprovisioner
Parameters:
  resturl: http://heketi-storage-project.1102-8ym.qe.rhcloud.com:80
  restuser: admin
Provisioner: kubernetes.io/glusterfs
creationTimestamp: null
name: glusterprovisioner


# oc get pvc
NAME        STATUS    VOLUME                                     CAPACITY   ACCESSMODES   STORAGECLASS         AGE
c1          Pending                                                                       gluster-block        13m
glusterc1   Bound     pvc-52a6397a-c510-11e7-b960-0050569f42d9   10Gi       RWO           glusterprovisioner   1m