search

AzureAD / microsoft-authentication-library-for-objc

Microsoft Authentication Library (MSAL) for iOS and macOS
http://aka.ms/aadv2
MIT License
259 stars 141 forks source link

Regression #2187

Open ShmuelCammebys opened 3 months ago

ShmuelCammebys commented 3 months ago

We are experiencing this issue in production for macOS users on Sonoma 14.5 (23F79), as well as iOS 17.4.1: https://github.com/AzureAD/microsoft-authentication-library-for-objc/issues/1123

Veena11 commented 1 month ago

@ShmuelCammebys , I did a quick test on Sonoma 14.5 and I couldn't reproduce the issue. I was able to get the token successfully. Could you provide steps for repro failing logs as well as the MSAL version that you are using?

ShmuelCammebys commented 1 month ago

It is indeed pretty rare and unpredictable. I think this is the right log:

Default
debug
02:59:08.494
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:59:08 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] acquireToken returning with error: (MSALErrorDomain, -50005) Masked(not-null)
Default
debug
02:59:08.494
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:59:08 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Interactive flow finished. Result (null), error: -51700 error domain: MSIDErrorDomain
Default
debug
02:59:08.494
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:59:08 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Result from authorization session callbackURL host: (null) , has error: YES
Default
debug
02:59:08.493
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:59:08] Creating Error with description: User cancelled the authorization session.
Ui Lifecycle
info
02:58:49.526

{
beingPresented: false,
is_window_rootViewController: true,
screen: UIInputWindowController,
window: <UITextEffectsWindow: 0x106814e00; frame = (0 0; 414 896); opaque = NO; autoresize = W+H; layer = <UIWindowLayer: 0x300f7eee0>>,
window_isKeyWindow: false,
window_windowLevel: 10.000000
}
Default
debug
02:58:49.177
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Start webview authorization session with webview controller class MSIDSystemWebviewController: 
Default
debug
02:58:49.176
[MSAL] TID=91487 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Parsed response: (not-null), error (null), error domain: (null), error code: 0
Default
debug
02:58:49.176
[MSAL] TID=91487 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Received network response: (not-null), error (null)
HTTP
info
02:58:49.173
GET: https://login.microsoftonline.com/<uuid>/v2.0/.well-known/openid-configuration [200]

{
reason: no error,
request_body_size: 0,
response_body_size: 1753
}
Default
debug
02:58:49.097
[MSAL] TID=91485 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Returned from Authority Validation Queue
Default
debug
02:58:49.097
[MSAL] TID=91483 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Sending network request: (not-null), headers: (not-null)
Default
debug
02:58:49.097
[MSAL] TID=91483 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Resolved authority, validated: YES, error: 0
Default
debug
02:58:49.097
[MSAL] TID=91483 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] networkHost: login-us.microsoftonline.com, cacheHost: login-us.microsoftonline.com, aliases: login-us.microsoftonline.com
Default
debug
02:58:49.097
[MSAL] TID=91483 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] networkHost: login.microsoftonline.us, cacheHost: login.microsoftonline.us, aliases: login.microsoftonline.us, login.usgovcloudapi.net
Default
debug
02:58:49.096
[MSAL] TID=91483 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] networkHost: login.microsoftonline.de, cacheHost: login.microsoftonline.de, aliases: login.microsoftonline.de
Default
debug
02:58:49.095
[MSAL] TID=91483 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] networkHost: login.partner.microsoftonline.cn, cacheHost: login.partner.microsoftonline.cn, aliases: login.partner.microsoftonline.cn, login.chinacloudapi.cn
Default
debug
02:58:49.095
[MSAL] TID=91483 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] networkHost: login.microsoftonline.com, cacheHost: login.windows.net, aliases: login.microsoftonline.com, login.windows.net, login.microsoft.com, sts.windows.net
Default
debug
02:58:49.095
[MSAL] TID=91483 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Caching AAD Environements
Default
debug
02:58:49.094
[MSAL] TID=91483 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Parsed response: (not-null), error (null), error domain: (null), error code: 0
Default
debug
02:58:49.094
[MSAL] TID=91483 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Received network response: (not-null), error (null)
HTTP
info
02:58:49.093
GET: https://login.microsoftonline.com/common/discovery/instance [200]

{
http.query: api-version=1.1&authorization_endpoint=https://login.microsoftonline.com/<uuid>/oauth2/v2.0/authorize,
reason: no error,
request_body_size: 0,
response_body_size: 980
}
Default
debug
02:58:49.025
[MSAL] TID=91484 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:49] session:didReceiveChallenge:completionHandler - nsurlauthenticationmethodservertrust. Host: login.microsoftonline.com. Previous challenge failure count: 0
Default
debug
02:58:48.921
[MSAL] TID=91485 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Waiting on Authority Validation Queue
Default
debug
02:58:48.919
[MSAL] TID=91485 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Sending network request: (not-null), headers: (not-null)
Default
debug
02:58:48.890
[MSAL] TID=91485 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] No cached preferred_network for authority
Default
debug
02:58:48.889
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Resolving authority: Masked(not-null), upn: Masked(null)
Default
debug
02:58:48.889
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48] Start background app task with type 0 & taskId : 3
Default
debug
02:58:48.889
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] Beginning interactive flow.
Default
debug
02:58:48.888
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48 - 30335059-0748-4504-B76C-27F0C99C7881] [MSAL] -[MSALPublicClientApplication acquireTokenWithParameters:(
    "User.Read"
)
                                     extraScopesToConsent:(null)
                                                  account:Masked(null)
                                                loginHint:Masked(null)
                                               promptType:MSALPromptTypePromptIfNecessary
                                     extraQueryParameters:(null)
                                                authority:(null)
                                              webviewType:MSALWebviewTypeDefault
                                            customWebview:No
                                            correlationId:(null)
                                             capabilities:(null)
                                            claimsRequest:(null)]
Default
debug
02:58:48.888
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48] Intune Resource JSON is nil.
Default
debug
02:58:48.888
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48] Intune Resource JSON is nil.
Default
debug
02:58:48.888
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48] Requiring default broker type due to app being built with iOS 13 SDK
Default
debug
02:58:48.888
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48] Init MSIDKeychainTokenCache with keychainGroup: Masked(not-null)
Default
debug
02:58:48.887
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48] Using "Masked(not-null)" Team ID.
Default
debug
02:58:48.887
[MSAL] TID=91475 MSAL 1.3.3 iOS 17.5.1 [2024-07-12 14:58:48] Default app's access group: "Masked(not-null)".
Ui Lifecycle
info
02:58:48.879

{
beingPresented: false,
is_window_rootViewController: false,
parentViewController: PresentationHostingController<AnyView>,
presentingViewController: UIHostingController<ModifiedContent<AnyView, RootModifier>>,
screen: UIMSALAuthPresentationViewController,
window: <UIWindow: 0x102625380; frame = (0 0; 414 896); autoresize = W+H; gestureRecognizers = <NSArray: 0x300f3e220>; layer = <UIWindowLayer: 0x300f3e070>>,
window_isKeyWindow: true,
window_windowLevel: 0.000000
}
Ui Lifecycle
info
02:58:48.878

{
beingPresented: true,
is_window_rootViewController: false,
presentingViewController: UIHostingController<ModifiedContent<AnyView, RootModifier>>,
screen: PresentationHostingController<AnyView>,
window: <UIWindow: 0x102625380; frame = (0 0; 414 896); autoresize = W+H; gestureRecognizers = <NSArray: 0x300f3e220>; layer = <UIWindowLayer: 0x300f3e070>>,
window_isKeyWindow: true,
window_windowLevel: 0.000000
}
App Lifecycle
info
02:58:48.512

{
state: foreground
}
Ui Lifecycle
info
02:58:48.373

{
beingPresented: false,
is_window_rootViewController: true,
screen: UIHostingController<ModifiedContent<AnyView, RootModifier>>,
window: <UIWindow: 0x102625380; frame = (0 0; 414 896); autoresize = W+H; gestureRecognizers = <NSArray: 0x300f3e220>; layer = <UIWindowLayer: 0x300f3e070>>,
window_isKeyWindow: true,
window_windowLevel: 0.000000
}
Device Orientation
info
02:58:48.306

{
position: portrait
}
Default
info
02:58:48.305
application: $<_TtC7SwiftUIP33_ACC2C5639A7D76F611E170E831FCA49118SwiftUIApplication: 0x1026046e0>, didFinishLaunchingWithOptions: nil
Veena11 commented 1 month ago

Is this happening when user clicks on continue from Safari browser ? could you help me understand the flow sequence that leads to this error ? Please share the full MSAL logs which includes the steps that lead to this error

ShmuelCammebys commented 1 month ago

To be honest, I don't remember fully, and I don't have access to logs older than 30 days. However it is one of two possibilities. And the previous message contains the full logs from app startup until MSAL returns to our app which reports the error. The previous log ends with an error of code -50005, so I assumed they were the same issue.

  1. Happens when user clicks continue
  2. Happens after user approves login and the MSAL response should theoretically include the token but instead includes the error.

Flow:

  1. App calls acquireToken(with: interactiveParams...)
  2. Modal dialog pops up asking if the user wants to continue with the interactive login in a browser window
  3. User clicks "Continue"
  4. Either returns from acquireToken here with error and no token, or opens a browser window with the login screen
  5. If opens browser, user completes login flow from browser window and browser window closes (once login is complete)
  6. Control returns to app and acquireToken returns with error and no token.
Veena11 commented 4 weeks ago

@ShmuelCammebys , Thanks for the logs. Unfortunately the logs you provided doesnt have entries that lead to the error -50005. When ASWebAuthenticationSession was failing in the previous bug, the issue was consistently reproducing on beta version. But your issue seems to be intermittent and happening on stable OS version, I suspect this might be because of some other issue. Hence please provide full logs for the repro, so that we can take a deeper look.