COS Plugin error handling issue

[EimantasPelikis]

Issue context

I'm using the ibmcloud-object-storage-plugin together with Helm Charts Museum app. Initially my setup was working perfectly fine - helm charts get stored on the mounted volume and I was able to fetch them via API, but now it seems that volume get detached after it’s used one time after app is deployed. So, I need to re-deploy the app every time to get the volume back on pod - this is my observation after a quick troubleshooting - listing the files in the mounted directory as the app is used.

Recent troubleshooting pointed my to the plugin itself where I see the matching pattern of network errors and the problems with my app. Hope this helps to identify the issue and fix it.

Additional context
ibmcloud-object-storage-plugin pod logs:

{"level":"info","ts":"2020-08-19T21:58:29.231Z","caller":"provisioner/main.go:83","msg":"Failed to set flag:","error":"no such flag -logtostderr"}
{"level":"info","ts":"2020-08-19T21:58:29.231Z","caller":"provisioner/main.go:100","msg":"Provisioner specified: ","provisioner":"ibm.io/ibmc-s3fs"}
{"level":"info","ts":"2020-08-19T21:58:29.270Z","caller":"config/config.go:103","msg":"Entry SetUpEvn"}
{"level":"info","ts":"2020-08-19T21:58:29.313Z","caller":"config/config.go:147","msg":"Exporting cluster-config","cluster-info":{"cluster_id":"bsbhotel09vq2e1nk5ag","cluster_name":"prod-lon04-bsbhotel09vq2e1nk5ag","datacenter":"lon02"}}
{"level":"info","ts":"2020-08-19T21:58:29.313Z","caller":"config/config.go:111","msg":"Exit SetUpEvn"}
{"level":"info","ts":"2020-08-19T22:24:57.931Z","caller":"provisioner/ibm-s3fs-provisioner.go:193","msg":"aidt-charts-museum:bsbhotel09vq2e1nk5ag:Provisioning storage with these spec","requestID":"0df7cd61-e114-460d-ba44-3a2bc2dff777"}
{"level":"info","ts":"2020-08-19T22:24:57.931Z","caller":"provisioner/ibm-s3fs-provisioner.go:194","msg":"aidt-charts-museum:bsbhotel09vq2e1nk5ag:PVC Details: ","requestID":"0df7cd61-e114-460d-ba44-3a2bc2dff777","pvc":"pvc-1a3557f0-caf9-43ab-b3ee-666cc532a4e2"}
{"level":"info","ts":"2020-08-19T22:24:58.903Z","caller":"provisioner/ibm-s3fs-provisioner.go:471","msg":"aidt-charts-museum:bsbhotel09vq2e1nk5ag: acccess mode is.. ","requestID":"0df7cd61-e114-460d-ba44-3a2bc2dff777","access mode":["ReadWriteOnce"]}
E0821 20:36:36.272455       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=2307, ErrCode=NO_ERROR, debug=""
E0821 20:36:36.272557       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=2307, ErrCode=NO_ERROR, debug=""
E0821 20:36:36.272623       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=2307, ErrCode=NO_ERROR, debug=""
E0825 22:58:22.570406       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=4749, ErrCode=NO_ERROR, debug=""
E0825 22:58:22.570738       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=4749, ErrCode=NO_ERROR, debug=""
E0825 22:58:22.570809       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=4749, ErrCode=NO_ERROR, debug=""
E0826 21:51:01.835653       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=9, ErrCode=NO_ERROR, debug=""
E0826 21:51:01.835610       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=9, ErrCode=NO_ERROR, debug=""
E0826 21:51:01.835636       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=9, ErrCode=NO_ERROR, debug=""
E0829 22:07:06.556877       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=1189, ErrCode=NO_ERROR, debug=""
E0829 22:07:06.556940       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=1189, ErrCode=NO_ERROR, debug=""
E0829 22:07:06.557320       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=1189, ErrCode=NO_ERROR, debug=""
E0831 22:16:15.508634       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=1173, ErrCode=NO_ERROR, debug=""
E0831 22:16:15.509132       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=1173, ErrCode=NO_ERROR, debug=""
E0831 22:16:15.509376       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=1173, ErrCode=NO_ERROR, debug=""
E0901 22:24:02.047365       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=1187, ErrCode=NO_ERROR, debug=""
E0901 22:24:02.047352       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=1187, ErrCode=NO_ERROR, debug=""
E0901 22:24:02.047688       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=1187, ErrCode=NO_ERROR, debug=""
E0908 21:42:33.325347       1 reflector.go:251] github.com/kubernetes-sigs/sig-storage-lib-external-provisioner/controller/controller.go:669: Failed to watch *v1.PersistentVolume: Get https://172.21.0.1:443/api/v1/persistentvolumes?resourceVersion=11239068&timeout=5m31s&timeoutSeconds=331&watch=true: unexpected EOF
E0924 18:32:45.462763       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=13, ErrCode=NO_ERROR, debug=""
E0924 18:32:45.463212       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=13, ErrCode=NO_ERROR, debug=""
E0924 18:32:45.463487       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=13, ErrCode=NO_ERROR, debug=""
E0925 19:41:42.637320       1 reflector.go:251] github.com/kubernetes-sigs/sig-storage-lib-external-provisioner/controller/controller.go:666: Failed to watch *v1.PersistentVolumeClaim: Get https://172.21.0.1:443/api/v1/persistentvolumeclaims?resourceVersion=15119148&timeout=8m25s&timeoutSeconds=505&watch=true: unexpected EOF
E1016 15:19:03.483561       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=4823, ErrCode=NO_ERROR, debug=""
E1016 15:19:03.483591       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=4823, ErrCode=NO_ERROR, debug=""
E1016 15:19:03.483562       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=4823, ErrCode=NO_ERROR, debug=""
E1018 15:00:03.118130       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=2299, ErrCode=NO_ERROR, debug=""
E1018 15:00:03.118889       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=2299, ErrCode=NO_ERROR, debug=""
E1018 15:00:03.119315       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=2299, ErrCode=NO_ERROR, debug=""
E1023 03:21:28.741645       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=1183, ErrCode=NO_ERROR, debug=""
E1023 03:21:28.742127       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=1183, ErrCode=NO_ERROR, debug=""
E1023 03:21:28.742389       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=1183, ErrCode=NO_ERROR, debug=""
E1027 17:19:01.406513       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=349, ErrCode=NO_ERROR, debug=""
E1027 17:19:01.407035       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=349, ErrCode=NO_ERROR, debug=""
E1027 17:19:01.407383       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=349, ErrCode=NO_ERROR, debug=""
E1029 01:03:41.842846       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=311, ErrCode=NO_ERROR, debug=""
E1029 01:03:41.842941       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=311, ErrCode=NO_ERROR, debug=""
E1029 01:03:41.842847       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=311, ErrCode=NO_ERROR, debug=""
E1029 02:42:09.232009       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=99, ErrCode=NO_ERROR, debug=""
E1029 02:42:09.232472       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=99, ErrCode=NO_ERROR, debug=""
E1029 02:42:09.232772       1 streamwatcher.go:109] Unable to decode an event from the watch stream: http2: server sent GOAWAY and closed the connection; LastStreamID=99, ErrCode=NO_ERROR, debug=""

[nkkashyap]

Hi @EimantasPelikis
Are you using IAM API key or HMAC key for COS Instance access secret?
https://cloud.ibm.com/docs/containers?topic=containers-object_storage#create_cos_secret

[EimantasPelikis]

I setup k8s secret for COS access using IAM API key:

kubectl create secret generic cos-write-access --type=ibm/ibmc-s3fs --from-literal=api-key=<api_key> --from-literal=service-instance-id=<service_instance_guid>

[nkkashyap]

There was a latent issue with s3fs, because of that s3fs is not able to refresh IBM IAM access token.
Install the latest version of the plugin 2.0.4

1. Uninstall the exiting plugin (it will not impact running workload)

$ helm ls --all --all-namespaces 
$ helm delete <helm_chart_name> -n <helm_chart_namespace>


2. Migrate to Helm-V3
https://cloud.ibm.com/docs/containers?topic=containers-helm#migrate_v3


3. Add the new helm repository

$ helm repo add ibm-helm https://raw.githubusercontent.com/IBM/charts/master/repo/ibm-helm
$ helm repo update
    
$ helm search repo -l ibm-helm/ibm-object-storage-plugin

 NAME                                   CHART VERSION    APP VERSION	DESCRIPTION                                       
 ibm-helm/ibm-object-storage-plugin	2.0.4            2.0.4      	Chart for deploying ibmcloud object storage plu...


4. Install new helm plugin ibmc

$ helm plugin uninstall ibmc
$ helm fetch --untar ibm-helm/ibm-object-storage-plugin
    

$ helm plugin install ./ibm-object-storage-plugin/helm-ibmc
$ helm ibmc --help


5. Install latest chart version

$ helm ibmc install ibm-object-storage-plugin ibm-helm/ibm-object-storage-plugin --set license=true