Skip to content

Instantly share code, notes, and snippets.

@jboyd01

jboyd01/gist:1aa48ab55276748577f28434ff2dc38c

Last active August 24, 2018 13:18
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save jboyd01/1aa48ab55276748577f28434ff2dc38c to your computer and use it in GitHub Desktop.
Save jboyd01/1aa48ab55276748577f28434ff2dc38c to your computer and use it in GitHub Desktop.
Download ZIP
missing kubernetes events
Raw
gistfile1.txt
I've got a BZ issue that indicates events are sometimes missing on service
instances. I've been able to replicate it. Generally you see all events, but
sometimes, it seems like the most recent events are not displayed. For
instance, in my controller log I pull out all occurrences of "event.go" which
shows the events that were set on (in this case) the instance. The instance was
in an error condition for a bit (set to an invalid plan), but then the last
action I did updated the plan to a valid plan:
21:41:58.603293 1 event.go:221] Event(v1.ObjectReference{Kind:"ServiceInstance", Namespace:"default", Name:"myservice2",...... ResourceVersion:"126", FieldPath:""}): type: 'Warning' reason: 'ReferencesNonexistentServicePlan' References a non-existent ClusterServicePlan {ClusterServicePlanExternalName:"defaultXXX"} on ClusterServiceClass 4f6e6cf6-ffdd-425f-a2c7-3c9258ad246a {ClusterServiceClassExternalName:"example-starter-pack-service"} or there is more than one (found: 0)
21:41:59.325117 1 event.go:221] Event(v1.ObjectReference{Kind:"ServiceInstance", Namespace:"default", Name:"myservice2",...... ResourceVersion:"126", FieldPath:""}): type: 'Warning' reason: 'ReferencesNonexistentServicePlan' References a non-existent ClusterServicePlan {ClusterServicePlanExternalName:"defaultXXX"} on ClusterServiceClass 4f6e6cf6-ffdd-425f-a2c7-3c9258ad246a {ClusterServiceClassExternalName:"example-starter-pack-service"} or there is more than one (found: 0)
21:42:00.688095 1 event.go:221] Event(v1.ObjectReference{Kind:"ServiceInstance", Namespace:"default", Name:"myservice2",...... ResourceVersion:"126", FieldPath:""}): type: 'Warning' reason: 'ReferencesNonexistentServicePlan' References a non-existent ClusterServicePlan {ClusterServicePlanExternalName:"defaultXXX"} on ClusterServiceClass 4f6e6cf6-ffdd-425f-a2c7-3c9258ad246a {ClusterServiceClassExternalName:"example-starter-pack-service"} or there is more than one (found: 0)
21:42:03.390251 1 event.go:221] Event(v1.ObjectReference{Kind:"ServiceInstance", Namespace:"default", Name:"myservice2",...... ResourceVersion:"126", FieldPath:""}): type: 'Warning' reason: 'ReferencesNonexistentServicePlan' References a non-existent ClusterServicePlan {ClusterServicePlanExternalName:"defaultXXX"} on ClusterServiceClass 4f6e6cf6-ffdd-425f-a2c7-3c9258ad246a {ClusterServiceClassExternalName:"example-starter-pack-service"} or there is more than one (found: 0)
21:42:07.081418 1 event.go:221] Event(v1.ObjectReference{Kind:"ServiceInstance", Namespace:"default", Name:"myservice2",...... ResourceVersion:"129", FieldPath:""}): type: 'Normal' reason: 'UpdatingInstance' The instance is being updated asynchronously
21:42:08.180659 1 event.go:221] Event(v1.ObjectReference{Kind:"ServiceInstance", Namespace:"default", Name:"myservice2",...... ResourceVersion:"130", FieldPath:""}): type: 'Normal' reason: 'UpdatingInstance' The instance is being updated asynchronously (operation in progress: 0.25%)
21:42:08.546584 1 event.go:221] Event(v1.ObjectReference{Kind:"ServiceInstance", Namespace:"default", Name:"myservice2",...... ResourceVersion:"131", FieldPath:""}): type: 'Normal' reason: 'UpdatingInstance' The instance is being updated asynchronously (operation in progress: 0.5%)
21:42:10.612849 1 event.go:221] Event(v1.ObjectReference{Kind:"ServiceInstance", Namespace:"default", Name:"myservice2",...... ResourceVersion:"132", FieldPath:""}): type: 'Normal' reason: 'UpdatingInstance' The instance is being updated asynchronously (operation in progress: 0.75%)
21:42:18.987876 1 event.go:221] Event(v1.ObjectReference{Kind:"ServiceInstance", Namespace:"default", Name:"myservice2",...... ResourceVersion:"133", FieldPath:""}): type: 'Normal' reason: 'InstanceUpdatedSuccessfully' The instance was updated successfully
So you can see up to 21:42:07 it should be showing a message about a bogus
ClusterServicePlan. But AFTER that, it should show update events, and then
successfully updated. But here's the describe, the only condition shows the
expected last transition time properly (successfully updated), but the events
for the last update and successfully updated are not present. Would you agree?
from describe:
Status:
Async Op In Progress: false
Conditions:
Last Transition Time: 2018-08-22T21:42:18Z
Message: The instance was updated successfully
Reason: InstanceUpdatedSuccessfully
Status: True
Type: Ready
Deprovision Status: Required
External Properties:
Cluster Service Plan External ID: 86064792-7ea2-467b-af93-ac9694d96d5b
Cluster Service Plan External Name: default
Observed Generation: 7
Orphan Mitigation In Progress: false
Provision Status: Provisioned
Reconciled Generation: 7
Events:
Type Reason Age From Message
---- ------ ---- ---- -------
Normal Provisioning 5m service-catalog-controller-manager The instance is being provisioned asynchronously
Normal Provisioning 5m service-catalog-controller-manager The instance is being provisioned asynchronously (operation in progress: 0.25%)
Normal Provisioning 5m service-catalog-controller-manager The instance is being provisioned asynchronously (operation in progress: 0.5%)
Normal Provisioning 5m service-catalog-controller-manager The instance is being provisioned asynchronously (operation in progress: 0.75%)
Normal ProvisionedSuccessfully 4m service-catalog-controller-manager The instance was provisioned successfully
Warning ReferencesNonexistentServicePlan 3m (x12 over 3m) service-catalog-controller-manager References a non-existent ClusterServicePlan {ClusterServicePlanExternalName:"XX"} on ClusterServiceClass 4f6e6cf6-ffdd-425f-a2c7-3c9258ad246a {ClusterServiceClassExternalName:"example-starter-pack-service"} or there is more than one (found: 0)
Normal UpdatingInstance 3m service-catalog-controller-manager The instance is being updated asynchronously
Normal UpdatingInstance 3m service-catalog-controller-manager The instance is being updated asynchronously (operation in progress: 0.25%)
Normal UpdatingInstance 1m service-catalog-controller-manager The instance is being updated asynchronously
Normal UpdatingInstance 1m service-catalog-controller-manager The instance is being updated asynchronously (operation in progress: 0.25%)
Normal UpdatingInstance 1m (x2 over 2m) service-catalog-controller-manager The instance is being updated asynchronously (operation in progress: 0.5%)
Normal UpdatingInstance 1m (x2 over 2m) service-catalog-controller-manager The instance is being updated asynchronously (operation in progress: 0.75%)
Normal InstanceUpdatedSuccessfully 1m (x2 over 2m) service-catalog-controller-manager The instance was updated successfully
Warning ReferencesNonexistentServicePlan 42s (x17 over 1m) service-catalog-controller-manager References a non-existent ClusterServicePlan {ClusterServicePlanExternalName:"defaultXXX"} on ClusterServiceClass 4f6e6cf6-ffdd-425f-a2c7-3c9258ad246a {ClusterServiceClassExternalName:"example-starter-pack-service"} or there is more than one (found: 0)
$ date -u
Wed Aug 22 21:42:50 UTC 2018
It seems like it's missing events at the bottom doesn't it? Wouldn't you expect the last event listed to be the NEWEST?
I'm not certain if there is something funky going on with sumarizing/collapsing
the report of multiple events, ie the age, specifically the (x2 over 2m) bit.
But I'd only expect to see that for events that are in order. Do you know for
certain what I the correct behavior is?
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment