Bug 1876874

Description of problem: 

The audit log does not capture UID for "identities" resource in oauth-apiserver/audit.log with the 'Default' audit policy. 
The following audit events are recorded for "identities" resource but those do not capture UID of the normal user on 
first time login.  

$ oc adm node-logs --role master --path=oauth-apiserver/audit.log |grep "identities" 
ip-10-0-209-179.us-east-2.compute.internal {"kind":"Event","apiVersion":"audit.k8s.io/v1","level":"Metadata","auditID":"627d8a96-307f-4b71-8e50-5cea43db9f5a","stage":"ResponseComplete","requestURI":"/apis/user.openshift.io/v1/identities/flexy-htpasswd-provider:testuser-0","verb":"get","user":{"username":"system:serviceaccount:openshift-authentication:oauth-openshift","groups":["system:serviceaccounts","system:serviceaccounts:openshift-authentication","system:authenticated"]},"sourceIPs":["10.0.209.179","10.129.0.1"],"userAgent":"oauth-server/v0.0.0 (linux/amd64) kubernetes/$Format","objectRef":{"resource":"identities","name":"flexy-htpasswd-provider:testuser-0","apiGroup":"user.openshift.io","apiVersion":"v1"},"responseStatus":{"metadata":{},"status":"Failure","reason":"NotFound","code":404},"requestReceivedTimestamp":"2020-09-07T04:03:05.791984Z","stageTimestamp":"2020-09-07T04:03:05.799132Z","annotations":{"authorization.k8s.io/decision":"allow","authorization.k8s.io/reason":"RBAC: allowed by ClusterRoleBinding \"system:openshift:openshift-authentication\" of ClusterRole \"cluster-admin\" to ServiceAccount \"oauth-openshift/openshift-authentication\""}} 

ip-10-0-209-179.us-east-2.compute.internal {"kind":"Event","apiVersion":"audit.k8s.io/v1","level":"Metadata","auditID":"88ab8bae-a036-487c-97aa-edba82027a24","stage":"ResponseComplete","requestURI":"/apis/user.openshift.io/v1/identities","verb":"create","user":{"username":"system:serviceaccount:openshift-authentication:oauth-openshift","groups":["system:serviceaccounts","system:serviceaccounts:openshift-authentication","system:authenticated"]},"sourceIPs":["10.0.209.179","10.129.0.1"],"userAgent":"oauth-server/v0.0.0 (linux/amd64) kubernetes/$Format","objectRef":{"resource":"identities","name":"flexy-htpasswd-provider:testuser-0","apiGroup":"user.openshift.io","apiVersion":"v1"},"responseStatus":{"metadata":{},"code":201},"requestReceivedTimestamp":"2020-09-07T04:03:05.880668Z","stageTimestamp":"2020-09-07T04:03:05.887537Z","annotations":{"authorization.k8s.io/decision":"allow","authorization.k8s.io/reason":"RBAC: allowed by ClusterRoleBinding \"system:openshift:openshift-authentication\" of ClusterRole \"cluster-admin\" to ServiceAccount \"oauth-openshift/openshift-authentication\""}} 


Version-Release number of selected component (if applicable): 

4.6.0-0.nightly-2020-09-07-224533 

How reproducible: 

Always 

Steps to Reproduce: 

1.Create normal HTPasswd identity provider user 
2.Login into cluster using normal/test user  
$ oc login -u testuser-0 -p <pass> 
3.Log out and now, login into cluster using kubeadmin user 
$ oc login -u kubeadmin -p <pass> 
4.Get the normal user UID using the below command 
$ oc get identities 
5.Check if the event captures for "identities" resource with UID in oauth-apiserver audit logs 
$ oc adm node-logs --role master --path=oauth-apiserver/audit.log |grep "<Test user UID>"  
OR you can check on each master nodes individually 
$ grep "<Test user UID>" /var/log/oauth-apiserver/*.log 

Actual results: 

The audit log does not capture UID for "identities" resource in oauth-apiserver/audit.log with 'Default' audit policy on 
first time normal user login.

Expected results: 

The audit log should capture UID for "identities" resource in oauth-apiserver/audit.log on first time normal user login 
with 'Default' audit policy 

Additional info: 

This feature has been added in OCP 4.3 through [1] and since then it is capturing the following audit event with UID in 
'openshift-apiserver/audit.log' with 'Default' audit policy but with the recent changes in OCP 4.6 [2], it is not 
capturing this event with the 'Default' audit policy.  

o The following event captures on OCP 4.5 & below version with 'Default' audit policy. 

$ oc get identities 
NAME                                 IDP NAME                  IDP USER NAME   USER NAME    USER UID 
flexy-htpasswd-provider:testuser-0   flexy-htpasswd-provider   testuser-0      testuser-0   748e3413-ba7c-496a-b49f-10d0d0d14c64 

$ oc adm node-logs --role master --path=openshift-apiserver/audit.log |grep "748e3413-ba7c-496a-b49f-10d0d0d14c64" 
ip-10-0-51-231.us-east-2.compute.internal {"kind":"Event","apiVersion":"audit.k8s.io/v1","level":"RequestResponse","auditID":"2e506831-efce-4c74-84ab-be6c1a6b1196","stage":"ResponseComplete","requestURI":"/apis/user.openshift.io/v1/identities","verb":"create","user":{"username":"system:serviceaccount:openshift-authentication:oauth-openshift","groups":["system:serviceaccounts","system:serviceaccounts:openshift-authentication","system:authenticated"]},"sourceIPs":["10.130.0.40","10.130.0.1"],"userAgent":"oauth-server/v0.0.0 (linux/amd64) kubernetes/$Format","objectRef":{"resource":"identities","name":"flexy-htpasswd-provider:testuser-0","apiGroup":"user.openshift.io","apiVersion":"v1"},"responseStatus":{"metadata":{},"code":201},"requestObject":{"kind":"Identity","apiVersion":"user.openshift.io/v1","metadata":{"name":"flexy-htpasswd-provider:testuser-0","creationTimestamp":null},"providerName":"flexy-htpasswd-provider","providerUserName":"testuser-0","user":{"name":"testuser-0","uid":"748e3413-ba7c-496a-b49f-10d0d0d14c64"}},"responseObject":{"kind":"Identity","apiVersion":"user.openshift.io/v1","metadata":{"name":"flexy-htpasswd-provider:testuser-0","selfLink":"/apis/user.openshift.io/v1/identities/flexy-htpasswd-provider%3Atestuser-0","uid":"1ec30b15-9908-4745-a29b-ce639fc13a13","resourceVersion":"50900","creationTimestamp":"2020-05-27T05:53:19Z","managedFields":[{"manager":"oauth-server","operation":"Update","apiVersion":"user.openshift.io/v1","time":"2020-05-27T05:53:19Z","fieldsType":"FieldsV1","fieldsV1":{"f:providerName":{},"f:providerUserName":{},"f:user":{"f:name":{},"f:uid":{}}}}]},"providerName":"flexy-htpasswd-provider","providerUserName":"testuser-0","user":{"name":"testuser-0","uid":"748e3413-ba7c-496a b49f-10d0d0d14c64"}},"requestReceivedTimestamp":"2020-05-27T05:53:19.594853Z","stageTimestamp":"2020-05-27T05:53:19.600682Z","annotations":{"authorization.k8s.io/decision":"allow","authorization.k8s.io/reason":"RBAC: allowed by ClusterRoleBinding \"system:o
penshift:openshift-authentication\" of ClusterRole \"cluster-admin\" to ServiceAccount \"oauth-openshift/openshift-authentication\""}}   


o The above similar event captures on OCP 4.6 when the audit policy set to 'AllRequestBodies'. 

$ oc get identities 
NAME                                 IDP NAME                  IDP USER NAME   USER NAME    USER UID 
flexy-htpasswd-provider:testuser-1   flexy-htpasswd-provider   testuser-1      testuser-1   56fd41dc-fe03-43b5-b885-ef9371a45ad8 

$ oc get apiserver/cluster -ojson | jq .spec.audit 
{ 
  "profile": "AllRequestBodies" 
} 

$ oc adm node-logs --role master --path=oauth-apiserver/audit.log |grep "56fd41dc-fe03-43b5-b885-ef9371a45ad8" 
ip-10-0-182-10.us-east-2.compute.internal {"kind":"Event","apiVersion":"audit.k8s.io/v1","level":"RequestResponse","auditID":"b6897944-188b-4067-91aa-dc6f9a74e54b","stage":"ResponseComplete","requestURI":"/apis/user.openshift.io/v1/identities","verb":"create","user":{"username":"system:serviceaccount:openshift-authentication:oauth-openshift","groups":["system:serviceaccounts","system:serviceaccounts:openshift-authentication","system:authenticated"]},"sourceIPs":["10.0.182.10","10.128.0.1"],"userAgent":"oauth-server/v0.0.0 (linux/amd64) kubernetes/$Format","objectRef":{"resource":"identities","name":"flexy-htpasswd-provider:testuser-1","apiGroup":"user.openshift.io","apiVersion":"v1"},"responseStatus":{"metadata":{},"code":201},"requestObject":{"kind":"Identity","apiVersion":"user.openshift.io/v1","metadata":{"name":"flexy-htpasswd-provider:testuser-1","creationTimestamp":null},"providerName":"flexy-htpasswd-provider","providerUserName":"testuser-1","user":{"name":"testuser-1","uid":"56fd41dc-fe03-43b5-b885-ef9371a45ad8"}},"responseObject":{"kind":"Identity","apiVersion":"user.openshift.io/v1","metadata":{"name":"flexy-htpasswd-provider:testuser-1","selfLink":"/apis/user.openshift.io/v1/identities/flexy-htpasswd-provider%3Atestuser-1","uid":"24a17a62-fbd3-43b9-be2b-bbcc7b2b9462","resourceVersion":"359601","creationTimestamp":"2020-09-08T10:29:24Z"},"providerName":"flexy-htpasswd-provider","providerUserName":"testuser-1","user":{"name":"testuser-1","uid":"56fd41dc-fe03-43b5-b885-ef9371a45ad8"}},"requestReceivedTimestamp":"2020-09-08T10:29:24.583830Z","stageTimestamp":"2020-09-08T10:29:24.605686Z","annotations":{"authorization.k8s.io/decision":"allow","authorization.k8s.io/reason":"RBAC: allowed by ClusterRoleBinding \"system:openshift:openshift-authentication\" of ClusterRole \"cluster-admin\" to ServiceAccount \"oauth-openshift/openshift-authentication\""}} 

[1] https://issues.redhat.com/browse/CMP-175 
[2] http://post-office.corp.redhat.com/archives/aos-devel/2020-August/msg00021.html