Bug 1459252

Summary: journalctl on node repeats UnmountVolume operation started for volume messages
Product: OKD Reporter: Phil Cameron <pcameron>
Component: StorageAssignee: Matthew Wong <mawong>
Status: CLOSED NOTABUG QA Contact: Jianwei Hou <jhou>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 3.xCC: aos-bugs, aos-storage-staff, bbennett, eparis, hchen, mawong
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: 2017-06-13 17:03:20 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:

Description Phil Cameron 2017-06-06 15:58:23 UTC 
Description of problem:
journalctl -flu atomic-openshift-node.service | grep -e _wrapped_wrapped_
displays repeated messages for example,
Jun 06 11:54:17 netdev35 atomic-openshift-node[115713]: I0606 11:54:17.416698  115713 reconciler.go:201] UnmountVolume operation started for volume "kubernetes.io/configmap/f083fcee-4608-11e7-b1a5-ecf4bbd7ae44-wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_config-volume.deleting~461540041.deleting~889175940.deleting~469023339.deleting~783960268.deleting~000819238.deleting~209408262.deleting~397218250.deleting~603280394" (spec.Name: "wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_config-volume.deleting~461540041.deleting~889175940.deleting~469023339.deleting~783960268.deleting~000819238.deleting~209408262.deleting~397218250.deleting~603280394") from pod "f083fcee-4608-11e7-b1a5-ecf4bbd7ae44" (UID: "f083fcee-4608-11e7-b1a5-ecf4bbd7ae44").
Jun 06 11:54:17 netdev35 atomic-openshift-node[115713]: I0606 11:54:17.421298  115713 reconciler.go:201] UnmountVolume operation started for volume "kubernetes.io/configmap/f083fcee-4608-11e7-b1a5-ecf4bbd7ae44-wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_config-volume.deleting~151677536.deleting~030149897.deleting~096579521.deleting~512783192.deleting~123077078.deleting~118263454.deleting~001451200.deleting~668627464" (spec.Name: "wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_config-volume.deleting~151677536.deleting~030149897.deleting~096579521.deleting~512783192.deleting~123077078.deleting~118263454.deleting~001451200.deleting~668627464") from pod "f083fcee-4608-11e7-b1a5-ecf4bbd7ae44" (UID: "f083fcee-4608-11e7-b1a5-ecf4bbd7ae44").
Jun 06 11:54:17 netdev35 atomic-openshift-node[115713]: I0606 11:54:17.425387  115713 reconciler.go:201] UnmountVolume operation started for volume "kubernetes.io/configmap/f083fcee-4608-11e7-b1a5-ecf4bbd7ae44-wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_config-volume.deleting~878887437.deleting~626538613.deleting~626857022.deleting~967767454.deleting~704035685.deleting~443312250.deleting~898141921" (spec.Name: "wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_wrapped_config-volume.deleting~878887437.deleting~626538613.deleting~626857022.deleting~967767454.deleting~704035685.deleting~443312250.deleting~898141921") from pod "f083fcee-4608-11e7-b1a5-ecf4bbd7ae44" (UID: "f083fcee-4608-11e7-b1a5-ecf4bbd7ae44").


Version-Release number of selected component (if applicable):
software built from latest origin clone.

How reproducible:
At present can't get it to stop.

Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:

Master Log:

Node Log (of failed PODs):

PV Dump:

PVC Dump:

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

Additional info:
Comment 1 Bradley Childs 2017-06-06 16:09:07 UTC 
Phil - Can you provide more information including the dump of PVs and PVCs and any pods?
Comment 2 Phil Cameron 2017-06-06 17:02:37 UTC 
There are no PV/PVC in the setup

# oc get po
NAME                      READY     STATUS        RESTARTS   AGE
docker-registry-4-2hdmp   1/1       Running       0          1h
hello-rc-c9m05            1/1       Running       0          4d
Comment 3 hchen 2017-06-06 17:05:58 UTC 
Looks like https://github.com/kubernetes/kubernetes/issues/45935

Fix coming to 1.7
https://github.com/kubernetes/kubernetes/commit/c6bfa43c58d7323563a128b3189e0f7d2359cfc1
Comment 4 Phil Cameron 2017-06-06 17:12:09 UTC 
This was built with:
# go version
go version go1.8.1 linux/amd64
Comment 5 Eric Paris 2017-06-06 17:16:33 UTC 
how dangerous is the backport of https://github.com/kubernetes/kubernetes/pull/43878 to 3.6? Officially we will only ever build 3.6 with golang 1.7 but Phil won't be the only dev to do so...
Comment 6 Phil Cameron 2017-06-06 18:17:18 UTC 
Rebuilt with go 1.7.4 still getting the journal messages. Is there some way to clean things up?
Comment 7 Matthew Wong 2017-06-06 18:43:59 UTC 
The bad "deleting~...deleting~ folders to clean up should be under /var/lib/origin/pods/$POD_UID/volumes/kubernetes.io~config-map
Comment 8 Matthew Wong 2017-06-06 18:45:21 UTC 
correction: /var/lib/origin/openshift.local.volumes/pods/$POD_UID/volumes/kubernetes.io~config-map
Comment 9 Matthew Wong 2017-06-13 17:03:20 UTC 
This was caused by go version mismatch, manual cleanup of directories is required but resolves the issue.