iterable-android-sdk icon indicating copy to clipboard operation
iterable-android-sdk copied to clipboard

IterableAuthManager.decodedExpiration(): infinite retry loop caused by an ArrayIndexOutOfBoundsException

Open GBouerat opened this issue 1 year ago • 12 comments

The function IterableAuthManager.decodedExpiration() doesn't check the length of an array before reading the second index,

https://github.com/Iterable/iterable-android-sdk/blob/e8b65329c6b1882522e9bccb6df0b60e259492b2/iterableapi/src/main/java/com/iterable/iterableapi/IterableAuthManager.java#L131

so this happens:

ArrayIndexOutOfBoundsException: length=1; index=1 in IterableAuthManager.java:131

and when that happens, an auth token refresh is scheduled in 10 seconds which will encounter the same error and will lead to a kind of infinite loop.

Could you please do something about that ? thanks.

GBouerat avatar Aug 28 '23 11:08 GBouerat

A short logcat output about that:

2023-08-28 14:09:24.775 26119-26119 IterableAuth            com.*****.apps.android.*****.debug  E   ❤️ Error while parsing JWT for the expiration
                                                                                                    java.lang.ArrayIndexOutOfBoundsException: length=1; index=1
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager.decodedExpiration(IterableAuthManager.java:131)
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager.queueExpirationRefresh(IterableAuthManager.java:88)
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager$2.onSuccess(IterableAuthManager.java:51)
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager$2.onSuccess(IterableAuthManager.java:47)
                                                                                                    	at com.iterable.iterableapi.util.Future$2.run(Future.java:54)
                                                                                                    	at android.os.Handler.handleCallback(Handler.java:942)
                                                                                                    	at android.os.Handler.dispatchMessage(Handler.java:99)
                                                                                                    	at android.os.Looper.loopOnce(Looper.java:201)
                                                                                                    	at android.os.Looper.loop(Looper.java:288)
                                                                                                    	at android.app.ActivityThread.main(ActivityThread.java:7918)
                                                                                                    	at java.lang.reflect.Method.invoke(Native Method)
                                                                                                    	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
                                                                                                    	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:936)
2023-08-28 14:09:34.810 26119-26119 IterableAuth            com.*****.apps.android.*****.debug  E   ❤️ Error while parsing JWT for the expiration
                                                                                                    java.lang.ArrayIndexOutOfBoundsException: length=1; index=1
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager.decodedExpiration(IterableAuthManager.java:131)
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager.queueExpirationRefresh(IterableAuthManager.java:88)
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager$2.onSuccess(IterableAuthManager.java:51)
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager$2.onSuccess(IterableAuthManager.java:47)
                                                                                                    	at com.iterable.iterableapi.util.Future$2.run(Future.java:54)
                                                                                                    	at android.os.Handler.handleCallback(Handler.java:942)
                                                                                                    	at android.os.Handler.dispatchMessage(Handler.java:99)
                                                                                                    	at android.os.Looper.loopOnce(Looper.java:201)
                                                                                                    	at android.os.Looper.loop(Looper.java:288)
                                                                                                    	at android.app.ActivityThread.main(ActivityThread.java:7918)
                                                                                                    	at java.lang.reflect.Method.invoke(Native Method)
                                                                                                    	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
                                                                                                    	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:936)
2023-08-28 14:09:44.847 26119-26119 IterableAuth            com.*****.apps.android.*****.debug  E   ❤️ Error while parsing JWT for the expiration
                                                                                                    java.lang.ArrayIndexOutOfBoundsException: length=1; index=1
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager.decodedExpiration(IterableAuthManager.java:131)
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager.queueExpirationRefresh(IterableAuthManager.java:88)
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager$2.onSuccess(IterableAuthManager.java:51)
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager$2.onSuccess(IterableAuthManager.java:47)
                                                                                                    	at com.iterable.iterableapi.util.Future$2.run(Future.java:54)
                                                                                                    	at android.os.Handler.handleCallback(Handler.java:942)
                                                                                                    	at android.os.Handler.dispatchMessage(Handler.java:99)
                                                                                                    	at android.os.Looper.loopOnce(Looper.java:201)
                                                                                                    	at android.os.Looper.loop(Looper.java:288)
                                                                                                    	at android.app.ActivityThread.main(ActivityThread.java:7918)
                                                                                                    	at java.lang.reflect.Method.invoke(Native Method)
                                                                                                    	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
                                                                                                    	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:936)
2023-08-28 14:09:54.873 26119-26119 IterableAuth            com.*****.apps.android.*****.debug  E   ❤️ Error while parsing JWT for the expiration
                                                                                                    java.lang.ArrayIndexOutOfBoundsException: length=1; index=1
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager.decodedExpiration(IterableAuthManager.java:131)
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager.queueExpirationRefresh(IterableAuthManager.java:88)
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager$2.onSuccess(IterableAuthManager.java:51)
                                                                                                    	at com.iterable.iterableapi.IterableAuthManager$2.onSuccess(IterableAuthManager.java:47)
                                                                                                    	at com.iterable.iterableapi.util.Future$2.run(Future.java:54)
                                                                                                    	at android.os.Handler.handleCallback(Handler.java:942)
                                                                                                    	at android.os.Handler.dispatchMessage(Handler.java:99)
                                                                                                    	at android.os.Looper.loopOnce(Looper.java:201)
                                                                                                    	at android.os.Looper.loop(Looper.java:288)
                                                                                                    	at android.app.ActivityThread.main(ActivityThread.java:7918)
                                                                                                    	at java.lang.reflect.Method.invoke(Native Method)
                                                                                                    	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
                                                                                                    	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:936)

GBouerat avatar Aug 28 '23 12:08 GBouerat

Thank you @GBouerat for raising this issue with all the detailed logs!

What is the format of passed authToken here? Does it conform to jwt authtoken format? Or is it a case where empty/ different/ malformed string is passed?

Also, would be great if you could provide steps to reproduce this issue.

Thanks again.

Ayyanchira avatar Aug 28 '23 15:08 Ayyanchira

It happens when for some reasons one of ours debug builds returns an empty string "" from this method IterableAuthHandler.onAuthTokenRequested().

GBouerat avatar Aug 30 '23 06:08 GBouerat

The idea of retry was to overcome the situation where null or empty string would be passed by the app if the app is not ready with jwtToken. So SDK could give some time so the app can have it ready by the next fetch.

When we set authHandler to IterableConfig, it tells SDK that this is a jwt based project and the app will provide one as needed. From that point on, every request the SDK makes is validated against a jwtToken.

Would you be able to take a look into what makes the app return empty strings even for the subsequent attempts?

Ayyanchira avatar Aug 31 '23 01:08 Ayyanchira

Hi, we are facing a similar situation, is stated in the docs that the token will be requested in the following situations:

  • When your app sets the user's email or user ID.
  • When your app updates the user's email.
  • Before the current JWT expires.
  • When your app receives a 401 response from Iterable's API.

However the Iterable SDK is trying to get a token from the start even if we set the setAutoPushRegistration value as false.

In our particular case the user needs to log in order to make a request to the backend so we can't provide a token to the Iterable SDK right away. Our expectation is that as soon as the user logs in we get the JWT token from our backend, set the email in iterable, call registerForPush and the token is ready for the auth callbacks. Is this possible?

We can still do this but a lot of errors would happen in the background until the user logs in, is this expected? Thanks in advance.

punkrobot avatar Sep 19 '23 23:09 punkrobot

@Ayyanchira please help me, what token should be returned when the user logs out? If I give an empty token, there is an infinite try

baloghbalazsBB avatar Jan 19 '24 15:01 baloghbalazsBB

Hi, we are facing a similar situation, is stated in the docs that the token will be requested in the following situations:

  • When your app sets the user's email or user ID.
  • When your app updates the user's email.
  • Before the current JWT expires.
  • When your app receives a 401 response from Iterable's API.

However the Iterable SDK is trying to get a token from the start even if we set the setAutoPushRegistration value as false.

In our particular case the user needs to log in order to make a request to the backend so we can't provide a token to the Iterable SDK right away. Our expectation is that as soon as the user logs in we get the JWT token from our backend, set the email in iterable, call registerForPush and the token is ready for the auth callbacks. Is this possible?

We can still do this but a lot of errors would happen in the background until the user logs in, is this expected? Thanks in advance.

While the retry mechanism is being taken a look at, it will be advisable to get jwt token for logged in user first and then use setEmail(email, authToken) for logging in the user. This will avoid many null or 401 retry scenarios.

Ayyanchira avatar Feb 27 '24 14:02 Ayyanchira

Hi @GBouerat following up on this, please see our updated Android SDK version 3.5.1, which includes a change that should prevent this issue. Let us know your results!

jena-chakour avatar Mar 18 '24 15:03 jena-chakour

Now if the app return an empty token then no retry, but if the app return a null then log write this:

Auth token received as null. Calling the handler in 10 seconds

...but nothing happens And the IterableAuthManager will be deadlocked because the onAuthTokenRequested() method will never be called again

I have attached images about the code, which clearly show the cause: Screenshot 2024-04-18 at 10 43 09 Screenshot 2024-04-18 at 10 43 32

baloghbalazsBB avatar Apr 18 '24 09:04 baloghbalazsBB

Hi @punkrobot , @GBouerat ,and @baloghbalazsBB
We have updated the JWT retry mechanism and made it more stable. Please try out version 3.5.2 and let us know :)

Ayyanchira avatar May 22 '24 20:05 Ayyanchira

I just tried it, the retry really more stable :)

Some thoughts:

  • If you use pauseAuthRetries(true) then the retrying stops but the log still say: Auth token received as null. Calling the handler in 10 seconds
  • The requestNewAuthToken() is called from many places and now if it run while waiting for the retry then a new loop is created, so now 2-3 retry waiting cycles are in parallel. So it runs a retry every 3-4 seconds and the max retry count out in 40-60 seconds
  • The log doesn't give any information if a call is not executed because another one is in pending, or if the retry has run out
  • The retryCount is always increased, no matter if a retry happens or not (currently not a problem because the token rarely changes)

I think we won't update to this version, because the requestNewAuthToken() is too complex, and I afraid that this will cause problems in production. We prefer to use the version 3.5.1 without the retry mechanism.

baloghbalazsBB avatar May 29 '24 09:05 baloghbalazsBB

@baloghbalazsBB thank you for trying it out and providing such a great feedback. My team highly appreciated it! We will have updated docs released to help understand this recent change so it will be easier to understand how the retryCount and retry mechanism work.

If you use pauseAuthRetries(true) then the retrying stops but the log still say: Auth token received as null. Calling the handler in 10 seconds

Thanks for pointing this out. Will have this logging part updated

The log doesn't give any information if a call is not executed because another one is in pending, or if the retry has run out

Definitely great point. Incorporating more logs to understand why certain retries were skipped and when retryCount has maxed out 👍🏼 will be added in SDK

Ayyanchira avatar May 29 '24 16:05 Ayyanchira