Bug 1298121 - Can't record NodeNotSchedulable/NodeSchedulable event when run command quickly
Can't record NodeNotSchedulable/NodeSchedulable event when run command quickly
Status: NEW
Product: OpenShift Origin
Classification: Red Hat
Component: Pod (Show other bugs)
3.x
Unspecified Unspecified
low Severity low
: ---
: ---
Assigned To: Avesh Agarwal
DeShuai Ma
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2016-01-13 05:07 EST by DeShuai Ma
Modified: 2016-02-04 09:06 EST (History)
3 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed:
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description DeShuai Ma 2016-01-13 05:07:44 EST
Description of problem:
When run manage-node command with --schedulable=false/true quickly, can't record NodeNotSchedulable/NodeSchedulable event. Run one command and wait a moment then run another can record event successfully.

Version-Release number of selected component (if applicable):
openshift v1.1-764-g7e08c95
kubernetes v1.1.0-origin-1107-g4c8e6f4
etcd 2.1.2

How reproducible:
Always

Steps to Reproduce:
1.Check NodeNotSchedulable/NodeSchedulable event
[fedora@ip-172-18-6-98 sample-app]$ oc get event|grep "NodeNotSchedulable"
12m         8m         3         ip-172-18-6-98            Node                                          NodeNotSchedulable   {kubelet ip-172-18-6-98}      Node ip-172-18-6-98 status is now: NodeNotSchedulable
[fedora@ip-172-18-6-98 sample-app]$ oc get event|grep "NodeSchedulable"
10m         8m         3         ip-172-18-6-98            Node                                          NodeSchedulable      {kubelet ip-172-18-6-98}      Node ip-172-18-6-98 status is now: NodeSchedulable

2.Enable/Disable node schedulable quickly
cat > run.sh <<EOF
oadm manage-node ip-172-18-6-98 --schedulable=false
oadm manage-node ip-172-18-6-98 --schedulable=true
EOF
$ sh run.sh

3.Check NodeNotSchedulable/NodeSchedulable event
[fedora@ip-172-18-6-98 sample-app]$ oc get event|grep "NodeNotSchedulable"
14m         10m        3         ip-172-18-6-98            Node                                          NodeNotSchedulable   {kubelet ip-172-18-6-98}      Node ip-172-18-6-98 status is now: NodeNotSchedulable
[fedora@ip-172-18-6-98 sample-app]$ oc get event|grep "NodeSchedulable"
13m         10m        3         ip-172-18-6-98            Node                                          NodeSchedulable      {kubelet ip-172-18-6-98}      Node ip-172-18-6-98 status is now: NodeSchedulable


Actual results:
3.No new NodeNotSchedulable/NodeSchedulable event be recorded

Expected results:
3.Should record NodeNotSchedulable/NodeSchedulable event

Additional info:
Comment 1 Avesh Agarwal 2016-02-03 11:19:46 EST
Its weird, somehow I am not able to see any events in origin now, still looking why the api server seems to be rejecting all events.
Comment 2 Avesh Agarwal 2016-02-03 11:21:29 EST
E0203 11:02:32.658211   28129 event.go:188] Server rejected event '&api.Event{TypeMeta:unversioned.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:api.ObjectMeta{Name:"192.168.122.253.142f7a01c37a7f2d", GenerateName:"", Namespace:"default", SelfLink:"", UID:"", ResourceVersion:"", Generation:0, CreationTimestamp:unversioned.Time{Time:time.Time{sec:0, nsec:0, loc:(*time.Location)(nil)}}, DeletionTimestamp:(*unversioned.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil)}, InvolvedObject:api.ObjectReference{Kind:"Node", Namespace:"", Name:"192.168.122.253", UID:"192.168.122.253", APIVersion:"", ResourceVersion:"", FieldPath:""}, Reason:"RegisteredNode", Message:"Node 192.168.122.253 event: Registered Node 192.168.122.253 in NodeController", Source:api.EventSource{Component:"controllermanager", Host:""}, FirstTimestamp:unversioned.Time{Time:time.Time{sec:63590112152, nsec:657100589, loc:(*time.Location)(0x51cd8c0)}}, LastTimestamp:unversioned.Time{Time:time.Time{sec:63590112152, nsec:657100589, loc:(*time.Location)(0x51cd8c0)}}, Count:1, Type:"Normal"}': 'Event "192.168.122.253.142f7a01c37a7f2d" is invalid: involvedObject.namespace: invalid value '', Details: not required for node' (will not retry!)
Comment 3 Avesh Agarwal 2016-02-03 12:33:10 EST
I am able to reproduce the issue.
Comment 4 Avesh Agarwal 2016-02-03 12:34:41 EST
Please note, I was able to reproduce it with origin/v1.1.1.1 tag as the latest origin master branch has issue as server is rejecting events from node.
Comment 5 Avesh Agarwal 2016-02-03 13:20:07 EST
It seems that as far as one is as quick as under 5s, there wont be new events shown with oc get events.
Comment 6 Avesh Agarwal 2016-02-04 09:06:40 EST
I looked into the code and it seems that it is working as expected. So right now it seems like "not a bug".

The reason is that kubelet does not send/record events if it finds that there is not change in its current state (node.Spec.Unschedulable) and old state (oldNodeUnschedulable). 

If the change from Schedulable->Unschedulable->Schedulable is fast enough (every few seconds kubelet updates its status to api server ) that the state remain same Schedulable during this period, no event is generated. And thats why this behaviour.  

I am not sure it is worthwhile to change kubelet behaviour for this issue. So again I would say it sounds like "not a bug" right now. 

Please let me know if it makes sense and we can close this bug.

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