Azure API Management
An Azure service that provides a hybrid, multi-cloud management platform for APIs.
1,908 questions
This browser is no longer supported.
Upgrade to Microsoft Edge to take advantage of the latest features, security updates, and technical support.
I noticed that the timestamps in APIM Policies look like a lot of things are running in parallel.
I have the following policy:
<policies>
<inbound>
<set-variable name="start_time" value="@(DateTime.UtcNow.ToString("o"))" />
<xsl-transform>
[...]
</xsl-transform>
<base />
<set-variable name="end_time" value="@(DateTime.UtcNow.ToString("o"))" />
<set-backend-service base-url="[...]" />
</inbound>
<backend>
<base />
</backend>
<outbound>
<base />
<set-variable name="outbound_time" value="@(DateTime.UtcNow.ToString("o"))" />
</outbound>
<on-error>
<base />
</on-error>
</policies>
The sanitized trace shows this:
{
"serviceName":"[...]",
"traceEntries":{
"inbound":[
{
"source":"cors",
"timestamp":"2024-06-18T10:43:37.9545915Z",
"elapsed":"00:00:00.0050615",
"data":"Origin header was missing or empty and the request was classified as not cross-domain. CORS policy was not applied."
},
{
"source":"set-variable",
"timestamp":"2024-06-18T10:43:37.9545915Z",
"elapsed":"00:00:00.0050681",
"data":{
"message":"Expression was successfully evaluated.",
"expression":"DateTime.UtcNow.ToString(\"o\")",
"value":"2024-06-18T10:43:37.9545915Z"
}
},
{
"source":"set-variable",
"timestamp":"2024-06-18T10:43:37.9545915Z",
"elapsed":"00:00:00.0050768",
"data":{
"message":"Context variable was successfully set.",
"name":"start_time",
"value":"2024-06-18T10:43:37.9545915Z"
}
},
{
"source":"xsl-transform",
"timestamp":"2024-06-18T10:43:37.9701951Z",
"elapsed":"00:00:00.0078287",
"data":"XSL Transform policy was applied. Original Content-Length header updated to new value. "
},
{
"source":"set-variable",
"timestamp":"2024-06-18T10:43:37.9701951Z",
"elapsed":"00:00:00.0078450",
"data":{
"message":"Expression was successfully evaluated.",
"expression":"DateTime.UtcNow.ToString(\"o\")",
"value":"2024-06-18T10:43:37.9701951Z"
}
},
{
"source":"set-variable",
"timestamp":"2024-06-18T10:43:37.9701951Z",
"elapsed":"00:00:00.0078632",
"data":{
"message":"Context variable was successfully set.",
"name":"end_time",
"value":"2024-06-18T10:43:37.9701951Z"
}
},
{
"source":"set-backend-service",
"timestamp":"2024-06-18T10:43:37.9701951Z",
"elapsed":"00:00:00.0078743",
"data":{
"message":"Backend service URL was changed.",
"oldBackendServiceUrl":"",
"newBackendServiceUrl":"[...]",
"request":{
"url":"[...]"
}
}
}
],
"backend":[
{
"source":"forward-request",
"timestamp":"2024-06-18T10:43:37.9701951Z",
"elapsed":"00:00:00.0080680",
[...]
}
],
"outbound":[
{
"source":"set-variable",
"timestamp":"2024-06-18T10:43:38.6108878Z",
"elapsed":"00:00:00.6624263",
"data":{
"message":"Expression was successfully evaluated.",
"expression":"DateTime.UtcNow.ToString(\"o\")",
"value":"2024-06-18T10:43:38.6108878Z"
}
},
{
"source":"set-variable",
"timestamp":"2024-06-18T10:43:38.6108878Z",
"elapsed":"00:00:00.6624385",
"data":{
"message":"Context variable was successfully set.",
"name":"outbound_time",
"value":"2024-06-18T10:43:38.6108878Z"
}
},
{
"source":"transfer-response",
"timestamp":"2024-06-18T10:43:38.6108878Z",
"elapsed":"00:00:00.6628708",
"data":{
"message":"Response has been sent to the caller in full"
}
}
]
}
}
The trace seems to be wrong. How can the xsl-transform, set-variable and the backend actions run at the exact same time (down to the millisecond)?
inbound:
backend - 2024-06-18T10:43:37.9701951Z
outbound - 2024-06-18T10:43:38.6108878Z