Bug 1766747 - A lot of events in the activity card have a timestamp of 1 AM
Summary: A lot of events in the activity card have a timestamp of 1 AM
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Management Console
Version: 4.3.0
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ---
: 4.3.0
Assignee: Samuel Padgett
QA Contact: Yadan Pei
URL:
Whiteboard:
Depends On:
Blocks: 1771520
TreeView+ depends on / blocked
 
Reported: 2019-10-29 19:29 UTC by Udi Kalifon
Modified: 2020-01-23 11:10 UTC (History)
9 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1771520 1772502 (view as bug list)
Environment:
Last Closed: 2020-01-23 11:09:47 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
Timestamps in activity card (209.47 KB, image/png)
2019-10-29 19:29 UTC, Udi Kalifon
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Github openshift console pull 3421 0 'None' closed Bug 1766747: Handle events created with events.k8s.io API 2020-09-11 09:52:01 UTC
Red Hat Product Errata RHBA-2020:0062 0 None None None 2020-01-23 11:10:15 UTC

Description Udi Kalifon 2019-10-29 19:29:06 UTC
Created attachment 1630318 [details]
Timestamps in activity card

Description of problem:
In the dashboards page you see a lot of activity from 1AM. In my case it's an illogical time since this setup has just been installed.


Version-Release number of selected component (if applicable):
4.3.0-0.ci-2019-10-29-152254


How reproducible:
Unknown


Steps to Reproduce:
1. Look at the activity card in the dashboards page.


Actual results:
Illogical timestamps


Additional info:
Screenshot attached

Comment 1 Rastislav Wagner 2019-11-04 08:56:59 UTC
I also saw this once and the issue was that the event itself has a wrong timestamp (1.00 AM 1 January 1970). Can you take a look at the event itself if this is the same case ? If yes, than its not a bug in UI.

Comment 2 Udi Kalifon 2019-11-06 14:44:46 UTC
The timestamp is <unknown>:

oc get events -n openshift-marketplace
<unknown>   Normal    Scheduled                pod/redhat-operators-7779d777f8-np5ph    Successfully assigned openshift-marketplace/redhat-operators-7779d777f8-np5ph to rhhi-node-master-2
<unknown>   Normal    Scheduled                pod/redhat-operators-784b69c4b8-d8pcv    Successfully assigned openshift-marketplace/redhat-operators-784b69c4b8-d8pcv to rhhi-node-master-2

It's still a problem that in the UI these events are always at the top of the list (they're the most recent), and the timestamps are confusing in the GUI if they're from a different date.

Comment 3 Samuel Padgett 2019-11-12 14:22:09 UTC
I'm going to change the component to kube-apiserver to investigate since these events should have timestamps, but also clone this bug to have console handle missing values.

Comment 4 Samuel Padgett 2019-11-14 13:47:18 UTC
Here's the YAML for one event with the missing timestamp:

- action: Binding
  apiVersion: v1
  eventTime: "2019-11-14T10:50:00.212773Z"
  firstTimestamp: null
  involvedObject:
    apiVersion: v1
    kind: Pod
    name: curator-1573728600-7z2sj
    namespace: openshift-logging
    resourceVersion: "1179999"
    uid: 339b7484-bc2c-4775-a419-7ca41dbf2681
  kind: Event
  lastTimestamp: null
  message: Successfully assigned openshift-logging/curator-1573728600-7z2sj to ip-10-0-167-133.ap-south-1.compute.internal
  metadata:
    creationTimestamp: "2019-11-14T10:50:00Z"
    name: curator-1573728600-7z2sj.15d701d2ec8e357d
    namespace: openshift-logging
    resourceVersion: "1180004"
    selfLink: /api/v1/namespaces/openshift-logging/events/curator-1573728600-7z2sj.15d701d2ec8e357d
    uid: 198674a0-9392-4d25-b34c-ae558880e977
  reason: Scheduled
  reportingComponent: default-scheduler
  reportingInstance: default-scheduler-ip-10-0-160-4
  source:
    component: default-scheduler
  type: Normal

Comment 5 Samuel Padgett 2019-11-14 14:03:16 UTC
I'm going to clone this bug. We should fix the missing timestamps in the resource, but web console shouldn't try to display a null timestamp.

Comment 6 Jan Chaloupka 2019-11-14 14:10:47 UTC
Rastislav, can you tell which event field is used by the UI to provide the timestamp? Is it lastTimestamp or firstTimestamp?

Comment 7 Samuel Padgett 2019-11-14 14:11:57 UTC
The YAML in is comment #4.

Comment 8 Michal Fojtik 2019-11-14 14:20:07 UTC
Sam, the web console should tolerate FirstTimestamp not be set. We can fix scheduler to set those, but in API that field is optional and other components might ignore it as well.

Comment 9 Samuel Padgett 2019-11-14 14:41:20 UTC
(In reply to Michal Fojtik from comment #8)
> Sam, the web console should tolerate FirstTimestamp not be set. We can fix
> scheduler to set those, but in API that field is optional and other
> components might ignore it as well.

Agreed. I already opened a PR: https://github.com/openshift/console/pull/3398

Comment 10 Jan Chaloupka 2019-11-15 10:28:52 UTC
Upstream switched to v1beta1 version of events [1] where both FirstTimestamp and LastTimestamp are depricated [2]. EventTime field carries the timestamp instead. As event sample in https://bugzilla.redhat.com/show_bug.cgi?id=1766747#c4 show, eventTime is set properly. UI needs to take both versions of events into account.

[1] https://github.com/openshift/origin/blob/master/vendor/k8s.io/kubernetes/staging/src/k8s.io/client-go/tools/events/event_recorder.go#L73-L91
[2] https://github.com/kubernetes/kubernetes/pull/49112/commits/69e2a9cb48fd49cf1449042984ea9c25edc0598c#diff-9170926eb096433f55393c1277d676cdR80-R85

Comment 11 Samuel Padgett 2019-11-15 13:26:50 UTC
It looks like the only way to handle this is to request the new event API and handle both the new and deprecated fields. For some events, only the deprecated fields are set even after switching to the new API group.

Comment 12 Samuel Padgett 2019-11-15 14:18:43 UTC
Unfortunately, console is blocked from moving to the new events API because it doesn't support field selectors on the involved object like the previous API:

❯ oc get events.events.k8s.io --field-selector regarding.name=postgres-655d497f6d-lg27m,regarding.kind=Pod
Error from server (BadRequest): Unable to find "events.k8s.io/v1beta1, Resource=events" that match label selector "", field selector "regarding.name=postgres-655d497f6d-lg27m,regarding.kind=Pod": "regarding.kind" is not a known field selector: only "metadata.name", "metadata.namespace"

This breaks the console Events tab. I don't believe there is a way to fix this in console alone.

Comment 13 Samuel Padgett 2019-11-15 14:26:12 UTC
Sending back to the kube-apiserver since field selector for the involved object does not work with the new API group. Console can't transition to the new API until this is available, and `series.lastObservedTime` is not available in any way through the legacy events API. Ideally, `regarding.uid` would work as a field selector. There's no way to fix this in console with current APIs.

Comment 14 Samuel Padgett 2019-11-15 14:37:35 UTC
Note that `eventTime` is not the same because console is showing `lastTimestamp` for the event and using `lastTimestamp` for sorting. `eventTime` is the first timestamp. The new `series.lastObservedTime` is not available in the core/v1 API, and `lastTimestamp` is null for these events.

Comment 15 Samuel Padgett 2019-11-15 14:58:41 UTC
I have a branch with the console changes ready if we are able to add the field selector: https://github.com/spadgett/console/commits/events-api

Comment 16 Samuel Padgett 2019-11-15 15:36:05 UTC
*** Bug 1772891 has been marked as a duplicate of this bug. ***

Comment 17 Samuel Padgett 2019-11-15 17:51:11 UTC
I'm wrong: series does appear to be in the core/v1 API, so we can test for that.

Comment 19 Yadan Pei 2019-11-19 01:58:19 UTC
- apiVersion: events.k8s.io/v1beta1
  deprecatedCount: 1
  deprecatedFirstTimestamp: "2019-11-19T01:10:56Z"
  deprecatedLastTimestamp: "2019-11-19T01:10:56Z"
  deprecatedSource:
    component: replicaset-controller
  eventTime: null
  kind: Event
  metadata:
    creationTimestamp: "2019-11-19T01:10:56Z"
    name: perl-659b959555.15d86b2042d27fb7
    namespace: yapei-1
    resourceVersion: "519542"
    selfLink: /apis/events.k8s.io/v1beta1/namespaces/yapei-1/events/perl-659b959555.15d86b2042d27fb7
    uid: 95630346-512f-48d5-a96f-95ec3d208fb7
  note: 'Created pod: perl-659b959555-98k4t'
  reason: SuccessfulCreate
  regarding:
    apiVersion: apps/v1
    kind: ReplicaSet
    name: perl-659b959555
    namespace: yapei-1
    resourceVersion: "515972"
    uid: 08f65129-8df3-4f0f-84c7-58aa3688414d
  type: Normal
kind: List
metadata:
  resourceVersion: ""
  selfLink: ""


Above is example event YAML using new event API events.k8s.io/v1beta1 we got from `oc get events -n test1 -o yaml`

Then
1)Check events displaying on Dashboards->Activity
2)Check events displaying on Events page
3) Check filtering by Type on Events page 

All above function work properly, verified on 4.3.0-0.nightly-2019-11-18-175710

Comment 21 errata-xmlrpc 2020-01-23 11:09:47 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2020:0062


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