Generate a local UUID for requests with a parent UUID for debug purposes

[pmvilaca]

At the moment, if service A needs to make 2 independent calls to service B, according the best-practices, service A should pass the UUID to service B.

That is useful to identify a global transaction but isn't so useful if we need to identify a single request. We can track the requests looking at the logs, timestamps, ... but that could be a problem if we have alerts based on that field.

[eswdd]

There was a suggestion a year ago that we derive new request uuids from passed in ones, such that they become unique but it is still possible to search on the parent. the intention was to append to the string of the parent uuid, but that could conceivably be considered to be an implementation choice of this request.

[pmvilaca]

I think that it's better to generate a new uuid and log that as a new field
instead of appending something to the original uuid.. That would force us
to apply a regex to extract the original uuid.

On Tuesday, January 7, 2014, Simon Matic Langford wrote:

There was a suggestion a year ago that we derive new request uuids from
passed in ones, such that they become unique but it is still possible to
search on the parent. the intention was to append to the string of the
parent uuid, but that could conceivably be considered to be an
implementation choice of this request.

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/60#issuecomment-31778529
.

[eswdd]

Won't you have to use regex or some other configuration to extract the uuid anyway?

If we introduce a seperate uuid, then bear in mind that that will only be logged in one place alongside the parent (likely the request log since it's common to all transports). From the PoV of something like Zipkin which is automagically stitching things together and grabbing all available data this is simple, for a human you will always need to join across this single log to trace something, making scripts more complex.

The appending mechanism is actually quite an elegant solution since it helps in a number of styles of usage:

• Want to trace what requests a service/client made because it was slow: just grep for the parent uuid in all logs
• Want to find the source of a request from the access log: just decompose the uuid and grep in the logs to find the parent request.

It's also not dissimilar to a mechanism we have in tracing events through the system - perhaps we should/could consider joining them. If we change the appending style from what I'd originally considered, namely just appending -1, -2, -3 to the current uuid when making a request, to including the hostname like we do for new uuids, then we know the exact location of the source (at least where it's something sharing the uuid scheme - and if it's not at least it will look different).

[pmvilaca]

Fair enough.. But I don't know how could we append the -1, -2, -... in the client side. Most of the times, there are requests to the same endpoints in parallel.

[eswdd]

And yet they all get passed the same RequestUUID - I see 2 choices here:

1. Add a method to the request uuid to get a child one which uses an internal atomic integer or long
2. Make the code create the sub-Requests prior to passing in to the cougar client - more code complexity but more control maybe?

[pmvilaca]

1. We can do that in the code that sends the requests to other services
   (cougar client), assuming that original context is being used for those
   requests but that isn't valid for requests from the sites (I'm talking
   about Mantis). Those requests are creating ExecutionContext instances based
   using the UUID (already generated). Just to clarify.. With this option, you
   are suggesting that we invoke a method before sending the requests just to
   increment the number of the request (-1, -2, -...), right?
2. I'm not sure about what you are trying to say.. Could you elaborate?

2014/1/8 Simon Matic Langford notifications@github.com

And yet they all get passed the same RequestUUID - I see 2 choices here:

1. Add a method to the request uuid to get a child one which uses an
   internal atomic integer or long
2. Make the code create the sub-Requests prior to passing in to the cougar
   client - more code complexity but more control maybe?

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/60#issuecomment-31877938
.

[eswdd]

I think you got the jist of it in 1.. the 2 choices here weren't really choices on re-reading, just different parts of the same thing.

I do think we should follow my suggestion to add the host as well as the -1, -2, but only if the uuid that we're creating from is not generated by this host (because there's wasn't one on the request).

e.g. I'm making a new request on host abc001:

• if i received a request with no uuid on it then the uuid will be of the form abc001-xxxxxxxx-yyyy in which case new uuids should be of the form abc001-xxxxxxxx-yyyy-1, abc001-xxxxxxxx-yyyy-2 etc
• if i received a request with a uuid (e.g. xyz001-xxxxxxx-yyyy), then I should also append my host: xyz001-xxxxxxx-yyyy-abc001-1, xyz001-xxxxxxx-yyyy-abc001-2

[pmvilaca]

Sounds like a plan.. :)
+1

[eswdd]

So I started looking at this this morning and there are some probs..

1. Any change in what we send as uuid to legacy servers is going to hit the regexp limiting uuids to 20-50 characters, which is irritating.
2. If we keep chaining info together, we're going to hit massive uuids within a few hops, and at some point we need to set a sensible limit.

Suggested solutions:
2. We can meet the various requirements by having a triple component uuid, namely "root:parent:mine" which then allows us to set a sensible limit of (say) 150 characters.

1. We can add some settings to our various clients which allow us to disable sending the root and parent component part uuids, which can be set until we know that servers have been upgraded.

[eswdd]

I wonder if the extended uuid should be sent in a new header alongside the legacy one, so that we don't have to have a config option - will have to consider impact on binary client..

[pmvilaca]

Thinking about the 2nd suggested solution, in fact, it's what we need for
the zipkin implementation. If we decide to follow that approach half of the
things needed to the zipkin integration will be implemented.

Just to clarify the origin of this issue.. I think that it was created
after an internal discussion in betfair to define if the "Service A" should
pass the same UUID to the "Service B" when it needs to invoke the service B
multiple times in the same transaction. And the team that is responsible
for the "Service B" doesn't want that the same UUID is used because there
is a reporting tool based on the logs that assumes that one UUID represents
only one transaction.

So, maybe we can implemented this issue and solve the debug problem and at
the same time, make some progress for the zipkin adoption in cougar. What
do you think?

2014-07-02 11:56 GMT+01:00 Simon Matic Langford notifications@github.com:

I wonder if the extended uuid should be sent in a new header alongside the
legacy one, so that we don't have to have a config option - will have to
consider impact on binary client..

—
Reply to this email directly or view it on GitHub
#60 (comment).

[eswdd]

That is precisely why I'm working on this now ;) Also hence the comments regarding the need for ExecutionContext changes for Zipkin integration. The only thing that seems a little rough around the edges is how to ensure the client doesn't send out the same uuid for multiple calls - at the moment it's up to the developer to pass a sub-uuid to the client when constructing the execution context..

[pmvilaca]

I think that we can delegate the generation of the sub-uuid to the cougar
client. That way the developer should pass an ExecutionContext with the
root uuid and with the current uuid and every time that it makes a call to
the another cougar service using the cougar client, the client will pick
the 2 original values and add a new one.

After that, when a cougar service receives call with the 3 values
(root:parent:mine) it means that it's receiving a call that belongs to a
on-going span.

Using this approach, the UUID that should be logged to represent the
current implementation is the root uuid, and we can use the other fields to
correlate the calls between the services and also for zipkin.

This is a little bit difficult to explain by email, but I hope that you can
understand my idea :)

2014-07-02 14:32 GMT+01:00 Simon Matic Langford notifications@github.com:

That is precisely why I'm working on this now ;) Also hence the comments
regarding the need for ExecutionContext changes for Zipkin integration. The
only thing that seems a little rough around the edges is how to ensure the
client doesn't send out the same uuid for multiple calls - at the moment
it's up to the developer to pass a sub-uuid to the client when constructing
the execution context..

—
Reply to this email directly or view it on GitHub
#60 (comment).

[eswdd]

All understood, it's exactly what i was thinking, except i think we want to log the full compound uuid in all cases, and the zipkin log parsing can extract the bits it needs from that field and humans still get to see the full uuid (it also means no breaking change to the log format).

With regard to delegating to the client, it seems the preferred approach, but I only wonder if this could cause probs where existing apps already pass in a new generated request uuid. However I wonder if we can detect and deal with this. I will think some more on the situations which could be problematic.

[pmvilaca]

When I was investigating how we could integrate zipkin in cougar, I wasn't planing to use log files because I think that we don't really need it. At least in Betfair, they're using 0MQ to emit metrics to their own metrics aggregator system (something like statsd). So, I was planning to emit zipkin events to 0MQ and then use that system to pick those events and send them to the zipkin collector.

Regarding your concern, you're talking about the cases where the developers are creating a new ExecutionContext object and setting the UUID of that ExecutionContext? Sorry if it doesn't make sense but my memory isn't fresh enough to remember those "strange" situations. Could you post some snippets of code (if you've some)?

[eswdd]

The metrics aggregator system is called statse and whilst a client has been released and it is integrated into Cougar via Tornjak it's now 8 months down the line and the server has not been released, hence the feature raised to integrate statsd into Tornjak.

My concern on using 0MQ to integrate Cougar with Zipkin would be as to whether the other end of 0MQ (the collection daemon) would also be released in any sensible timescales. So it may well be that #59 is the shared abstraction and the Zipkin integration for Cougar use something off the shelf and already available (for example Brave's Zipkin Span Collector. It rather depends on Betfair's capacity/appetite for open sourcing more components.

I would still emit the full uuid in the log files to support the other usecases surrounding uuids.

Regarding my concern - it's rubbish, I realised that now, so ignore me on that.

[atropineal]

If by chance you're talking about Cougar applications that receive a
request with one UUID and then contact other services using a totally new
requestUUID, then I've seen that happening many times. In my experience of
reviewing Cougar applications it's actually the norm. Makes
troubleshooting across apps a real pain. :-)

On Wed, Jul 2, 2014 at 8:16 PM, Simon Matic Langford <
notifications@github.com> wrote:

The metrics aggregator system is called statse and whilst a client has
been released and it is integrated into Cougar via Tornjak
https://github.com/betfair/tornjak it's now 8 months down the line and
the server has not been released, hence the feature raised to integrate
statsd into Tornjak.

My concern on using 0MQ to integrate Cougar with Zipkin would be as to
whether the other end of 0MQ (the collection daemon) would also be release
in any sensible timescales. So it may well be that #59
#59 is the shared abstraction
and the Zipkin integration for Cougar use something off the shelf and
already available (for example Brave's Zipkin Span Collector
https://github.com/kristofa/brave/tree/master/brave-zipkin-spancollector.
It rather depends on Betfair's capacity/appetite for open sourcing more
components.

I would still emit the full uuid in the log files to support the other
usecases surrounding uuids.

Regarding my concern - it's rubbish, I realised that now, so ignore me on
that.

—
Reply to this email directly or view it on GitHub
#60 (comment).

[eswdd]

Ah, I'd rather assumed it wasn't. I think with the changes we're suggesting, that would be no worse, and if tracing across distributed calls was desirable then perhaps service owners could be persuaded to fix their apps - especially if all they need to do is pass the RequestUUID from the EC passed into the service code into the client calls. I suspect in most cases this is a case of people not realising the benefits they can achieve by just passing this item on.

[richardqd]

I'd have thought people were self-motivated to fix this, given the
additional grief it adds to their support burden!

On 2 July 2014 20:23, Simon Matic Langford notifications@github.com wrote:

Ah, I'd rather assumed it wasn't. I think with the changes we're
suggesting, that would be no worse, and if tracing across distributed calls
was desirable then perhaps service owners could be persuaded to fix their
apps - especially if all they need to do is pass the RequestUUID from the
EC passed into the service code into the client calls. I suspect in most
cases this is a case of people not realising the benefits they can achieve
by just passing this item on.

—
Reply to this email directly or view it on GitHub
#60 (comment).

[atropineal]

I think, in the applications I've seen, it was often the case that by the
time one service impl was calling out to another, the initial
RequestContext had been forgotten - having been lost in that popular layer
which translates between the Cougar and an internal domain. Folks, perhaps
forgivably (especially if they do not have experience of troubleshooting
across services), forget about passing on the stuff in the RC like like the
UUID unless they simply cannot fulfill their functionality without it (e.g.
a user or cert name for audit or whatever).

Another case I seem to remember was where a popular internal service
distributed their own library to client services, but where that client
library did not expose any way to set the outgoing request's UUID. The
library just exposed a plain interface that knew nothing about Cougar at
all, and the necessary Cougar stuff was done 'behind the scenes'.

On Wed, Jul 2, 2014 at 8:39 PM, richardqd notifications@github.com wrote:

I'd have thought people were self-motivated to fix this, given the
additional grief it adds to their support burden!

On 2 July 2014 20:23, Simon Matic Langford notifications@github.com
wrote:

Ah, I'd rather assumed it wasn't. I think with the changes we're
suggesting, that would be no worse, and if tracing across distributed
calls
was desirable then perhaps service owners could be persuaded to fix
their
apps - especially if all they need to do is pass the RequestUUID from
the
EC passed into the service code into the client calls. I suspect in most
cases this is a case of people not realising the benefits they can
achieve
by just passing this item on.

—
Reply to this email directly or view it on GitHub
#60 (comment).

—
Reply to this email directly or view it on GitHub
#60 (comment).

[eswdd]

The distributed client library of course comes with it's own issues, like generated code incompatibility with different Cougar versions, but the first is the situation I had imagined originally.

[eswdd]

Can anyone think of a better mechanism for ensuring backwards compatibility (new clients talking to old servers) when introducing this? So far I have 2 ideas, I think I prefer the second:

1. Add a new header X-UUID2 and send the old format in X-UUID and the new in X-UUID2
2. Break out the root:parent component and put in X-UUID-Parents (or similar) and send the local component in X-UUID

[atropineal]

I've just realized that Pedro has earlier said:

"this issue.. was created after an internal discussion in betfair to define
if the "Service A" should pass the same UUID to the "Service B" if it needs
to invoke the service B multiple times in the same transaction. And the
team that is responsible for the "Service B" doesn't want that the same
UUID is used because there is a reporting tool based on the logs that
assumes that one UUID represents only one transaction".

That was me representing service B. I definitely did not want multiple
requests coming in with the same UUID. Sort of violated (for me at least!)
the concept of a 'request identifier' since I then wouldn't be able to
identify a specific actual request with it any more, only a logical one
that could be made up of any number of actual requests. From my
perspective this negatively impacted several non-functionals:
troubleshooting / tooling / log mining... I encouraged them to adopt a
UUID-suffix style approach, ('-1', '-2' or whatever), especially since in
this case the multiple requests were serial in nature.

I'd even be in favor of an inbuilt mechanism that actively tries to prevent
duplicate request UUIDs, since somebody can 'break me' (non-functionally,
in the ways above) quite easily without really knowing the impact. For
example a generated Cougar client could remember UUIDs going to the target
service within a time and/or size limited window and reject duplicates?
I'm just brainstorming here.

Another thing I'm not keen on regarding UUIDs is that people can use
whatever they like. I massively appreciate UUIDs having the abbreviated
client node name as a prefix, it really is a boon for investigation speed.
But unfortunately some clients decide for whatever reason that this isn't
for them, and they'll transmit some custom gibberish. Or they'll transmit
something that has a prefix that looks like it's a node name but isn't.
I'm in favor of making sure all outgoing request UUIDs are standardized,
with this prefix being part of the standard.

Simon, idea 2 sounds better to me because it doesn't create an 'old way vs
new way' type situation, it just augments what is there. No 'OK, now we do
everything 2 ways until we migrate totally' type affair.

On Wed, Jul 2, 2014 at 9:07 PM, Simon Matic Langford <
notifications@github.com> wrote:

Can anyone think of a better mechanism for ensuring backwards
compatibility (new clients talking to old servers) when introducing this?
So far I have 2 ideas, I think I prefer the second:

1. Add a new header X-UUID2 and send the old format in X-UUID and the new
   in X-UUID2
2. Break out the root:parent component and put in X-Tracing-Info (or
   similar) and send the local component in X-UUID

—
Reply to this email directly or view it on GitHub
#60 (comment).

[eswdd]

I'd wondered about client 'memory' to try to resolve that issue, although if we change the clients so they always generate a sub this wouldn't have much effect. It also doesn't deal with clients which are not using cougar generated clients.

The UUID naming I totally agree on, although is hampered by the ability to plugin a custom generator which seems valid if you wish some form of service identifier but your hostname is not sufficient. I wonder if it's valid for a server to reject a client uuid or regenerate part of it if it disagrees with the formatting? Probably not, this sounds like a governance issue to me although I definitely agree with the sentiment.

[andredasilvapinto]

From a Zipkin point of view, considering it follows Google's Dapper paper we will need to support not 2 but 3 data fields (headers in the case of HTTP):

• TraceId
• SpanId
• ParentSpanId (when applicable)

These fields should all be probabilistically unique 64 bits integers (i.e. longs), which would imply a conflict with the current X-UUID format. This would be especially problematic if we use something like Brave (like was referred above) as its API is expecting longs, but depending on whether Zipkin collector/query/web components introduce this format contraint it might be even impossible to use any other format. I think using hash functions here in order to convert the UUID string format to a long would imply unnecessary work per request/span and defeat the purpose of using the entire 64 bits range.

I would suggest we add those 3 new fields to the transports while keeping the current X-UUID field format for backward compatibility.

[eswdd]

Is there a suggested mechanism that makes them probabilistically unique enough?

Seems odd to restrict the ids to longs when it’s relatively easy to generate GUIDs if you allow strings. I’d almost argue that’s rather a large failing, but I’m sure they have their reasons.

Frustratingly, I’d rather assumed strings were ok, should have read the docs better. Given the amount of work we do everywhere else, hashing might not be unreasonable and would allow dual use of the X-UUID data..

On 3 Jul 2014, at 00:07, André Pinto notifications@github.com wrote:

From a Zipkin point of view, considering it follow Google's Dapper paper we will need to support not 2 but 3 data fields (headers in the case of HTTP):

TraceId
SpanId
ParentSpanId (when applicable)
These fields should all be probabilistically unique 64 bits integers (i.e. longs), which would imply a conflict with the current X-UUID format. This would be especially problematic if we use something like Brave (like was referred above) as its API is expecting longs, not strings and I think using hash functions here would imply unnecessary work per request/span and defeat the purpose of using the entire 64 bits range.

I would suggest we add those 3 new fields to the transports while keeping the current X-UUID field format for backward compatibility.

—
Reply to this email directly or view it on GitHub.

[andredasilvapinto]

On Dapper's paper? No.

I'm using ThreadLocalRandom.nextLong(Long.MIN_VALUE, Long.MAX_VALUE) (Java 7+) in Mantis in order to avoid contention. Pedro Vilaça also suggested the use of UUID.getMostSignificantBits() although I think that would probably be a little more expensive (haven't tested though).

[eswdd]

Can it handle clashes if they do occur? I can't find any reference in the docs.

[andredasilvapinto]

Are you referring to Zipkin ids clashes? I think they don't do any magic here. If you have duplicated trace ids (which is very unlikely with a uniform probabilistic function over a 64 bit range - 5.4210109e-20 probability) then it will probably override the old one:

We generate a random trace ID to use (a 64-bit int in hex) which we can do because it's very unlikely that we'll have trace ID collisions (and it's not a big deal if we do -- some other trace will get overwritten).

From a browser extension plugin but still on the twitter/zipkin repo:
https://github.com/twitter/zipkin/blob/master/zipkin-browser-extension/firefox/CONTRIBUTING.md

[eswdd]

ok, cool thanks. Am going to explore hashing a little to see if there's any legs there in terms of low duplicate rates and full use of the 64bit spectrum, otherwise will consider fleshing out the isTracingEnabled on ExecutionContext into a TracingInfo interface which contains the isTracingEnabled and enables tracing plugins to hook in the data they need.

[eswdd]

So was thinking on this some more overnight...

This feature request sits on it's own if you ignore the Zipkin/tracing requirements for the purposes of debugging, and so we should continue to make the changes on the basis I was already working.

It would be nice to be able to leverage this for Zipkin/tracing, but not mandatory. If Zipkin needs the same info but in a different format, and is unable to derive it from this info (ie hashing doesn't work) then I think it's reasonable to state that the Zipkin ids are also request uuids, just a different format of them and thus it's reasonable for the Zipkin integration to provide a RequestUUID impl which provides the standard Cougar uuids as well as those required for Zipkin. Then we do not need changes to the EC interface (which as @richardqd says is painful) and we only then need to provide the tracing hooks in the client and transports.

This also suggests that the header name I proposed is sensible and if we need extra info for tracing we can use an appropriate seperate header such as X-Trace-Info

[andredasilvapinto]

Hashing would also imply that every non-Cougar node of the ecosystem would have to be aware of the way Cougar's hash function works as they need to pass and receive the fields to/from them.

[eswdd]

Yes it would. It would have to be a well published algorithm. I appreciate
this would not be desirable in a mixed ecosystem.

On 4 July 2014 09:06, André Pinto notifications@github.com wrote:

Hashing would also imply that every non-Cougar node of the ecosystem would
have to be aware of the way Cougar's hash function works as they need to
pass and receive the fields to/from them.

—
Reply to this email directly or view it on GitHub
#60 (comment).

[andredasilvapinto]

ThreadLocalRandom.nextLong(Long.MIN_VALUE, Long.MAX_VALUE) is not an option.

Looking at the method definition, and considering it refers no restriction on the documentation, I thought it would allow the entire long range, but after testing and looking at the implementation you can see that it only allows 32 bit range as the kind of operations it performs internally introduce overflow problems for larger ranges.

I'm now using Vilaça's suggestion

UUID.randomUUID().get[Least|Most]SignificantBits().

[eswdd]

This issue is now complete. Any further discussion regarding zipkin or tracing should occur on the appropriate issues.