microsoft-authentication-library-for-android icon indicating copy to clipboard operation
microsoft-authentication-library-for-android copied to clipboard
verified publisher icon AzureAD

NullPointerException on getLastTelemetryHeaderString()

Open choongyouqi opened this issue 2 years ago • 3 comments

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

  • Device: SM-S908E (Samsung Galaxy S22 Ultra)
  • Android Version: 14
  • Screen: [dpi: 600, height: 2932, width: 1440]
  • Browser: Chrome Custom Tabs after setting broker_redirect_uri_registered: false
  • MSAL Version: 5.0.0

User B

  • Device: Xiaomi POCO F2 Pro
  • Android Version: 12
  • Screen: [dpi: 440, height: 2270, width: 1080]
  • Browser: Chrome Custom Tabs after setting broker_redirect_uri_registered: false
  • MSAL Version: 5.0.0

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

  • AuthenticationCallback.onSuccess.
  • it works fine on some phones that we tested (OnePlus 8T, OnePlus 6T, Samsung S20 FE 5G) but not on the stated phones above.

Actual Behavior

  • get AuthenticationCallback.onError callback with MsalException(error_code = "unknown_error", message: "Attempt to invoke virtual method 'int java.lang.String.hashCode()' on a null object reference")

What else have we tried

  • We have clear data for Chrome app and issue still persist.

choongyouqi avatar Jan 16 '24 08:01 choongyouqi

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 avatar Jan 17 '24 05:01 choongyouqi

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

choongyouqi avatar Jan 17 '24 06:01 choongyouqi

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

negoe avatar Jan 29 '24 01:01 negoe

No response, closing issue.

negoe avatar Mar 26 '24 14:03 negoe