CADF identity.authenticate event initiator id is random UUID

Bug #1780503 reported by Gage Hugo
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Identity (keystone)
Fix Released
Medium
Gage Hugo

Bug Description

When enabling CADF notifications and clearing the notification_opt_out setting[0] (which cause keystone to be more chatty with notifications) in order to audit identity.authenticate events, keystone emits a notification for the identity.authentication event where the initiator's ID is a random UUID that doesn't match up to a user. Normally the initiator's ID is the ID of the user who performed the operation[1]. This was noticed when users would log into horizon and from the audit notification, it could not be determined which user was logging in.

An example of this is shown below, where keystone only has one user (admin). The config values for enabling CADF notifications were set here:

DEFAULT:
  notification_format: cadf
  notification_opt_out: ""
oslo_messaging_notifications:
  driver: messagingv2

ubuntu@zbook:~$ openstack --os-cloud openstack_helm token issue
+------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Field | Value |
+------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| expires | 2018-07-07T10:55:00+0000 |
| id | gAAAAABbP_NE7uqaSEN6dDR4sEDB5N0EvOA085lp82_puZmDxeVV16ulJ_4wCp_FR7suulqGyOf078kXWabvbL8jn45pBS95qRHfJeHDYZtf-mDsjFWm22YaiwqYnSUImz3Y2HsCD9ps_oJgwc2BHQUHHIYCiQeWQ-XmkzEvlc6tqQwflWFhHoM |
| project_id | f9e2428b6863443f85bcbb11ac6c300e |
| user_id | 37d3c436d45347529926a4887607d01b |
+------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

ubuntu@zbook:~$ python rabbitmqadmin --host=[redacted] --port=15672 --vhost="keystone" --username=superuser --password=123456 get queue=notifications.info ackmode=ack_requeue_false | tail -n +4 | head -n +1

| notifications.info | keystone | 0 | {"oslo.message": "{\"priority\": \"INFO\", \"_unique_id\": \"c4180ddc9500419898d6dd89086c1a0a\", \"event_type\": \"identity.authenticate\", \"timestamp\": \"2018-07-06 22:55:00.205671\", \"publisher_id\": \"identity.keystone-api-7d5c6cff4-g9dvd\", \"payload\": {\"typeURI\": \"http://schemas.dmtf.org/cloud/audit/1.0/event\", \"initiator\": {\"typeURI\": \"service/security/account/user\", \"host\": {\"agent\": \"osc-lib/1.10.0 keystoneauth1/3.7.0 python-requests/2.18.4 CPython/2.7.12\", \"address\": \"[redacted]\"}, \"id\": \"936c1487-eff3-59cc-b424-096cff3cd6e9\"}, \"target\": {\"typeURI\": \"service/security/account/user\", \"id\": \"932768de-4bf4-5c83-88cc-11f33f39cba9\"}, \"observer\": {\"typeURI\": \"service/security\", \"id\": \"9e53891b98b84bb898c0419e16426eca\"}, \"eventType\": \"activity\", \"eventTime\": \"2018-07-06T22:55:00.205401+0000\", \"action\": \"authenticate\", \"outcome\": \"success\", \"id\": \"bf658c41-24b5-5075-9aee-64e6b3db92cc\"}, \"message_id\": \"b1026bd5-c0d2-48af-adec-dc44c2e1a46b\"}", "oslo.version": "2.0"} | 1054 | string | False |

ubuntu@zbook:~$ openstack --os-cloud openstack_helm user list
+----------------------------------+-------+
| ID | Name |
+----------------------------------+-------+
| 37d3c436d45347529926a4887607d01b | admin |
+----------------------------------+-------+

ubuntu@zbook:~$ python rabbitmqadmin --host=[redacted] --port=15672 --vhost="keystone" --username=superuser --password=123456 get queue=notifications.info ackmode=ack_requeue_false | tail -n +4 | head -n +1

| notifications.info | keystone | 1 | {"oslo.message": "{\"priority\": \"INFO\", \"_unique_id\": \"c0fa7577c07a4de39013f41b33185489\", \"event_type\": \"identity.authenticate\", \"timestamp\": \"2018-07-06 22:56:45.534129\", \"publisher_id\": \"identity.keystone-api-7d5c6cff4-g9dvd\", \"payload\": {\"typeURI\": \"http://schemas.dmtf.org/cloud/audit/1.0/event\", \"initiator\": {\"typeURI\": \"service/security/account/user\", \"host\": {\"agent\": \"osc-lib/1.10.0 keystoneauth1/3.7.0 python-requests/2.18.4 CPython/2.7.12\", \"address\": \"[redacted]\"}, \"id\": \"129bfaf0-a8e3-579b-9030-0a5917547b46\"}, \"target\": {\"typeURI\": \"service/security/account/user\", \"id\": \"f67acddd-78df-58f1-be93-dcb196e44a9e\"}, \"observer\": {\"typeURI\": \"service/security\", \"id\": \"9e53891b98b84bb898c0419e16426eca\"}, \"eventType\": \"activity\", \"eventTime\": \"2018-07-06T22:56:45.533872+0000\", \"action\": \"authenticate\", \"outcome\": \"success\", \"id\": \"50468200-4b87-5a8a-b855-d25e8721ccea\"}, \"message_id\": \"cd9fe069-c0f6-4d3e-af65-f288cbb90f41\"}", "oslo.version": "2.0"} | 1054 | string | False |

ubuntu@zbook:~$ python rabbitmqadmin --host=[redacted] --port=15672 --vhost="keystone" --username=superuser --password=123456 get queue=notifications.info ackmode=ack_requeue_false | tail -n +4 | head -n +1

| notifications.info | keystone | 0 | {"oslo.message": "{\"priority\": \"INFO\", \"_unique_id\": \"e13c4eb09440496cb80b2297a61c12b8\", \"event_type\": \"identity.authenticate\", \"timestamp\": \"2018-07-06 22:56:45.572963\", \"publisher_id\": \"identity.keystone-api-7d5c6cff4-g9dvd\", \"payload\": {\"typeURI\": \"http://schemas.dmtf.org/cloud/audit/1.0/event\", \"initiator\": {\"typeURI\": \"service/security/account/user\", \"host\": {\"agent\": \"osc-lib/1.10.0 keystoneauth1/3.7.0 python-requests/2.18.4 CPython/2.7.12\", \"address\": \"[redacted]\"}, \"id\": \"38cee0b3-9b7f-5905-95f1-fa6cf61a637d\"}, \"target\": {\"typeURI\": \"service/security/account/user\", \"id\": \"3c9cdad0-a0f4-5151-ab44-da09add4be49\"}, \"observer\": {\"typeURI\": \"service/security\", \"id\": \"9e53891b98b84bb898c0419e16426eca\"}, \"eventType\": \"activity\", \"eventTime\": \"2018-07-06T22:56:45.572690+0000\", \"action\": \"authenticate\", \"outcome\": \"success\", \"id\": \"1b0d8ade-f94a-517c-a9f6-fb3df0a2c8c1\"}, \"message_id\": \"c8a55a89-908c-49c0-a0b2-9002fccecb03\"}", "oslo.version": "2.0"} | 1054 | string | False |

[0] https://github.com/openstack/keystone/blob/master/keystone/conf/default.py#L221

[1] https://docs.openstack.org/keystone/latest/advanced-topics/event_notifications.html#auditing-with-cadf

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix proposed to keystone (master)

Related fix proposed to branch: master
Review: https://review.openstack.org/580780

Gage Hugo (gagehugo)
summary: - identity.authenticate CADF initiator id is random
+ CADF identity.authenticate event initiator id is random UUID
Dave Chen (wei-d-chen)
Changed in keystone:
importance: Undecided → Medium
status: New → Confirmed
Gage Hugo (gagehugo)
description: updated
Revision history for this message
Lance Bragstad (lbragstad) wrote :

I was able to recreate this. I didn't verify this with rabbit directly, but I did see the messages logged via python. I used the following configuration in keystone.conf (using devstack):

```
[DEFAULT]
notification_opt_out = ""

[oslo_messaging_notifications]
driver = log
```

I created a token as the administrator:

ubuntu|devstack|keystone >>> openstack --os-cloud devstack-admin token issue
+------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Field | Value |
+------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| expires | 2018-08-01T19:55:52+0000 |
| id | gAAAAABbYgI4DieU2QDc79b6kVTeywh0ifYhQQFforMOSyNOTYL6bWveY7WsqyEYGDYOosBxpF69V89aj0b6ZYiB067KjY0OXVfbSZjohuqW2l6Jkcy-mAq4K8Vp6-6oe_-jcDYeMD0h2wDxd7OwJuIZKl0EXaDgFtzkk_Pt2N4MSJ0uQyIluDk |
| project_id | da1acf5e6e3c4457bc97e332ab23c8f3 |
| user_id | 383d315c51c041cab1411b21989d3f68 |
+------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

The resulting notification in the logs doesn't include the user ID anywhere:

Aug 01 18:55:52 devstack <email address hidden>[14999]: INFO oslo.messaging.notification.identity.authenticate [None req-abce0d65-af48-4a60-9a67-6b39d3590cbc None None] {"event_type": "identity.authenticate", "timestamp": "2018-08-01 18:55:52.897045", "payload": {"typeURI": "http://schemas.dmtf.org/cloud/audit/1.0/event", "initiator": {"typeURI": "service/security/account/user", "host": {"agent": "openstacksdk/0.17.1 keystoneauth1/3.10.0 python-requests/2.19.1 CPython/2.7.15rc1", "address": "192.168.1.202"}, "id": "89d7d8e1-0889-5484-9ea4-21f8a66d2df9"}, "target": {"typeURI": "service/security/account/user", "id": "37c56d47-110c-5c65-bebc-298c85cb75f4"}, "observer": {"typeURI": "service/security", "id": "81f6210c355b49aab537a92c21108df1"}, "eventType": "activity", "eventTime": "2018-08-01T18:55:52.831833+0000", "action": "authenticate", "outcome": "success", "id": "81a27074-5e4d-538d-9fff-dca598a2c73a"}, "priority": "INFO", "publisher_id": "identity.devstack", "message_id": "b381953a-cedc-4392-8226-7c90ef7e2c0c"}

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix merged to keystone (master)

Reviewed: https://review.openstack.org/580780
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=fe5cdc6732fc0102c9e55d45da0bb28c248bebca
Submitter: Zuul
Branch: master

commit fe5cdc6732fc0102c9e55d45da0bb28c248bebca
Author: Gage Hugo <email address hidden>
Date: Fri Jul 6 18:10:23 2018 -0500

    Expose random uuid bug in cadf notifications

    When enabling CADF notifications and clearing the notification_opt_out
    setting[0] (which cause keystone to be more chatty with notifications)
    in order to audit identity.authenticate events, keystone emits a
    notification for the identity.authentication event where the
    initiator's ID is a random UUID that doesn't match up to the user
    who authenticated.

    This was noticed when users would log into horizon and from the audit
    notification, it could not be determined which user was logging in.

    This appears to be true for only the authentication event, other
    events such as project CRUD appear to work as intended.

    [0] https://github.com/openstack/keystone/blob/master/keystone/conf/default.py#L221

    Change-Id: I8363f265faacb9ad5783b12d4a64b570b9af46f0
    Related-Bug: #1780503

Gage Hugo (gagehugo)
description: updated
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to keystone (master)

Fix proposed to branch: master
Review: https://review.openstack.org/588086

Changed in keystone:
status: Confirmed → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to keystone (master)

Reviewed: https://review.openstack.org/588086
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=fd8b5f3206392f210a7240af5b52358791a1df87
Submitter: Zuul
Branch: master

commit fd8b5f3206392f210a7240af5b52358791a1df87
Author: Gage Hugo <email address hidden>
Date: Wed Aug 1 15:49:03 2018 -0500

    Set initiator id as user_id for auth events

    This change sets the initiator id as the user_id for
    authentication events. The notificiation initiator id would
    be set to a random UUID by default, which makes auditing the
    identity of the user who is authenticating difficult. This
    also adds the user_id as well for auth events for consistency.

    Also removes the WIP unit-test header to verify that this
    change works as intended.

    Change-Id: I511a03eada22c66847bd1502b16cbd2c34b1b35d
    Closes-Bug: #1780503

Changed in keystone:
status: In Progress → Fix Released
Changed in keystone:
milestone: none → rocky-rc1
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to keystone (stable/queens)

Fix proposed to branch: stable/queens
Review: https://review.openstack.org/644527

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to keystone (stable/rocky)

Fix proposed to branch: stable/rocky
Review: https://review.openstack.org/644534

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to keystone (stable/queens)

Reviewed: https://review.openstack.org/644527
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=0161ffadd754707768c790e41167860b2e3797b7
Submitter: Zuul
Branch: stable/queens

commit 0161ffadd754707768c790e41167860b2e3797b7
Author: Gage Hugo <email address hidden>
Date: Wed Aug 1 15:49:03 2018 -0500

    Set initiator id as user_id for auth events

    This change sets the initiator id as the user_id for
    authentication events. The notificiation initiator id would
    be set to a random UUID by default, which makes auditing the
    identity of the user who is authenticating difficult. This
    also adds the user_id as well for auth events for consistency.

    Also removes the WIP unit-test header to verify that this
    change works as intended.

    Change-Id: I511a03eada22c66847bd1502b16cbd2c34b1b35d
    Closes-Bug: #1780503
    (cherry picked from commit fd8b5f3206392f210a7240af5b52358791a1df87)

tags: added: in-stable-queens
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to keystone (stable/rocky)

Reviewed: https://review.openstack.org/644534
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=182ff97dc8b094005c6a45c056c222482f664b27
Submitter: Zuul
Branch: stable/rocky

commit 182ff97dc8b094005c6a45c056c222482f664b27
Author: Gage Hugo <email address hidden>
Date: Wed Aug 1 15:49:03 2018 -0500

    Set initiator id as user_id for auth events

    This change sets the initiator id as the user_id for
    authentication events. The notificiation initiator id would
    be set to a random UUID by default, which makes auditing the
    identity of the user who is authenticating difficult. This
    also adds the user_id as well for auth events for consistency.

    Also removes the WIP unit-test header to verify that this
    change works as intended.

    Change-Id: I511a03eada22c66847bd1502b16cbd2c34b1b35d
    Closes-Bug: #1780503
    (cherry picked from commit fd8b5f3206392f210a7240af5b52358791a1df87)

tags: added: in-stable-rocky
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/keystone 15.0.0.0rc1

This issue was fixed in the openstack/keystone 15.0.0.0rc1 release candidate.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/keystone 14.1.0

This issue was fixed in the openstack/keystone 14.1.0 release.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/keystone 13.0.3

This issue was fixed in the openstack/keystone 13.0.3 release.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.