Open Stack

On 05/16/2017 01:28 PM, John Dickinson wrote:
<snip>
> I'm not sure the best place to respond (mailing list or gerrit), so
> I'll write this up and post it to both places.
> 
> I think the idea behind this proposal is great. It has the potential
> to bring a lot of benefit to users who are tracing a request across
> many different services, in part by making it easy to search in an
> indexing system like ELK.
> 
> The current proposal has some elements that won't work with the way
> Swift currently solves this problem. This is mostly due to the
> proposed uuid-ish check for validation. However, the Swift solution
> has a few aspects that I believe would be very helpful for the entire
> community.
> 
> NB: Swift returns both an |X-OpenStack-Request-ID| and an |X-Trans-ID|
> header in every response. The |X-Trans-ID| was implemented before the
> OpenStack request ID was proposed, and so we've kept the |X-Trans-ID| so
> as not to break existing clients. The value of |X-OpenStack-Request-ID|
> in any response from Swift is simply a mirror of the |X-Trans-ID| value.
> 
> The request id in Swift is made up of a few parts:
> 
> |X-Openstack-Request-Id: txbea0071df2b0465082501-00591b3077saio-extraextra |
> 
> In the code, this in generated from:
> 
> |'tx%s-%010x%s' % (uuid.uuid4().hex[:21], time.time(),
> quote(trans_id_suffix)) |
> 
> ...meaning that there are three parts to the request id. Let's take
> each in turn.
> 
> The first part always starts with 'tx' (originally from the
> "transaction id") and then is the first 21 hex characters of a uuid4.
> The truncation is to limit the overall length of the value.
> 
> The second part is the hex value of the current time, padded to 10
> characters.
> 
> Finally, the third part is the quoted suffix, and it defaults to the
> empty string. The suffix itself can be made of two parts. The first is
> configured in the Swift proxy server itself (ie the service that does
> the logging) via the |trans_id_suffix| config. This allows an operator
> to set a different suffix for each API endpoint or each region or each
> cluster in order to help distinguish them in logs. For example, if a
> deployment with multiple clusters uses centralized log aggregation, a
> different trans_id_suffix value for each cluster makes it very easy to
> distinguish between the clusters' logs.
> 
> The last part of the suffix is settable via the end-user (ie the one
> calling the API). When the "X-Trans-ID-Extra" header in a request,
> it's value is quoted and appended to the final transaction id value.
> 
> Here's a curl example that shows this all put together. You can see
> that I have my Swift-All-In-One dev environment configured to use the
> "saio" value for the |trans_id_suffix| value:
> 
> |$ 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 |
> 
> The |X-Trans-ID-Extra| header, specifically, sounds very similar to
> what is being proposed to solve the cross-project reuqest IDs. To
> quote from the commit in Swift that added this:
> 
> |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. |
> 
> I hope this information helps move the conversation around cross-
> project reuqest IDs forward. I believe that Swift's current solution
> and pattern would work very well for other OpenStack projects.

Thanks for the write up John. One of the swift devs also gave me a quick
intro to that at the end of the session there. I also find it
interesting that time is encoded in the id (though only second
resolution), is that because of rsyslog skew issues?

Given the existing oslo infrastructure (request_id middleware, context,
log), I see a pretty clear path forward on the dual values. It also is
valuable that these will be separate structures in memory so when they
are exposed through structured logging like fluentd or json, there is no
guessing on the parts in question. Heuristic parsing is definitely a
thing we're trying to get away from.

Because the validation point is going to be in a single area of oslo
middleware, if swift was migrating over to olso, it would be easy enough
to accommodate changing the validation criteria.

	-Sean

-- 
Sean Dague
http://dague.net