As an IAM practitioner, handling issues related to authentication failures are very common. There are some issues, which are not straightforward and solving those, gives us insight on how authentication is integrated with underlying system components. Finding the failure can be very tricky. Some issues are described here.

Today, I am going to talk about a mysterious authentication failure of Az login

Issue Description

User unable to login using Az Login, it was failing with the error

Get token request returned error: 400 and server response: ("error": interaction_requi red" , "error _ description AADSTS5303: Access has been blocked by Conditional Access policies. The access policy does not allow token issuance. .......

Troubleshooting

Interestingly, Azure AD SignIn logs shows login was successful and no CA Policy was applying for this login and blocking.

                       

Conditional Access What-If tools with same parameters - user/apps/location/device also shows no CA policy is applying and hence login should work.  

Looking the sign in event little closely shows that the Correlation ID in this event is different from what was returned on the shell.

Correlation ID in SignIn Event                                  Correlation returned from AZ Login                      

                                     

Searching the correlation id in sign in logs returned no results. We seems to hit a roadblock with further investigation, so we engaged Microsoft Support. They looked into their backend logs and found the Correlation ID of Az Login and informed us the name of the policy which was blocking and the reason.

To our surprise, we found that the request failed because of the policy, which prevent access from un-trusted location. Further we found that it was a different IP than what we see in our Azure AD SignIn logs. This IP is indeed not part of trusted location.  

To dig further, we ran the Az Login with --debug switch

Event: CommandInvoker.OnPostParseArgs [<function OutputProducer.handle_output_argument at 0x04277A98>, <function CLIQuery.handle_query_parameter at ......

Windows is detected. Set HTTPServer.allow_reuse_address to False

Open browser with url: https://login.microsoftonline.com/common/oauth2/authorize?response_type=code&client_id=XXXXXXX&redirect_uri=http://localhost:8400&state=s26xxxxpc&resource=https://management.core.windows.net/&prompt=select_account

adal-python : 270e2801-XXXX-b55680b3c778 - Authority:Performing instance discovery: ...

adal-python : 270e2801-XXXX-844f-b55680b3c778 - Authority:Performing static instance discovery

adal-python : 270e2801-XXXX-844f-b55680b3c778 - Authority:Authority validated via static instance discovery

adal-python : 270e2801-XXXX-b55680b3c778 - TokenRequest:Getting token with auth code.

urllib3.connectionpool : Starting new HTTPS connection (1): login.microsoftonline.com:443

urllib3.connectionpool : https://login.microsoftonline.com:443 "POST /common/oauth2/token HTTP/1.1" 400 567

cli.azure.cli.core.util : Get Token request returned http error: 400 and server response: {"error":"interaction_required","error_description":"AADSTS53003: Access has been blocked by Conditional Access policies. The access policy does not allow token issuance.\r\nTrace ID: XXX-XXXX-XXXX1\r\nCorrelation ID: XXXX-XXXXX\r\nTimestamp: YYYY-MM-DD HH:MM:SSZ","error_codes":[53003],"timestamp":"YYYY-MM-DD HH:MM:SSZZ","trace_id":"XXXXXX","correlation_id":"XXXXXXX","error_uri":"https://login.microsoftonline.com/error?code=53003","suberror":"message_only"}

This debug log reveals many things.

Az Login is doing OAuth2 Authorize code flow

Keeping above flow in mind, let us run through the logs and user experience.

Step 1 - App pop up a browser dialog and collect user name and request for Authorization code, it is clear from the below logs

https://login.microsoftonline.com/common/oauth2/authorize?response_type=code&client_id=..... resource=https://management.core.windows.net/&prompt=select_account

endpoint - https://login.microsoftonline.com/common/oauth2/authorize

response_Type=code -> It is expecting a code in response. If authentication successful, AAD returns code

client_id –XXX-XXX - This is the client representation of Azure CLI in Azure AD.

resource=https://management.core.windows.net – This is the API or resource where Azure CLI wants to connect.

prompt=select_account - This interrupt sign in and list any accounts in session(already logged in) or provide options to choose a  different account

Step 2 – User completes policy – Which means, user perform authentication.

Step 3 – If step 2 is successful, AAD, returns Authorization code. In our case, it appears that step 2 was successful, as we are creating another request for the token endpoint.

adal-python : 270e2801-XXXX-b55680b3c778 - Authority:Performing instance discovery: …

adal-python : 270e2801-XXXX-844f-b55680b3c778 - Authority:Performing static instance discovery

adal-python : 270e2801-XXXX-844f-b55680b3c778 - Authority:Authority validated via static instance discovery

urllib3.connectionpool : Starting new HTTPS connection (1): login.microsoftonline.com:443

urllib3.connectionpool : https://login.microsoftonline.com:443 "POST /common/oauth2/token HTTP/1.1" 400 567

Step 4 – Request for OAuth2 token, this is where it was failed. Since this is not interactive login, event is not logged in Azure AD SignIn logs. This is where the CA Policy is applying and blocking the request, as the request was made from a non-trusted IP Address.

cli.azure.cli.core.util : Get Token request returned http error: 400 and server response: {"error":"interaction_required","error_description":"AADSTS53003: Access has been blocked by Conditional Access policies

User has not done anything different to request a token, he just initiated Az Login command, so why it was successful in the first place, when hit the /authorization end point and why it was failed /token endpoint. It appears that the IP Address changed between calling /authorize endpoint and /token endpoint.

For /authorization endpoint, we see a popup so connection to internet seems to use corporate proxy, settings configured in Internet Explorer.  Assuming that Az Login is using WinHTTP to send HTTP request, we query what proxy is configured for WinHTTP, using the below command.

Netsh winhttp show proxy

Interestingly, we found the same corporate proxy was configured as in Internet Explorer. It makes clear that Az login is not using WinHTTP to send HTTP request.

It appears that Az Login is sending HTTP call using default windows environment, which is using direct internet connection. We can change this behavior setting the Environment Variable – HTTP_Proxy, which can be done by using the below command

set HTTP_PROXY=http://proxy_userid:proxy_password@proxy_ip:proxy_port

Finally, it resolved by setting above proxy configuration.

What are some of the learnings?

1. Azure AD SignIn logs only report Interactive-SignIn, where user manually provides his username. It does not report non-interactive SignIn, where user interaction is not needed and application makes silent call.

2. In single user sign in journey, CA Policy applies separately, for /authorization endpoint and /token endpoint.

3. The way application is designed and use underlying OS environment, it is possible that parameters  changes even in single user SignIn journey.