Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Investigate the expected service-side behavior of AzurePipelinesCredential.InvalidSystemAccessToken_LIVEONLY_ returning HTTP status code 203 #5786

Open
ahsonkhan opened this issue Jul 11, 2024 · 2 comments

Comments

@ahsonkhan
Copy link
Member

ahsonkhan commented Jul 11, 2024

The test, as it is currently written, expects an HTTP status code 302 (Found) when an invalid system access token is provided, per the TSG.

However, the service is returning HTTP status code 203 (Non-Authoritative Information). This will either require a TSG and test update, to capture the observed behavior, or a discussion from the service team to understand if 203 is the correct behavior we should expect in this scenario.

TEST(AzurePipelinesCredential, InvalidSystemAccessToken_LIVEONLY_)

The behavior seems inconsistent as well. For example, here, on the first run of the test (which happens to be on Ubuntu), the service returns 302 and the test passes. However, on subsequent test runs (on Windows), an HTTP 203 is returned which fails the test.
[1]
https://dev.azure.com/azure-sdk/internal/_build/results?buildId=3955276&view=logs&j=e732a657-4392-5bc3-3289-b34fe17fd560&t=28d3e977-de2c-5feb-854f-4d9592e2dd8b

2024-07-11T23:21:04.8412858Z 80: [ RUN      ] AzurePipelinesCredential.InvalidSystemAccessToken_LIVEONLY_
2024-07-11T23:21:04.8413898Z 80: [2024-07-11T23:21:04.8406100Z T: 140075951321344] INFO  : Identity: AzurePipelinesCredential was created successfully.
2024-07-11T23:21:04.8415046Z 80: [2024-07-11T23:21:04.8406699Z T: 140075951321344] INFO  : HTTP Request : POST https://dev.azure.com/azure-sdk/590cfd2a-581c-4dcb-a12e-6568ce786175/_apis/distributedtask/hubs/build/plans/34304abc-4a96-46df-804a-b3683ba7fd1a/jobs/e732a657-4392-5bc3-3289-b34fe17fd560/oidctoken?api-version=7.1&serviceConnectionId=REDACTED
2024-07-11T23:21:04.8415911Z 80: authorization : REDACTED
2024-07-11T23:21:04.8416497Z 80: content-type : application/json
2024-07-11T23:21:04.8417127Z 80: user-agent : azsdk-cpp-identity/1.9.0-beta.2 (Linux 5.15.0-1067-azure x86_64 #76~20.04.1-Ubuntu SMP Thu Jun 13 18:00:23 UTC 2024)
2024-07-11T23:21:04.8417706Z 80: x-ms-client-request-id : 2b73b0da-92c7-4236-b1c6-78554ba9900b
2024-07-11T23:21:04.8418291Z 80: [2024-07-11T23:21:04.8406825Z T: 140075951321344] DEBUG : [CURL Transport Adapter]: Creating a new session.
2024-07-11T23:21:04.8418890Z 80: [2024-07-11T23:21:04.8406954Z T: 140075951321344] DEBUG : [CURL Transport Adapter]: Spawn new connection.
2024-07-11T23:21:04.8652911Z 80: [2024-07-11T23:21:04.8648126Z T: 140075951321344] DEBUG : [CURL Transport Adapter]: No Host in request headers. Adding it
2024-07-11T23:21:04.8653992Z 80: [2024-07-11T23:21:04.8648405Z T: 140075951321344] DEBUG : [CURL Transport Adapter]: No content-length in headers. Adding it
2024-07-11T23:21:04.8654690Z 80: [2024-07-11T23:21:04.8648546Z T: 140075951321344] DEBUG : [CURL Transport Adapter]: Send request without payload
2024-07-11T23:21:04.8655352Z 80: [2024-07-11T23:21:04.8649446Z T: 140075951321344] DEBUG : [CURL Transport Adapter]: Parse server response
2024-07-11T23:21:04.9135503Z 80: [2024-07-11T23:21:04.9120412Z T: 140075951321344] DEBUG : [CURL Transport Adapter]: Request completed. Moving response out of session and session to response.
2024-07-11T23:21:04.9137080Z 80: [2024-07-11T23:21:04.9120743Z T: 140075951321344] DEBUG : Moving connection to pool...
2024-07-11T23:21:04.9138067Z 80: [2024-07-11T23:21:04.9120905Z T: 140075951321344] DEBUG : Start clean thread
2024-07-11T23:21:04.9139100Z 80: [2024-07-11T23:21:04.9122015Z T: 140075951321344] INFO  : HTTP/1.1 Response (71ms) : 302 Found

[2]
https://dev.azure.com/azure-sdk/internal/_build/results?buildId=3955276&view=logs&j=bde6d2cb-0847-54f8-b066-ca83e951fc62&t=7e88246e-2d7d-5f11-e032-00f743b98e55

2024-07-11T23:30:09.9592141Z 38: [ RUN      ] AzurePipelinesCredential.InvalidSystemAccessToken_LIVEONLY_
2024-07-11T23:30:09.9593171Z 38: [2024-07-11T23:30:09.9582952Z T: 6368] INFO  : Identity: AzurePipelinesCredential was created successfully.
2024-07-11T23:30:09.9594535Z 38: [2024-07-11T23:30:09.9583952Z T: 6368] INFO  : HTTP Request : POST https://dev.azure.com/azure-sdk/590cfd2a-581c-4dcb-a12e-6568ce786175/_apis/distributedtask/hubs/build/plans/34304abc-4a96-46df-804a-b3683ba7fd1a/jobs/bde6d2cb-0847-54f8-b066-ca83e951fc62/oidctoken?api-version=7.1&serviceConnectionId=REDACTED
2024-07-11T23:30:09.9595860Z 38: authorization : REDACTED
2024-07-11T23:30:09.9596951Z 38: content-type : application/json
2024-07-11T23:30:09.9598180Z 38: user-agent : azsdk-cpp-identity/1.9.0-beta.2 (Windows Server 2019 Datacenter 6.3 17763 17763.1.x86fre.rs5_release.180914-1434)
2024-07-11T23:30:09.9599209Z 38: x-ms-client-request-id : dd21cc84-810b-4c55-924e-43081471cd41
2024-07-11T23:30:09.9645449Z 38: [2024-07-11T23:30:09.9642880Z T: 1756] INFO  : Status operation: 1(WINHTTP_CALLBACK_STATUS_RESOLVING_NAME )
2024-07-11T23:30:09.9677224Z 38: [2024-07-11T23:30:09.9675163Z T: 7568] INFO  : Status operation: 2(WINHTTP_CALLBACK_STATUS_NAME_RESOLVED )
2024-07-11T23:30:09.9691686Z 38: [2024-07-11T23:30:09.9689911Z T: 7568] INFO  : Status operation: 4(WINHTTP_CALLBACK_STATUS_CONNECTING_TO_SERVER )
2024-07-11T23:30:09.9709629Z 38: [2024-07-11T23:30:09.9707483Z T: 7568] INFO  : Status operation: 8(WINHTTP_CALLBACK_STATUS_CONNECTED_TO_SERVER )
2024-07-11T23:30:09.9847701Z 38: [2024-07-11T23:30:09.9844064Z T: 7568] INFO  : Status operation: 16(WINHTTP_CALLBACK_STATUS_SENDING_REQUEST )
2024-07-11T23:30:09.9849090Z 38: [2024-07-11T23:30:09.9845573Z T: 7568] INFO  : Status operation: 32(WINHTTP_CALLBACK_STATUS_REQUEST_SENT )
2024-07-11T23:30:10.0330408Z 38: [2024-07-11T23:30:10.0327204Z T: 7568] INFO  : Status operation: 4194304(WINHTTP_CALLBACK_STATUS_SENDREQUEST_COMPLETE )
2024-07-11T23:30:10.0331983Z 38: [2024-07-11T23:30:10.0328109Z T: 6368] INFO  : Status operation: 64(WINHTTP_CALLBACK_STATUS_RECEIVING_RESPONSE )
2024-07-11T23:30:10.0333234Z 38: [2024-07-11T23:30:10.0328471Z T: 6368] INFO  : Status operation: 128(WINHTTP_CALLBACK_STATUS_RESPONSE_RECEIVED )
2024-07-11T23:30:10.0334407Z 38: [2024-07-11T23:30:10.0329407Z T: 6368] INFO  : Status operation: 16384(WINHTTP_CALLBACK_STATUS_REDIRECT )
2024-07-11T23:30:10.0335910Z 38: [2024-07-11T23:30:10.0333395Z T: 7568] INFO  : Status operation: 1(WINHTTP_CALLBACK_STATUS_RESOLVING_NAME )
2024-07-11T23:30:10.0360444Z 38: [2024-07-11T23:30:10.0358631Z T: 7580] INFO  : Status operation: 2(WINHTTP_CALLBACK_STATUS_NAME_RESOLVED )
2024-07-11T23:30:10.0361808Z 38: [2024-07-11T23:30:10.0360133Z T: 7580] INFO  : Status operation: 4(WINHTTP_CALLBACK_STATUS_CONNECTING_TO_SERVER )
2024-07-11T23:30:10.0377777Z 38: [2024-07-11T23:30:10.0374896Z T: 7580] INFO  : Status operation: 8(WINHTTP_CALLBACK_STATUS_CONNECTED_TO_SERVER )
2024-07-11T23:30:10.0464556Z 38: [2024-07-11T23:30:10.0461610Z T: 7580] INFO  : Status operation: 16(WINHTTP_CALLBACK_STATUS_SENDING_REQUEST )
2024-07-11T23:30:10.0465560Z 38: [2024-07-11T23:30:10.0463170Z T: 7580] INFO  : Status operation: 32(WINHTTP_CALLBACK_STATUS_REQUEST_SENT )
2024-07-11T23:30:10.1171839Z 38: [2024-07-11T23:30:10.1168411Z T: 7580] INFO  : Status operation: 64(WINHTTP_CALLBACK_STATUS_RECEIVING_RESPONSE )
2024-07-11T23:30:10.1174223Z 38: [2024-07-11T23:30:10.1169245Z T: 7580] INFO  : Status operation: 128(WINHTTP_CALLBACK_STATUS_RESPONSE_RECEIVED )
2024-07-11T23:30:10.1175802Z 38: [2024-07-11T23:30:10.1169476Z T: 7580] INFO  : Status operation: 131072(WINHTTP_CALLBACK_STATUS_HEADERS_AVAILABLE )
2024-07-11T23:30:10.1176965Z 38: [2024-07-11T23:30:10.1170840Z T: 6368] INFO  : Status operation: 64(WINHTTP_CALLBACK_STATUS_RECEIVING_RESPONSE )
2024-07-11T23:30:10.1195195Z 38: [[2024-07-11T23:30:10.1172282Z2024-07-11T23:30:10.1172326Z T:  T: 75806368] INFO ]  : DEBUGStatus operation: 128(WINHTTP_CALLBACK_STATUS_RESPONSE_RECEIVED ) : Read Data read from wire. Size: 0.
2024-07-11T23:30:10.1196340Z 38:
2024-07-11T23:30:10.1202390Z 38: [2024-07-11T23:30:10.1173116Z T: 7580] INFO  : Status operation: 524288(WINHTTP_CALLBACK_STATUS_READ_COMPLETE )
2024-07-11T23:30:10.1203602Z 38: [2024-07-11T23:30:10.1173668Z T: 6368] DEBUG : ReadData returned size: 8192.
2024-07-11T23:30:10.1204855Z 38: [2024-07-11T23:30:10.1174122Z T: 6368] INFO  : Status operation: 64(WINHTTP_CALLBACK_STATUS_RECEIVING_RESPONSE )
2024-07-11T23:30:10.1206909Z 38: [2024-07-11T23:30:10.1174767Z T: 6368] INFO  : Status operation: 128(WINHTTP_CALLBACK_STATUS_RESPONSE_RECEIVED )
2024-07-11T23:30:10.1208093Z 38: [2024-07-11T23:30:10.1175142Z T: 6368] INFO  : Status operation: 524288(WINHTTP_CALLBACK_STATUS_READ_COMPLETE )
2024-07-11T23:30:10.1209826Z 38: [2024-07-11T23:30:10.1175403Z T: 6368] DEBUG : Read Data read from wire. Size: 6800.
2024-07-11T23:30:10.1210906Z 38: [2024-07-11T23:30:10.1175678Z T: 6368] DEBUG : ReadData returned size: 6800.
2024-07-11T23:30:10.1212137Z 38: [2024-07-11T23:30:10.1176036Z T: 6368] INFO  : WinHttpRequest::~WinHttpRequest. Closing handle synchronously.
2024-07-11T23:30:10.1213191Z 38: [2024-07-11T23:30:10.1176514Z T: 6368] INFO  : Status operation: 2048(WINHTTP_CALLBACK_STATUS_HANDLE_CLOSING )
2024-07-11T23:30:10.1214770Z 38: [2024-07-11T23:30:10.1176830Z T: 6368] DEBUG : Closing handle; completing outstanding Close request
2024-07-11T23:30:10.1216707Z 38: [2024-07-11T23:30:10.1177231Z T: 6368] INFO  : WinHttpRequest::~WinHttpRequest. Handle closed.
2024-07-11T23:30:10.1218332Z 38: [2024-07-11T23:30:10.1177832Z T: 6368] INFO  : HTTP/1.1 Response (159ms) : 203 Non-Authoritative Information
2024-07-11T23:30:10.1219250Z 38: access-control-expose-headers : REDACTED
2024-07-11T23:30:10.1222352Z 38: activityid : REDACTED
2024-07-11T23:30:10.1224434Z 38: cache-control : no-cache, no-store, must-revalidate
2024-07-11T23:30:10.1226694Z 38: content-length : 14992
2024-07-11T23:30:10.1228392Z 38: content-type : text/html; charset=utf-8
2024-07-11T23:30:10.1230522Z 38: date : Thu, 11 Jul 2024 23:30:09 GMT
2024-07-11T23:30:10.1231353Z 38: expires : -1
2024-07-11T23:30:10.1232250Z 38: p3p : REDACTED
2024-07-11T23:30:10.1233118Z 38: pragma : no-cache
2024-07-11T23:30:10.1233950Z 38: request-context : REDACTED
2024-07-11T23:30:10.1234694Z 38: set-cookie : REDACTED
2024-07-11T23:30:10.1235663Z 38: strict-transport-security : REDACTED
2024-07-11T23:30:10.1236401Z 38: x-cache : REDACTED
2024-07-11T23:30:10.1237255Z 38: x-content-type-options : REDACTED
2024-07-11T23:30:10.1238688Z 38: x-frame-options : REDACTED
2024-07-11T23:30:10.1239868Z 38: x-msedge-ref : REDACTED
2024-07-11T23:30:10.1240603Z 38: x-tfs-location : REDACTED
2024-07-11T23:30:10.1241287Z 38: x-tfs-processid : REDACTED
2024-07-11T23:30:10.1241995Z 38: x-tfs-session : REDACTED
2024-07-11T23:30:10.1242668Z 38: x-vss-e2eid : REDACTED
2024-07-11T23:30:10.1243349Z 38: x-vss-senderdeploymentid : REDACTED
2024-07-11T23:30:10.1244163Z 38: [2024-07-11T23:30:10.1178260Z T: 6368] INFO  : HTTP status code 203 won't be retried.
2024-07-11T23:30:10.1245144Z 38: [2024-07-11T23:30:10.1179163Z T: 6368] DEBUG : Identity: AzurePipelinesCredential : 203 (Non-Authoritative Information) response from the OIDC endpoint. Check service connection ID and Pipeline configuration.
…
2024-07-11T23:30:10.1368237Z 38: D:\a\_work\1\s\sdk\identity\azure-identity\test\ut\azure_pipelines_credential_test.cpp(676): error: Value of: std::string(ex.what()).find("302 (Found)") != std::string::npos
2024-07-11T23:30:10.1369235Z 38:   Actual: false
2024-07-11T23:30:10.1369885Z 38: Expected: true
2024-07-11T23:30:10.1370737Z 38: AzurePipelinesCredential : 203 (Non-Authoritative Information) response from the OIDC endpoint. Check service connection ID and Pipeline configuration.

There's a similar test in JS:
https://github.com/Azure/azure-sdk-for-js/blob/53c6a206264175dab476c613f8a254f9695fbb00/sdk/identity/identity/test/public/node/azurePipelinesCredential.spec.ts#L76-L89

@ahsonkhan
Copy link
Member Author

cc @kboom, @manolerazvan, @geekzter

@ahsonkhan
Copy link
Member Author

We have the investigation pending from the service team, to understand the expected behavior.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Status: Blocked
Development

No branches or pull requests

1 participant