<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN">
<html>
<head>
<meta http-equiv="Content-Type" content="text/xhtml; charset=utf-8">
</head>
<body>
<div style="font-family:sans-serif"><div style="white-space:normal">
<p dir="auto">On 14 May 2017, at 4:04, Sean Dague wrote:</p>
<p dir="auto"></p></div>
<div style="white-space:normal"><blockquote style="border-left:2px solid #777; color:#777; margin:0 0 5px; padding-left:5px"><p dir="auto">One of the things that came up in a logging Forum session is how much effort operators are having to put into reconstructing flows for things like server boot when they go wrong, as every time we jump a service barrier the request-id is reset to something new. The back and forth between Nova / Neutron and Nova / Glance would be definitely well served by this. Especially if this is something that's easy to query in elastic search.<br>
<br>
The last time this came up, some people were concerned that trusting request-id on the wire was concerning to them because it's coming from random users. We're going to assume that's still a concern by some. However, since the last time that came up, we've introduced the concept of "service users", which are a set of higher priv services that we are using to wrap user requests between services so that long running request chains (like image snapshot). We trust these service users enough to keep on trucking even after the user token has expired for this long run operations. We could use this same trust path for request-id chaining.<br>
<br>
So, the basic idea is, services will optionally take an inbound X-OpenStack-Request-ID which will be strongly validated to the format (req-$uuid). They will continue to always generate one as well. When the context is built (which is typically about 3 more steps down the paste pipeline), we'll check that the service user was involved, and if not, reset the request_id to the local generated one. We'll log both the global and local request ids. All of these changes happen in oslo.middleware, oslo.context, oslo.log, and most projects won't need anything to get this infrastructure.<br>
<br>
The python clients, and callers, will then need to be augmented to pass the request-id in on requests. Servers will effectively decide when they want to opt into calling other services this way.<br>
<br>
This only ends up logging the top line global request id as well as the last leaf for each call. This does mean that full tree construction will take more work if you are bouncing through 3 or more servers, but it's a step which I think can be completed this cycle.<br>
<br>
I've got some more detailed notes, but before going through the process of putting this into an oslo spec I wanted more general feedback on it so that any objections we didn't think about yet can be raised before going through the detailed design.<br>
<br>
-Sean<br>
<br>
-- <br>
Sean Dague<br>
<a href="http://dague.net" style="color:#777">http://dague.net</a><br>
<br>
__________________________________________________________________________<br>
OpenStack Development Mailing List (not for usage questions)<br>
Unsubscribe: OpenStack-dev-request@lists.openstack.org?subject:unsubscribe<br>
<a href="http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev" style="color:#777">http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev</a></p>
</blockquote></div>
<div style="white-space:normal">
<p dir="auto">I'm not sure the best place to respond (mailing list or gerrit), so<br>
I'll write this up and post it to both places.</p>
<p dir="auto">I think the idea behind this proposal is great. It has the potential<br>
to bring a lot of benefit to users who are tracing a request across<br>
many different services, in part by making it easy to search in an<br>
indexing system like ELK.</p>
<p dir="auto">The current proposal has some elements that won't work with the way<br>
Swift currently solves this problem. This is mostly due to the<br>
proposed uuid-ish check for validation. However, the Swift solution<br>
has a few aspects that I believe would be very helpful for the entire<br>
community.</p>
<p dir="auto">NB: Swift returns both an <code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0 0.4em" bgcolor="#F7F7F7">X-OpenStack-Request-ID</code> and an <code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0 0.4em" bgcolor="#F7F7F7">X-Trans-ID</code><br>
header in every response. The <code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0 0.4em" bgcolor="#F7F7F7">X-Trans-ID</code> was implemented before the<br>
OpenStack request ID was proposed, and so we've kept the <code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0 0.4em" bgcolor="#F7F7F7">X-Trans-ID</code> so<br>
as not to break existing clients. The value of <code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0 0.4em" bgcolor="#F7F7F7">X-OpenStack-Request-ID</code><br>
in any response from Swift is simply a mirror of the <code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0 0.4em" bgcolor="#F7F7F7">X-Trans-ID</code> value.</p>
<p dir="auto">The request id in Swift is made up of a few parts:</p>
<pre style="background-color:#F7F7F7; border-radius:5px 5px 5px 5px; margin-left:15px; margin-right:15px; max-width:90vw; overflow-x:auto; padding:5px" bgcolor="#F7F7F7"><code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0" bgcolor="#F7F7F7">X-Openstack-Request-Id: txbea0071df2b0465082501-00591b3077saio-extraextra
</code></pre>
<p dir="auto">In the code, this in generated from:</p>
<pre style="background-color:#F7F7F7; border-radius:5px 5px 5px 5px; margin-left:15px; margin-right:15px; max-width:90vw; overflow-x:auto; padding:5px" bgcolor="#F7F7F7"><code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0" bgcolor="#F7F7F7">'tx%s-%010x%s' % (uuid.uuid4().hex[:21], time.time(), quote(trans_id_suffix))
</code></pre>
<p dir="auto">...meaning that there are three parts to the request id. Let's take<br>
each in turn.</p>
<p dir="auto">The first part always starts with 'tx' (originally from the<br>
"transaction id") and then is the first 21 hex characters of a uuid4.<br>
The truncation is to limit the overall length of the value.</p>
<p dir="auto">The second part is the hex value of the current time, padded to 10<br>
characters.</p>
<p dir="auto">Finally, the third part is the quoted suffix, and it defaults to the<br>
empty string. The suffix itself can be made of two parts. The first is<br>
configured in the Swift proxy server itself (ie the service that does<br>
the logging) via the <code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0 0.4em" bgcolor="#F7F7F7">trans_id_suffix</code> config. This allows an operator<br>
to set a different suffix for each API endpoint or each region or each<br>
cluster in order to help distinguish them in logs. For example, if a<br>
deployment with multiple clusters uses centralized log aggregation, a<br>
different trans_id_suffix value for each cluster makes it very easy to<br>
distinguish between the clusters' logs.</p>
<p dir="auto">The last part of the suffix is settable via the end-user (ie the one<br>
calling the API). When the "X-Trans-ID-Extra" header in a request,<br>
it's value is quoted and appended to the final transaction id value.</p>
<p dir="auto">Here's a curl example that shows this all put together. You can see<br>
that I have my Swift-All-In-One dev environment configured to use the<br>
"saio" value for the <code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0 0.4em" bgcolor="#F7F7F7">trans_id_suffix</code> value:</p>
<pre style="background-color:#F7F7F7; border-radius:5px 5px 5px 5px; margin-left:15px; margin-right:15px; max-width:90vw; overflow-x:auto; padding:5px" bgcolor="#F7F7F7"><code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0" bgcolor="#F7F7F7">$ curl -i -H "X-Auth-Token: AUTH_tk1bab51ce5e1d4e2bb6c54bccf59433ee" http://saio:8080/v1/AUTH_test/c/o --data-binary 1234 -XPUT -H "x-trans-id-extra: extraextra"
HTTP/1.1 201 Created
Last-Modified: Tue, 16 May 2017 17:04:17 GMT
Content-Length: 0
Etag: 81dc9bdb52d04dc20036dbd8313ed055
Content-Type: text/html; charset=UTF-8
X-Trans-Id: txf766cc02859c450eb4aef-00591b3110saio-extraextra
X-Openstack-Request-Id: txf766cc02859c450eb4aef-00591b3110saio-extraextra
Date: Tue, 16 May 2017 17:04:16 GMT
$
$ curl -i -H "X-Auth-Token: AUTH_tk1bab51ce5e1d4e2bb6c54bccf59433ee" http://saio:8080/v1/AUTH_test/c/o -H "x-trans-id-extra: moredifferentextra"
HTTP/1.1 200 OK
Content-Length: 4
Accept-Ranges: bytes
Last-Modified: Tue, 16 May 2017 17:04:17 GMT
Etag: 81dc9bdb52d04dc20036dbd8313ed055
X-Timestamp: 1494954256.25977
Content-Type: application/x-www-form-urlencoded
X-Trans-Id: tx4013173098b348b6b7952-00591b34d2saio-moredifferentextra
X-Openstack-Request-Id: tx4013173098b348b6b7952-00591b34d2saio-moredifferentextra
Date: Tue, 16 May 2017 17:20:18 GMT
1234
$ curl -i -H "X-Auth-Token: AUTH_tk1bab51ce5e1d4e2bb6c54bccf59433ee" http://saio:8080/v1/AUTH_test/c/o
HTTP/1.1 200 OK
Content-Length: 4
Accept-Ranges: bytes
Last-Modified: Tue, 16 May 2017 17:04:17 GMT
Etag: 81dc9bdb52d04dc20036dbd8313ed055
X-Timestamp: 1494954256.25977
Content-Type: application/x-www-form-urlencoded
X-Trans-Id: txf66856a06d7547c4ad79d-00591b3527saio
X-Openstack-Request-Id: txf66856a06d7547c4ad79d-00591b3527saio
Date: Tue, 16 May 2017 17:21:43 GMT
1234
</code></pre>
<p dir="auto">The <code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0 0.4em" bgcolor="#F7F7F7">X-Trans-ID-Extra</code> header, specifically, sounds very similar to<br>
what is being proposed to solve the cross-project reuqest IDs. To<br>
quote from the commit in Swift that added this:</p>
<pre style="background-color:#F7F7F7; border-radius:5px 5px 5px 5px; margin-left:15px; margin-right:15px; max-width:90vw; overflow-x:auto; padding:5px" bgcolor="#F7F7F7"><code style="background-color:#F7F7F7; border-radius:3px; margin:0; padding:0" bgcolor="#F7F7F7">The value of the X-Trans-Id-Extra header on the request (if any) will
now be appended to the transaction ID. This lets users put their own
information into transaction IDs.
For example, Glance folks upload images as large objects, so they'd
like to be able to tie together all the segment PUTs and the manifest
PUT with some operation ID in the logs. This would let them pass in
that operation ID as X-Trans-Id-Extra, and then when things went
wrong, it'd be much easier to find all the requests in Swift's logs.
Also, this aids debuggability when requests fail to receive
responses. If a user is sending in their own X-Trans-Id-Extra strings,
then that gives operators something to search for in the logs. The
normal txid won't work since that's in the response, but the client
didn't receive one.
Swift will only use the first 32 characters of X-Trans-Id-Extra so
that its log lines stay a manageable length. Also, it's URL-quoted so
that users cannot inject double quotes into X-Trans-Id-Extra and screw
up log parsers.
</code></pre>
<p dir="auto">I hope this information helps move the conversation around cross-<br>
project reuqest IDs forward. I believe that Swift's current solution<br>
and pattern would work very well for other OpenStack projects.</p>
</div>
</div>
</body>
</html>