AzureAD / microsoft-authentication-library-for-android

Microsoft Authentication Library (MSAL) for Android
http://aka.ms/aadv2
MIT License
218 stars 125 forks source link

NullPointerException on getLastTelemetryHeaderString() #2005

Closed choongyouqi closed 8 months ago

choongyouqi commented 10 months ago

Describe the bug Environment: Production.

in MFA, after entering 8-digit key and receiving a 2-digit number and approved in auth app, expected AuthenticationCallback.onSuccess, but received AuthenticationCallback.onError.

Smartphone (please complete the following information):

User A

User B

Stacktrace

Non-fatal Exception: com.microsoft.identity.client.exception.MsalClientException: Attempt to invoke virtual method 'int java.lang.String.hashCode()' on a null object reference
       at com.microsoft.identity.client.internal.controllers.MsalExceptionAdapter.msalExceptionFromBaseException(MsalExceptionAdapter.java:53)
       at com.microsoft.identity.client.PublicClientApplication$18.onError(PublicClientApplication.java:2204)
       at com.microsoft.identity.client.PublicClientApplication$18.onError(PublicClientApplication.java:2195)
       at com.microsoft.identity.common.java.controllers.CommandDispatcher.commandCallbackOnError(CommandDispatcher.java:642)
       at com.microsoft.identity.common.java.controllers.CommandDispatcher.access$900(CommandDispatcher.java:99)
       at com.microsoft.identity.common.java.controllers.CommandDispatcher$4.run(CommandDispatcher.java:622)
       at android.os.Handler.handleCallback(Handler.java:958)
       at android.os.Handler.dispatchMessage(Handler.java:99)
       at android.os.Looper.loopOnce(Looper.java:230)
       at android.os.Looper.loop(Looper.java:319)
       at android.app.ActivityThread.main(ActivityThread.java:8893)
       at java.lang.reflect.Method.invoke(Method.java)
       at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:608)
       at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1103)

Caused by com.microsoft.identity.common.java.exception.ClientException: Attempt to invoke virtual method 'int java.lang.String.hashCode()' on a null object reference
       at com.microsoft.identity.common.java.controllers.ExceptionAdapter.clientExceptionFromException(ExceptionAdapter.java:390)
       at com.microsoft.identity.common.java.controllers.ExceptionAdapter.baseExceptionFromException(ExceptionAdapter.java:349)
       at com.microsoft.identity.common.java.controllers.CommandDispatcher.executeCommand(CommandDispatcher.java:547)
       at com.microsoft.identity.common.java.controllers.CommandDispatcher.access$100(CommandDispatcher.java:99)
       at com.microsoft.identity.common.java.controllers.CommandDispatcher$5.run(CommandDispatcher.java:770)
       at io.opentelemetry.context.Context.lambda$wrap$1(Context.java:212)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
       at java.lang.Thread.run(Thread.java:1012)

Caused by java.lang.NullPointerException: Attempt to invoke virtual method 'int java.lang.String.hashCode()' on a null object reference
       at com.microsoft.identity.common.java.eststelemetry.FailedRequest.hashCode(FailedRequest.java:60)
       at java.util.HashMap.hash(HashMap.java:336)
       at java.util.HashMap.put(HashMap.java:608)
       at java.util.HashSet.add(HashSet.java:220)
       at com.microsoft.identity.common.java.eststelemetry.EstsTelemetry.getLastTelemetryHeaderString(EstsTelemetry.java:511)
       at com.microsoft.identity.common.java.eststelemetry.EstsTelemetry.getTelemetryHeaders(EstsTelemetry.java:548)
       at com.microsoft.identity.common.java.providers.oauth2.OAuth2Strategy.performTokenRequest(OAuth2Strategy.java:217)
       at com.microsoft.identity.common.java.providers.microsoft.microsoftsts.MicrosoftStsOAuth2Strategy.performTokenRequest(MicrosoftStsOAuth2Strategy.java:515)
       at com.microsoft.identity.common.java.providers.microsoft.microsoftsts.MicrosoftStsOAuth2Strategy.performTokenRequest(MicrosoftStsOAuth2Strategy.java:101)
       at com.microsoft.identity.common.java.providers.oauth2.OAuth2Strategy.requestToken(OAuth2Strategy.java:174)
       at com.microsoft.identity.common.java.controllers.BaseController.performTokenRequest(BaseController.java:415)
       at com.microsoft.identity.common.internal.controllers.LocalMSALController.acquireToken(LocalMSALController.java:172)
       at com.microsoft.identity.common.java.commands.InteractiveTokenCommand.execute(InteractiveTokenCommand.java:84)
       at com.microsoft.identity.common.java.commands.InteractiveTokenCommand.execute(InteractiveTokenCommand.java:46)
       at com.microsoft.identity.common.java.controllers.CommandDispatcher.executeCommand(CommandDispatcher.java:542)
       at com.microsoft.identity.common.java.controllers.CommandDispatcher.access$100(CommandDispatcher.java:99)
       at com.microsoft.identity.common.java.controllers.CommandDispatcher$5.run(CommandDispatcher.java:770)
       at io.opentelemetry.context.Context.lambda$wrap$1(Context.java:212)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
       at java.lang.Thread.run(Thread.java:1012)

To Reproduce Steps to reproduce the behavior:

Our Config

{
    "client_id": "xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx",
    "authorization_user_agent": "DEFAULT",
    "account_mode": "MULTIPLE",
    "broker_redirect_uri_registered": false,
    "redirect_uri": "msauth://packagename/[signature]",
    "authorities": [{
        "type": "AAD",
        "audience": {
            "type": "AzureADMyOrg",
            "tenant_id": "xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx"
        }
    }]
}

Invocation

val parameters = AcquireTokenParameters.Builder()
    .startAuthorizationFromActivity(requireActivity())
    .withScopes(listOf("User.Read"))
    .withCallback(authenticationCallback)
    .build()

PublicClientApplication
    .createMultipleAccountPublicClientApplication(activity.applicationContext, azureConfigFile)
    .acquireToken(parameters)

Expected behavior

Actual Behavior

What else have we tried

choongyouqi commented 10 months ago

Log from Logcat:

2024-01-17 12:59:27.637 11165-11961 BrowserAut...rowserFlow  I  [2024-01-17 04:59:27 - thread_id: 2, correlation_id: 83e16fec-d1be-4ae6-8ae4-e06fee44e12f - Android 34] Received redirect from customTab/browser.
2024-01-17 12:59:27.638 11165-11961 Authorizat...sendResult  I  [2024-01-17 04:59:27 - thread_id: 2, correlation_id: 83e16fec-d1be-4ae6-8ae4-e06fee44e12f - Android 34] Sending result from Authorization Activity, resultCode: COMPLETED
2024-01-17 12:59:27.638 11165-11961 LocalBroad...erCallback  I  [2024-01-17 04:59:27 - thread_id: 2, correlation_id: 83e16fec-d1be-4ae6-8ae4-e06fee44e12f - Android 34] Removing alias: cancel_authorization_request
2024-01-17 12:59:27.638 11165-11961 LocalBroad...:broadcast  I  [2024-01-17 04:59:27 - thread_id: 1479, correlation_id: UNSET - Android 34] broadcasting to alias: return_authorization_request_result
2024-01-17 12:59:27.649 11165-11961 LocalMSALC...ionSession  V  [2024-01-17 04:59:27 - thread_id: 1479, correlation_id: UNSET - Android 34] Completing authorization...
2024-01-17 12:59:27.667 11165-11961 CustomTabs...ger:unbind  I  [2024-01-17 04:59:27 - thread_id: 1479, correlation_id: UNSET - Android 34] CustomTabsService is unbound.
2024-01-17 12:59:27.684 11165-11961 MicrosoftS...tionResult  I  [2024-01-17 04:59:27 - thread_id: 1479, correlation_id: UNSET - Android 34] Auth code is successfully returned from webview redirect.
2024-01-17 12:59:27.690 11165-11961 LocalMSALC...tionResult  I  [2024-01-17 04:59:27 - thread_id: 1472, correlation_id: 83e16fec-d1be-4ae6-8ae4-e06fee44e12f - Android 34] Success Result
2024-01-17 12:59:27.693 11165-11961 LocalMSALC...tionResult  I  [2024-01-17 04:59:27 - thread_id: 1472, correlation_id: 83e16fec-d1be-4ae6-8ae4-e06fee44e12f - Android 34] Authorization Status: SUCCESS
2024-01-17 12:59:27.705 11165-11961 MicrosoftS...kenRequest  V  [2024-01-17 04:59:27 - thread_id: 1472, correlation_id: 83e16fec-d1be-4ae6-8ae4-e06fee44e12f - Android 34] Creating TokenRequest...
2024-01-17 12:59:27.705 11165-11961 BaseContro...kenRequest  I  [2024-01-17 04:59:27 - thread_id: 1472, correlation_id: 83e16fec-d1be-4ae6-8ae4-e06fee44e12f - Android 34] {"claims":"{}","x-app-name":"com.android.app","x-app-ver":"1.0.0","client_info":"1","client-request-id":"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","client_id":"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","grant_type":"authorization_code","redirect_uri":"msauth://com.android.app/xxxxxxxxxxxxxxxxxxxxxxxxxxxx","scope":"User.Read openid offline_access profile"}
2024-01-17 12:59:27.719 11165-11961 OAuth2Stra...questToken  V  [2024-01-17 04:59:27 - thread_id: 1472, correlation_id: 83e16fec-d1be-4ae6-8ae4-e06fee44e12f - Android 34] Requesting token...
2024-01-17 12:59:27.724 11165-11961 OAuth2Stra...kenRequest  V  [2024-01-17 04:59:27 - thread_id: 1472, correlation_id: 83e16fec-d1be-4ae6-8ae4-e06fee44e12f - Android 34] Performing token request...
2024-01-17 12:59:27.747 11165-11961 LocalBroad...erCallback  I  [2024-01-17 04:59:27 - thread_id: 1472, correlation_id: 83e16fec-d1be-4ae6-8ae4-e06fee44e12f - Android 34] Removing alias: return_authorization_request_result
2024-01-17 12:59:27.747 11165-11961 CommandDis...nteractive  I  [2024-01-17 04:59:27 - thread_id: 1472, correlation_id: 83e16fec-d1be-4ae6-8ae4-e06fee44e12f - Android 34] Completed interactive request for correlation id : **83e16fec-d1be-4ae6-8ae4-e06fee44e12f, with the status : ERROR
2024-01-17 12:59:27.750 11165-11961 LastReques...metryCache  V  [2024-01-17 04:59:27 - thread_id: 1472, correlation_id: 83e16fec-d1be-4ae6-8ae4-e06fee44e12f - Android 34] Saving Last Request Telemetry to cache...
2024-01-17 12:59:27.768 11165-11165 System.err               W  com.microsoft.identity.client.exception.MsalClientException: Attempt to invoke virtual method 'int java.lang.String.hashCode()' on a null object reference
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.client.internal.controllers.MsalExceptionAdapter.msalExceptionFromBaseException(MsalExceptionAdapter.java:53)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.client.PublicClientApplication$18.onError(PublicClientApplication.java:2204)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.client.PublicClientApplication$18.onError(PublicClientApplication.java:2195)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.controllers.CommandDispatcher.commandCallbackOnError(CommandDispatcher.java:642)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.controllers.CommandDispatcher.access$900(CommandDispatcher.java:99)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.controllers.CommandDispatcher$4.run(CommandDispatcher.java:622)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at android.os.Handler.handleCallback(Handler.java:958)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at android.os.Handler.dispatchMessage(Handler.java:99)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at android.os.Looper.loopOnce(Looper.java:230)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at android.os.Looper.loop(Looper.java:319)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at android.app.ActivityThread.main(ActivityThread.java:8893)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at java.lang.reflect.Method.invoke(Native Method)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:608)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1103)
2024-01-17 12:59:27.768 11165-11165 System.err               W  Caused by: com.microsoft.identity.common.java.exception.ClientException: Attempt to invoke virtual method 'int java.lang.String.hashCode()' on a null object reference
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.controllers.ExceptionAdapter.clientExceptionFromException(ExceptionAdapter.java:390)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.controllers.ExceptionAdapter.baseExceptionFromException(ExceptionAdapter.java:349)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.controllers.CommandDispatcher.executeCommand(CommandDispatcher.java:547)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.controllers.CommandDispatcher.access$100(CommandDispatcher.java:99)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.controllers.CommandDispatcher$5.run(CommandDispatcher.java:770)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at io.opentelemetry.context.Context.lambda$wrap$1(Context.java:212)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at io.opentelemetry.context.Context$$ExternalSyntheticLambda4.run(Unknown Source:4)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at java.lang.Thread.run(Thread.java:1012)
2024-01-17 12:59:27.768 11165-11165 System.err               W  Caused by: java.lang.NullPointerException: Attempt to invoke virtual method 'int java.lang.String.hashCode()' on a null object reference
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.eststelemetry.FailedRequest.hashCode(FailedRequest.java:60)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at java.util.HashMap.hash(HashMap.java:336)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at java.util.HashMap.put(HashMap.java:608)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at java.util.HashSet.add(HashSet.java:220)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.eststelemetry.EstsTelemetry.getLastTelemetryHeaderString(EstsTelemetry.java:511)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.eststelemetry.EstsTelemetry.getTelemetryHeaders(EstsTelemetry.java:548)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.providers.oauth2.OAuth2Strategy.performTokenRequest(OAuth2Strategy.java:217)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.providers.microsoft.microsoftsts.MicrosoftStsOAuth2Strategy.performTokenRequest(MicrosoftStsOAuth2Strategy.java:515)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.providers.microsoft.microsoftsts.MicrosoftStsOAuth2Strategy.performTokenRequest(MicrosoftStsOAuth2Strategy.java:101)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.providers.oauth2.OAuth2Strategy.requestToken(OAuth2Strategy.java:174)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.controllers.BaseController.performTokenRequest(BaseController.java:415)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.internal.controllers.LocalMSALController.acquireToken(LocalMSALController.java:172)
2024-01-17 12:59:27.768 11165-11165 System.err               W      at com.microsoft.identity.common.java.commands.InteractiveTokenCommand.execute(InteractiveTokenCommand.java:84)
2024-01-17 12:59:27.769 11165-11165 System.err               W      at com.microsoft.identity.common.java.commands.InteractiveTokenCommand.execute(InteractiveTokenCommand.java:46)
2024-01-17 12:59:27.769 11165-11165 System.err               W      at com.microsoft.identity.common.java.controllers.CommandDispatcher.executeCommand(CommandDispatcher.java:542)
2024-01-17 12:59:27.769 11165-11165 System.err               W      ... 7 more
choongyouqi commented 10 months ago

On further checking, it's happening to devices with Microsoft Authenticator installed. even if I signed in with a personal account.

Once it happened, retrying the same flow in the app after uninstalling Microsoft Authenticator will still hit the same exception. The user will need to clear data of the app only it will work correctly after

negoe commented 10 months ago

@choongyouqi Please update your configuration "broker_redirect_uri_registered": true' and test again.

negoe commented 8 months ago

No response, closing issue.