What should be the final outcome of service-to-service correlation tracking

fgheysels commented 2 years ago

When running the PoC, we currently have this end-to-end transaction overview:

In the PoC, we're already close to the desired end-result, but we're just not there yet.

In the above image, we can distinguish 2 major blocks:

the brown rectangle contains the requests & dependencies that are triggered by calling the Create Order operation on the Market API:
- The Create Order operation calls the GET bacon operation of the Bacon API, we can see the dependency being logged by the Market API
- We also see the Request being logged by the Bacon API.
- We can see that the Bacon API has a dependency on a SQL Server (example-server)
- The Market API posts a message on a service-bus; we can also see that dependency to the Orders queue on arcus-s2s-bus

Now, I think there are still some issues in this visual representation:

The dependency to the bacon API should imo be indented one level and should be 'linked' to the initial request that represents the Create Order operation of the Market API. (The first line in the overview). IMO, this must be done because that dependency is initiated / tied to the Create Order operation.
The call to the example-server SQL Server should also be indented one level.

So, I think the entries in the brown box should be displayed like this:

v  localhost:787 POST api/v1/market                   (request)
    arcus.api.bacon:999 GET /api/v1/bacon             (dependency)
    v arcus.api.bacon:999 GET /api/v1/bacon           (request)
       example-server SQL:bacon-db/flavors            (dependency)
    arcus-s2s-bus  orders                             (dependency)

Then we have an entry 'Time spent in queue'. This is the amount of time that has passed between the message being placed in the queue and the time by when it was picked up by the worker:

I think the representation of this entry is a bit weird, but I don't think we can control that.
the green rectangle contains the requests & dependencies logged by the Order Processor that takes the posted message(s) from the ServiceBus queue and processes them.

Also here, there are some issues with the representation imho:

The dependency to the arcus.api.bacon api must be indented, so that it is clear that this is a dependency of the Order Worker.
The dependency to the sql server should be indented, so that it is clear that it is a dependency of the GET bacon request.

I think, the dependencies & requests in the green box should be visualized like this:

        v  Order Worker Process           (request)
           arcus.api.bacon:999 GET /api/v1/bacon  (dependency)
           v  arcus.api.bacon:999 GET /api/v1/bacon (request)
                example-server SQL:bacondb/flavors (dependency)

At least, this is my opinion and what I would expect. What are your opinions @stijnmoreels @tomkerkhove @gverstraete ?

fgheysels commented 2 years ago

The outcome in this issue has been achieved in the service-to-service poc, with the changes that have been made in this PR.

fgheysels commented 2 years ago

I just don't know how we're going to make sure that the visualization in the Application Map also displays that the Order Worker retrieves messages from arcus-s2s-bus.

stijnmoreels commented 2 years ago

I just don't know how we're going to make sure that the visualization in the Application Map also displays that the Order Worker retrieves messages from arcus-s2s-bus.

That is to be expected, as said: the order worker needs some minutes before every call is made and tracked. This can take up to 5/10 min even. Or maybe more.

stijnmoreels commented 2 years ago

The outcome in this issue has been achieved in the service-to-service poc, with the changes that have been made in this PR.

You mean that this is already done? That the proposed indentation of dependencies based on requrests is already made possible with these changes? I would say, no, 😄 .

I think it's a valuable input on this very complex topic. I can definitely see the added-value if the entire flow is made like this. In one fluent motion. I was wondering if this is also how it's 'intended' to be. As in: is this also the result when people use the TelemetryClient instead of logging. 🤔 If not, than I think we're even better 😄 .

I think there are also some guidelines/requirements on correlation. Is this something we should take into account in this? HTTP correlation especially may need some work.

fgheysels commented 2 years ago

You mean that this is already done? That the proposed indentation of dependencies based on requrests is already made possible with these changes? I would say, no, 😄 .

No, I mean that the screenshots that are displayed here, are done via the modifications made in that PR :)

stijnmoreels commented 2 years ago

You mean that this is already done? That the proposed indentation of dependencies based on requrests is already made possible with these changes? I would say, no, 😄 .

No, I mean that the screenshots that are displayed here, are done via the modifications made in that PR :)

Ah, ok, and is the order worker still referenced? I assume it would as it's not related to that.

fgheysels commented 2 years ago

I'd expect that the dependency between the Order worker & Service Bus is visible in the Application map, as the Order worker logs a ServiceBus Request when it handles a message, but that is currently not the case.

stijnmoreels commented 2 years ago

I'd expect that the dependency between the Order worker & Service Bus is visible in the Application map, as the Order worker logs a ServiceBus Request when it handles a message, but that is currently not the case.

😕 Hmm, remember running the poc and seeing the connection with the order worker, though, it is the one reference that takes the longest time to come up (we're talking minutes here).

stijnmoreels commented 2 years ago

@fgheysels , can you give an update on this according to the updates made on the dependent libraries?

fgheysels commented 2 years ago

This is how it looks like now:

I would assume that:

the dependency to the bacon API should indent as opposed to the request to the market API. When I click on that dependency, I can see that the parentId is set to 000000000

I would expect that the parentId is set to the Id of the POST market operation
Same for the SQL dependency. Shouldn't the parent ID of that dependency not be set to the Id of the Get Bacon request ?
I also think it is strange that the duration of the POST market operation includes the duration that the message has spent in the queue.
It is also not clear that the POST market operation has a dependency on ServiceBus. Also here, I believe the ParentId must be set correctly, but here, it is also set to '0000000000000000'

stijnmoreels commented 2 years ago

also think it is strange that the duration of the POST market operation includes the duration that the message has spent in the queue.

The POST market request isn't done until the Worker and other API is done calling, so it's seems logical that this is included, no?

the dependency to the bacon API should indent as opposed to the request to the market API. When I click on that dependency, I can see that the parentId is set to 000000000, It is also not clear that the POST market operation has a dependency on ServiceBus. Also here, I believe the ParentId must be set correctly, but here, it is also set to '0000000000000000'

This is indeed not implemented. We now only made sure that the request is linked to the dependency call, but not the way around. It has also something to do with the initial POST market request, if that one doesn't specify a operation parent ID, there's nothing to link.

fgheysels commented 2 years ago

also think it is strange that the duration of the POST market operation includes the duration that the message has spent in the queue.

The POST market request isn't done until the Worker and other API is done calling, so it's seems logical that this is included, no?

That is not correct. The POST operation is done as soon as the message has been delivered to the queue by the API operation. The Worker that processes the messages on the queue, is another process. In theory, it is possible that the worker only picks up and processes the message after several hours or even days. The POST market operation ends as soon as the API operation has returned a statuscode.

fgheysels commented 2 years ago

the dependency to the bacon API should indent as opposed to the request to the market API. When I click on that dependency, I can see that the parentId is set to 000000000, It is also not clear that the POST market operation has a dependency on ServiceBus. Also here, I believe the ParentId must be set correctly, but here, it is also set to '0000000000000000'

This is indeed not implemented. We now only made sure that the request is linked to the dependency call, but not the way around. It has also something to do with the initial POST market request, if that one doesn't specify a operation parent ID, there's nothing to link.

But how is this then done in other libraries like Entity Framework ? Every trace has an id, even if you do not explicitly assign one. Maybe they're making use of the Activity class, idk.

stijnmoreels commented 2 years ago

Hmm, I think it is implemented, but we need to specify it in the operation ID header. That's also why we have the ExtractFromRequest option in the HTTP correlation middleware component.

We could, however, generate the operation parent ID if the result of that setting doesn't result in an operation parent ID, but we would have to check if we are allowed to do that within the HTTP correlation protocol.

stijnmoreels commented 2 years ago

also think it is strange that the duration of the POST market operation includes the duration that the message has spent in the queue.

That is not correct. The POST operation is done as soon as the message has been delivered to the queue by the API operation. The Worker that processes the messages on the queue, is another process. In theory, it is possible that the worker only picks up and processes the message after several hours or even days. The POST market operation ends as soon as the API operation has returned a statuscode.

Aha! Maybe this is a result of the service-to-service correlation, as the Duration column clearly states the duration but that doesn't corresponds with the graphic that is shown. So, this is probably the 'entire operation duration'. So, it's correct, no?

arcus-azure / arcus-service-to-service-correlation-poc

What should be the final outcome of service-to-service correlation tracking #7