Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
GBouerat opened this issue Aug 28, 2023 · 12 comments · Fixed by #733

Comments

@GBouerat
Copy link

GBouerat commented Aug 28, 2023

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

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 GBouerat changed the title IterableAuthManager.decodedExpiration(): ArrayIndexOutOfBoundsException IterableAuthManager.decodedExpiration(): infinite retry loop caused by an ArrayIndexOutOfBoundsException Aug 28, 2023
@GBouerat
Copy link
Author

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)

@Ayyanchira
Copy link
Member

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.

@GBouerat
Copy link
Author

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

@Ayyanchira
Copy link
Member

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?

@punkrobot
Copy link

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.

@baloghbalazsBB
Copy link

@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

@Ayyanchira
Copy link
Member

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.

@jena-chakour
Copy link
Contributor

jena-chakour commented Mar 18, 2024

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!

@baloghbalazsBB
Copy link

baloghbalazsBB commented Apr 18, 2024

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

@Ayyanchira Ayyanchira linked a pull request May 22, 2024 that will close this issue
@Ayyanchira
Copy link
Member

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 :)

@baloghbalazsBB
Copy link

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.

@Ayyanchira
Copy link
Member

@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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants