Mysterious Authentication failure of Az Login
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
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.