yahoo-eng-team team mailing list archive

[Markus Hentsch <1886657@xxxxxxxxxxxxxxxxxx>]

Public bug reported:

This is about the Global Request ID functionality of OpenStack [1].

While observing the Glance log file, I noticed Glance always logging
the global_request_id instead of a local one if it is available,
erroneously displaying the global ID as if it was a local ID.


# Technical summary

Using "%(global_request_id)s" within "logging_context_format_string" [2]
in the glance-api.conf will always print "None" in the logs whereas
"%(request_id)s" will either be an ID generated by Glance if no global
ID is available or the received global ID.

Culprit seems to be the context middleware of Glance where the global
ID in form of the "X-Openstack-Request-Id" header is parsed from the
request and passed as "request_id" instead of "global_request_id" to
the "glance.context.RequestContext.from_environ()" call [3].

This is in contrast to other services such as Nova or Neutron where
the two variables actually print the values according to their name
(request_id always being the local one, whereas global_request_id is
the global one or None).


# Proposed solution

The parsed header value should be passed as "global_request_id" to
the RequestContext call's kwargs in the code path referenced above.


# How to reproduce

1. Set the following setting in the Glance API configuration:

logging_context_format_string = %(levelname)s %(name)s [%(request_id)s |
%(global_request_id)s %(user_identity)s] %(instance)s%(message)s

2. Observe the Glance API log while making requests without specifying
   a global request id:

export OS_TOKEN=...
export GLANCE_ADDR=...
curl -g -i -X GET "http://$GLANCE_ADDR:9292/v2/images"; -H "X-Auth-Token: $OS_TOKEN"

3. Observe the Glance API log while making requests while explicitly
   specifying a global request id using the "X-Openstack-Request-Id"
   header:

export OS_TOKEN=...
export GLOBAL_ID=1593a32f-0912-49df-994d-5992c8a2a0c4
export GLANCE_ADDR=...
curl -g -i -X GET "http://$GLANCE_ADDR:9292/v2/images"; -H "X-Auth-Token: $OS_TOKEN" -H "X-Openstack-Request-Id: $GLOBAL_ID"

For step 2, you will see that %(request_id)s changes between requests,
whereas %(global_request_id)s is None. This correct behavior and
identical to other OpenStack API services.

For step 3, you will see that %(request_id)s is actually replaced by
the passed global ID, while %(global_request_id)s is still None. This
is an error since the former should still be a local ID whereas the
latter should display the passed global ID header content instead.


# Link references

[1] https://specs.openstack.org/openstack/oslo-specs/specs/pike/global-req-id.html
[2] https://docs.openstack.org/oslo.context/2.17.0/user/usage.html#context-variables
[3] https://github.com/openstack/glance/blob/e6db0b10a703037f754007bef6f56451086850cd/glance/api/middleware/context.py#L201

** Affects: glance
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to Glance.
https://bugs.launchpad.net/bugs/1886657

Title:
  Global request ID erroneously interpreted as local ID

Status in Glance:
  New

Bug description:
  This is about the Global Request ID functionality of OpenStack [1].

  While observing the Glance log file, I noticed Glance always logging
  the global_request_id instead of a local one if it is available,
  erroneously displaying the global ID as if it was a local ID.

  
  # Technical summary

  Using "%(global_request_id)s" within "logging_context_format_string" [2]
  in the glance-api.conf will always print "None" in the logs whereas
  "%(request_id)s" will either be an ID generated by Glance if no global
  ID is available or the received global ID.

  Culprit seems to be the context middleware of Glance where the global
  ID in form of the "X-Openstack-Request-Id" header is parsed from the
  request and passed as "request_id" instead of "global_request_id" to
  the "glance.context.RequestContext.from_environ()" call [3].

  This is in contrast to other services such as Nova or Neutron where
  the two variables actually print the values according to their name
  (request_id always being the local one, whereas global_request_id is
  the global one or None).

  
  # Proposed solution

  The parsed header value should be passed as "global_request_id" to
  the RequestContext call's kwargs in the code path referenced above.

  
  # How to reproduce

  1. Set the following setting in the Glance API configuration:

  logging_context_format_string = %(levelname)s %(name)s [%(request_id)s
  | %(global_request_id)s %(user_identity)s] %(instance)s%(message)s

  2. Observe the Glance API log while making requests without specifying
     a global request id:

  export OS_TOKEN=...
  export GLANCE_ADDR=...
  curl -g -i -X GET "http://$GLANCE_ADDR:9292/v2/images"; -H "X-Auth-Token: $OS_TOKEN"

  3. Observe the Glance API log while making requests while explicitly
     specifying a global request id using the "X-Openstack-Request-Id"
     header:

  export OS_TOKEN=...
  export GLOBAL_ID=1593a32f-0912-49df-994d-5992c8a2a0c4
  export GLANCE_ADDR=...
  curl -g -i -X GET "http://$GLANCE_ADDR:9292/v2/images"; -H "X-Auth-Token: $OS_TOKEN" -H "X-Openstack-Request-Id: $GLOBAL_ID"

  For step 2, you will see that %(request_id)s changes between requests,
  whereas %(global_request_id)s is None. This correct behavior and
  identical to other OpenStack API services.

  For step 3, you will see that %(request_id)s is actually replaced by
  the passed global ID, while %(global_request_id)s is still None. This
  is an error since the former should still be a local ID whereas the
  latter should display the passed global ID header content instead.

  
  # Link references

  [1] https://specs.openstack.org/openstack/oslo-specs/specs/pike/global-req-id.html
  [2] https://docs.openstack.org/oslo.context/2.17.0/user/usage.html#context-variables
  [3] https://github.com/openstack/glance/blob/e6db0b10a703037f754007bef6f56451086850cd/glance/api/middleware/context.py#L201

To manage notifications about this bug go to:
https://bugs.launchpad.net/glance/+bug/1886657/+subscriptions