Change in routing behavior?

[flmbray]

Hi... somewhere between 19.0.1 and 23.1.0, it seems something changed regarding how routes get handled. Our configuration had the following PathTemplates like this, in this order (omitting all the other parameters for brevity):

{ 
   "UpstreamPathTemplate": "/v1.0/document/getItemStatus?{everything}",
   "DownstreamPathTemplate": "/v1.0/document/getItemStatus?{everything}"
},
{ 
   "UpstreamPathTemplate": "/v1.0/document/getItemStatusHistory?{everything}",
   "DownstreamPathTemplate": "/v1.0/document/getItemStatusHistory?{everything}"
}

Prior to the upgrade (i.e. when we were using 19.0.1) these routes worked as expected. Since the upgrade to 23.1.0, we have recently discovered that when clients call getItemStatusHistory, Ocelot is actually picking and executing the downstream for getItemStatus instead (note the corresponding requestId values):

requestId: 0HN2OOAOCH902:0000001E, previousRequestId: No PreviousRequestId, message: 'No authentication needed for path '/v1.0/document/getItemStatus'.'
requestId: 0HN2OOAOCH902:0000001E, previousRequestId: No PreviousRequestId, message: '200 (OK) status code of request URI: http://XXXXXXX:######/v1.0/document/getItemStatus?id=a004b5c7-c6aa-4ecb-bd1a-5c71d42d349e&lineNumbers=1&type=201.'

requestId: 0HN2OOAOCH8VS:0000002B, previousRequestId: No PreviousRequestId, message: 'No authentication needed for path '/v1.0/document/getItemStatusHistory'.'
requestId: 0HN2OOAOCH8VS:0000002B, previousRequestId: No PreviousRequestId, message: '200 (OK) status code of request URI: http://XXXXXXX:######/v1.0/document/getItemStatus?id=a004b5c7-c6aa-4ecb-bd1a-5c71d42d349e&lineNumber=1&type=201.'

We were able to resolve this by swapping the order of the two routes in our configuration file, putting the route for getItemStatusHistory first. I don't see anything specifically about this in the release notes, although I saw a couple of pull request merges that might be the cause, this one in particular from 20.0.0. I'm also not completely sure we are using the templates correctly - this isn't my area of expertise and the people that originally implemented Ocelot in our project are no longer with us. However with my limited understanding, it seems that maybe Ocelot is somehow overlooking the ? and matching {everything} in the getItemStatus route to the "History" portion in the url. Previously, it seems that the presence of the ? in the getItemStatus template prevented this, as I would expect.

So I guess what I'm asking is:

• Is this the expected behavior, or is it a bug that was introduced? If it is a bug, how soon could I expect a fix? (I'm asking because we haven't released our code with the 23.2.0 version yet, and knowing when a fix might be coming could affect whether we downgrade or wait for the fix.) If it is the expected behavior,
• Are we misusing the {template} capability? If so, please clarify.

Thanks!

[raman-m]

Hi @flmbray !
Welcome to Ocelot world! 🐯

#1288 is not related to your case. PR #1288 fixed another problem.

---

I'm also not completely sure we are using the templates correctly

Please show me what you have done.

{ 
   "UpstreamPathTemplate": "/v1.0/document/getItemStatus?{everything}",
},
{ 
   "UpstreamPathTemplate": "/v1.0/document/getItemStatusHistory?{everything}",
}

The current version of our documentation defines "Catch All Query String" templates, which is a unique feature designed to route all query strings for a static path.

But your logs are:

requestId: 0HN2OOAOCH902:0000001E, previousRequestId: No PreviousRequestId, message: 'No authentication needed for path '/v1.0/document/getItemStatus'.'
requestId: 0HN2OOAOCH902:0000001E, previousRequestId: No PreviousRequestId, message: '200 (OK) status code of request URI: http://XXXXXXX:######/v1.0/document/getItemStatus?id=a004b5c7-c6aa-4ecb-bd1a-5c71d42d349e&lineNumbers=1&type=201.'

requestId: 0HN2OOAOCH8VS:0000002B, previousRequestId: No PreviousRequestId, message: 'No authentication needed for path '/v1.0/document/getItemStatusHistory'.'
requestId: 0HN2OOAOCH8VS:0000002B, previousRequestId: No PreviousRequestId, message: '200 (OK) status code of request URI: http://XXXXXXX:######/v1.0/document/getItemStatus?id=a004b5c7-c6aa-4ecb-bd1a-5c71d42d349e&lineNumber=1&type=201.'

I can't find any requests to the getItemStatusHistory downstream. If there are issues with priority or matching paths, we should still see logged calls to getItemStatusHistory. Can you provide the complete log, please? Also, ensure requests are made to both routes and that both URLs are logged during the debug session. Your logging level should be set to Debug or Info.

I'm unable to make a decision as your log appears incomplete. It could theoretically be an issue with the matching paths' priority for Catch All Query String templates.

---

this isn't my area of expertise and the people that originally implemented Ocelot in our project are no longer with us.

It's unfortunate to hear that. It's important to respect your former colleagues' decisions. Why not consider hiring a developer to update your Ocelot to the latest version? If the old version was functioning well, what prompted you to begin upgrading your solution?

---

Is this the expected behavior, or is it a bug that was introduced?

This is the expected behavior for the Catch All Query String feature when dealing with static paths. The confusion may arise from the assumption that paths can be dynamic.
But this definition of two routes can uncover a bug... I'm not sure now.

---

If it is a bug, how soon could I expect a fix?

I don't observe any bugs; rather, it appears to be a misconfiguration issue and a lack of documentation review. For breaking changes in major versions, we accept bug reports to open hotfix PRs and typically release the hotfix within one to two days. Hotfixes are usually released in 1-2 days. However, we are an open-source project, not a commercial one, and we do not have support engineers on our team. It seems it might be time for Ocelot to adopt some commercial aspects.

I'm asking because we haven't released our code with the 23.2.0 version yet, and knowing when a fix might be coming could affect whether we downgrade or wait for the fix.

Please revert to the previous version to ensure the stability of your solution. You may also want to consider updating to version 23.2.2, which includes a hotfix.

Are we misusing the {template} capability? If so, please clarify.
I'm not entirely certain, but it appears that the following recommendations will assist you in upgrading to version 23.2.2 and in correctly adjusting or redefining route templates:

{ 
   "UpstreamPathTemplate": "/v1.0/document/getItemStatus?{everything}",
   "DownstreamPathTemplate": "/v1.0/document/getItemStatus?{everything}"
},
{ 
   "UpstreamPathTemplate": "/v1.0/document/getItemStatusHistory?{everything}",
   "DownstreamPathTemplate": "/v1.0/document/getItemStatusHistory?{everything}"
}

Defining dynamic routes with varying query strings while also having dynamic paths can be problematic. This approach is a definitional error; it would be more efficient to merge both routes into a single one, for example:

{ 
   "UpstreamPathTemplate": "/v1.0/document/{everything}",
   "DownstreamPathTemplate": "/v1.0/document/{everything}"
},

The Catch All route definition includes all query strings and should address any issues with priority and path matching.

Hope it helps!

[flmbray]

I can't find any requests to the getItemStatusHistory downstream

That is pretty much the point I'm trying to demonstrate. The API call comes in to Ocelot as getItemStatusHistory?stuff, which matches the getItemStatusHistory?{everything} route better than the getItemStatus?{everything} route and yet Ocelot is picking the getItemStatus route anyway. I don't think I can provide logs that are much better, but here's the full set of logs I captured when requesting the getItemStatusHistory endpoint via Postman (note - I did NOT request getItemStatus?... when recording these logs!!!):

Info, { "LogMessage": [ "requestId: 0HN2PM2IOCK12:00000001, previousRequestId: No PreviousRequestId, message: 'EndpointRateLimiting is not enabled for /v1.0/document/getItemStatus?{everything}'" ], "level": "Info", "hostName": "XXXXX", "categoryName": "Ocelot.RateLimit.Middleware.ClientRateLimitMiddleware", "logTime": "04/12/2024 01:22:16.261", "environment": "qa1" }
Info, { "LogMessage": [ "requestId: 0HN2PM2IOCK12:00000001, previousRequestId: No PreviousRequestId, message: 'No authentication needed for path '/v1.0/document/getItemStatusHistory'.'" ], "level": "Info", "hostName": "XXXXX", "categoryName": "Ocelot.Authentication.Middleware.AuthenticationMiddleware", "logTime": "04/12/2024 01:22:16.261", "environment": "qa1" }
Info, { "LogMessage": [ "requestId: 0HN2PM2IOCK12:00000001, previousRequestId: No PreviousRequestId, message: '/v1.0/document/getItemStatus?{everything} route does not require user to be authorized'" ], "level": "Info", "hostName": "XXXXX", "categoryName": "Ocelot.Authorization.Middleware.AuthorizationMiddleware", "logTime": "04/12/2024 01:22:16.261", "environment": "qa1" }
Warn, { "LogMessage": [ "requestId: 0HN2PM2IOCK12:00000001, previousRequestId: No PreviousRequestId, message: '401 (Unauthorized) status code of request URI: http://XXXXX/v1.0/document/getItemStatus?id=a004b5c7-c6aa-4ecb-bd1a-5c71d42d349e&lineNumber=1&type=201.'" ], "level": "Warn", "hostName": "XXXXX", "categoryName": "Ocelot.Requester.Middleware.HttpRequesterMiddleware", "logTime": "04/12/2024 01:22:17.039", "environment": "qa1" }
Info, { "LogMessage": [ "RequestResponseLogging: [id=0HN2PM2IOCK12:00000001]", "http://XXXXX/v1.0/document/getItemStatusHistory?id=a004b5c7-c6aa-4ecb-bd1a-5c71d42d349e&type=201&lineNumber=1", "Response Status = 401", "Action Duration = 779ms", "Request Headers:", "[Accept]=[*/*]", "[Connection]=[keep-alive]", "[Host]=[XXXXX]", "[User-Agent]=[PostmanRuntime/7.37.3]", "[Accept-Encoding]=[gzip, deflate, br]", "[Postman-Token]=[f629e7ca-33e0-4f36-8d89-52098315de88]", "Response Headers:", "[Date]=[Fri, 12 Apr 2024 05:22:16 GMT]", "[Server]=[Kestrel]", "[Content-Length]=[0]" ], "level": "Info", "hostName": "XXXXX", "categoryName": "XXXXX", "logTime": "04/12/2024 01:22:17.040", "environment": "qa1" }

The first log is a bit confusing because it appears to be out of order (it incorrectly refers to getItemStatus whereas the second log correctly refers to getItemStatusHistory.) I feel that this out-of-order issue is likely just a glitch in the way we are recording the logs, and can be overlooked. Also, ignore the 401 error in the fourth log - that's just because I didn't generate a Bearer token for the connection. The point is that the request to getItemStatusHistory has somehow been routed to getItemStatus when I don't think it should have been, even understanding that there is a "Catch All Query String" capability. Note that the last log output is the result of our own custom middleware, and correctly shows that the URL that was requested was getItemStatusHistory.

The current version of our documentation defines "Catch All Query String" templates, which is a unique feature designed to route all query strings for a static path

This would make sense to me if it was only picking up changes in the query string.... but this catch-all seems to be also picking up an overlap in the path - it's almost like it is treating {everything} like a .* regex, as if it was getItemStatus.* and thus matching getItemStatusHistory. That doesn't make sense, but that seems to be what it is doing.

I have been able to create a nice demonstration of this... I've attached a file: Ocelot.zip.

This zip contains three files:

1. A LinqPad v7 C# Program script (taken almost literally from the Ocelot Getting Started page)
2. An ocelot.json configuration file
3. A postman collection that will be used to trigger the behavior

Once you extract the zip file, open the LinqPad script (it links Ocelot latest-version, currently 23.2.2, via Nuget so it might ask if you want to download it). Open the ocelot.json config and note that it defines two routes under BaseUrl=http://localhost:5000:

1. /get?{everything} - routes to https://postman-echo.com/get?{everything}
2. /getOverlap?{everything} - routes to https://postman-echo.com/getOverlap?{everything}

Note that get is a valid endpoint at postman-echo.com, but getOverlap is not. The idea of this test is that the get route should work but the getOverlap route should fail because the getOverlap endpoint doesn't exist at postman-echo.com. Finally, create a new Postman workspace and import the Ocelot.postman_collection.json file. There are two GET operations defined - one for each of get and getOverlap. Start the LinqPad program running, and then execute the Postman operation for the get request and note that it works as expected - we get the typical response from postman-echo.com/get endpoint (note especially the "url" response parameter says "/get" (you will end up with a different random word for the id arg):

Now run the Postman operation for getOverlap which should fail. But in fact it works (unexpectedly, in my opinion) because Ocelot routed the request to /get?... instead of /getOverlap?..., and this is confirmed by the response that we get from postman-echo via the Ocelot request:

And then for the final test, stop the Ocelot service, edit the ocelot.json file and swap the order of the two routes so that getOverlap is listed first, and then re-run the tests. You should now see that the get request still works as expected, and the getOverlap request now fails as expected. I presume that this first-match behavior is by design, but I still feel that the getOverlap?id=123 should not match the route for get?{everything}.

I can certainly understand that the order of routes in the config file can make a difference, but it doesn't make sense that getOverlap should get matched to the get route in either version of the test. I mean.... I'll defer to your judgement on this last point, and if you say that in fact it IS expected then I'll take your word for it and just be more cautious in how we order our routes, but the presence of the ? in both Upstream Templates seems to imply to me that "get" should only ever match "get" and "getOverlap" should only ever match "getOverlap". This is why I suspected #1335 because it seems to be doing some funky stuff with Regex's, and if the ?s in the urls aren't handled properly they could get interpreted as a special regex character. But because I can't quite follow what is going on with name and nAndV variables, I can't quite pin down how it would occur to cause the observed behavior.

So to conclude this, I ask you to please try my sample demonstration files to get a better understanding of what I think is wrong, and if you say again that you think it is operating as designed then I will work around the issue on my end.

Thank you so much for your time and dedication to supporting the community!

[raman-m]

Very interesting story!

This would make sense to me if it was only picking up changes in the query string.... but this catch-all seems to be also picking up an overlap in the path - it's almost like it is treating {everything} like a .* regex, as if it was getItemStatus.* and thus matching getItemStatusHistory. That doesn't make sense, but that seems to be what it is doing.

Indeed, the behavior you've described is anticipated due to a series of bug fixes addressing the omission of the final slash in Catch All templates. Unfortunately, I cannot provide links at this moment. Thus, this behavior is expected, and there's limited scope for further improvement in your scenario.

The "incorrect" behavior you've encountered is likely due to the redundant second definition in the Catch All case, which may raise concerns about priority. My advice is to define a single Catch All route and disregard the issue.

---

This is why I suspected #1335 because it seems to be doing some funky stuff with Regex's, and if the ?s in the urls aren't handled properly they could get interpreted as a special regex character.

Hmm... Is it an issue? Should it be fixed in your opinion?

---

So to conclude this, I ask you to please try my sample demonstration files to get a better understanding of what I think is wrong, and if you say again that you think it is operating as designed then I will work around the issue on my end.

🆗 I will...

Please inform me if you encounter any other peculiar behaviors with Ocelot!

[raman-m]

1. /get?{everything} - routes to https://postman-echo.com/get?{everything}
2. /getOverlap?{everything} - routes to https://postman-echo.com/getOverlap?{everything}

Changing the template to "UpstreamPathTemplate": "/{everything}" should not cause any issues, correct?

---

"UpstreamPathTemplate": "/get?{everything}",
"UpstreamPathTemplate": "/getOverlap?{everything}",

Now I understand the issue you've reported.
Regarding the .* regex, the bug could be within the template matching logic since our templates convert to RegEx, and the ? character might be problematic for /path?{everything} templates.

However, if you redefine the routes as follows replacing ? with /:

"UpstreamPathTemplate": "/get/{everything}",
"UpstreamPathTemplate": "/getOverlap/{everything}",

...then template logic should function flawlessly because the / character is not a special regex character.