Sunday 7 March 2021

Kotlin Coroutine throws JobCancellationException and trigger observers

I'm implementing kotlin coroutines in MVVM architecture in order to replace my RxJava dependency.

My problem: After logging out (this detail is important because I don't have the exception on a fresh start), I have a JobCancellationException coroutine exception thrown on the launch of the viewModelScope AND all of my observers in the LoginActivity are triggered (wtf ?) even if the try/catch block is not executed (breakpoint) so it totally breaks my code logic.

My layers are as follows: Activity, setOnClickListener triggered, call viewModel function -> ViewModel, create coroutine within viewModelScope and call suspend function -> Repository, suspended function called from viewModel and call a suspend function in ApiService -> suspend function that makes the Api call

Usecase: I log in my app freshly started (LoginActivity). My stack is cleared to start the MainActivity. I go to the SettingsActivity to logout. I logout and clear the stack once again to start a brand new LoginActivity. And when I try to login again I have the exception thrown and my observers are triggered.

LoginActivty:

override fun onCreate(savedInstanceState: Bundle?) {
        super.onCreate(savedInstanceState)
        setContentView(R.layout.activity_login)
        tvLogin.setSafeOnClickListener { login() }
}
private fun login() {
        Firebase.analytics.logEvent("hit_login", null)
        runOnUiThread {
            pDialog = SweetAlertDialog(this, SweetAlertDialog.PROGRESS_TYPE)
            pDialog!!.progressHelper.barColor = Color.parseColor("#2A6022")
            pDialog!!.titleText =
                "<font color='#2A6022'>" + resources.getString(R.string.signing) + "</font>"
            pDialog!!.setCancelable(false)
        }
        var pwd = etPassword.text.toString()
        if (passedBiometric) {
            pwd = sessionManager.decrypt(sessionManager.loadUsername())
        }
        passedBiometric = false
        viewModel.login(etUsername.text.toString(), pwd)
        viewModel.error.observe(this, {
            Toast.makeText(this, getString(it), Toast.LENGTH_SHORT).show()
        })
        viewModel.loadingState.observe(this, {
        Timber.e("LoadingState Observer triggered")
            when (it) {
                LoadingState.LOADED -> {
                    pDialog!!.dismiss()
                    Timber.e("LOADED")
                    startMainActivity()
                }
                LoadingState.FAILED -> {
                    pDialog!!.dismiss()
                    Timber.e("FAILED")
                    viewModel.error.value?.let { errorRsc ->
                        Toast.makeText(this, getString(errorRsc), Toast.LENGTH_SHORT).show()
                    }
                }
                LoadingState.LOADING -> {
                    pDialog!!.show()
                    Timber.e("LOADING")
                }
            }
        })
  }

private fun startMainActivity() {
    val intent = Intent(this, MainActivity::class.java)
    intent.flags = Intent.FLAG_ACTIVITY_NEW_TASK or Intent.FLAG_ACTIVITY_CLEAR_TASK
    intent.action = this.intent.action
    intent.putExtra(ProfileFragment.USER, viewModel.user.value)
    startActivity(intent)
    finish()
}

LoginViewModel:

class LoginViewModel(private val repo: ApiRepository, private val sessionManager: SessionManager) :
    ViewModel() {
    private val _error = MutableLiveData<Int>()
    val error: LiveData<Int>
        get() = _error
    private val _loadingState = MutableLiveData<LoadingState>()
    val loadingState: LiveData<LoadingState>
        get() = _loadingState
    private val token = MutableLiveData<SessionToken>()
    private val _user = MutableLiveData<User>()
    val user: LiveData<User>
        get() = _user

fun login(username: String, password: String) {
    try {
        Timber.e("enter try block outside viewModelScope.launch")
        viewModelScope.launch {
            try {
                Timber.e("try block inside viewModelScope.launch")
                _loadingState.value = LoadingState.LOADING
                token.value = repo.login(username, password)
                sessionManager.storeSessionToken(token.value!!.token)
                sessionManager.storeUsername(username)
                sessionManager.encrypt(username, password)
                _user.value = repo.getUser()
                _loadingState.value = LoadingState.LOADED
            } catch (e: Exception) {
                Timber.e("catch block inside viewModelScope.launch")
                if (e is HttpException) {
                    when (e.code()) {
                        500, 503 -> {
                            _error.value = R.string.error_api_down
                        }
                        400 -> {
                            _error.value = R.string.error_bad_credentials
                        }
                    }
                }
                _loadingState.value = LoadingState.FAILED
            }
        }
    }
    catch (e: Exception){
        Timber.e("Catch block outside viewmodelScope.launch")
        when (e){
            is CancellationException -> { Timber.e("CancellationException caught")}
            else -> { Timber.e("Unknown caught")}
        }
    }
}

}

ApiRepository:

class ApiRepository(
    private val apiService: ApiService,
    private val sessionManager: SessionManager
) {
    suspend fun login(username: String, password: String): SessionToken {
        val map = mutableMapOf<String, String>()
        map["username"] = username
        map["password"] = password
        return apiService.login(
            JSONObject(map.toMap()).toString()
                .toRequestBody("application/json".toMediaTypeOrNull())
        )
    }

    suspend fun getUser(): User {
        return apiService.getUser(sessionManager.loadSessionToken())
    }

}

ApiService:

interface ApiService {
    companion object {
        private const val AUTH = "Authorization"
    }
    @POST(ApiRouting.URL_TOKEN)
    suspend fun login(@Body requestBody: RequestBody): SessionToken
    @GET(ApiRouting.URL_GET_USER)
    suspend fun getUser(@Header(AUTH) token: String): User

}

SettingsActivity:

private fun initListeners() {
    tvLogout.setSafeOnClickListener {
        DashboardManager.clearValues()
        sessionManager.clearSessionToken()
        val intent = Intent(this, LoginActivity::class.java)
        intent.flags = Intent.FLAG_ACTIVITY_NEW_TASK or Intent.FLAG_ACTIVITY_CLEAR_TASK
        startActivity(intent)
        finish()
    }
}

TLDR: Why the exception is thrown ? Why the observers are triggered ? And Why is this situation only occurs after a logout and not on fresh start ?

I tried to add coroutineScope in the launch and another scope in the repository with withContext(Dispatchers.IO) but it didn't change anything

I'm a very beginner in kotlin coroutines so if you have any suggestion, link or whatever that might help welcome. Or if you need any other block of code let me know.

EDIT: I added several log (LoginViewModel and MainActivity) to detail when I enter in try catch block that surround my viewModelScope.launch and when my MainActivity start (next action after my observer is triggered in the LoginAvtivity.

To let you see more visibility on what a fresh (and successful) start looks like:

E/LoginViewModel: enter try block outside viewModelScope.launch
E/LoginViewModel$login: try block inside viewModelScope.launch
E/LoginActivity$login: LoadingState Observer triggered
V/ViewRootImpl: The specified message queue synchronization  barrier token has not been posted or has already been removed
E/LoginActivity$login: LOADING
    LoadingState Observer triggered
    LOADING
I/okhttp.OkHttpClient: --> POST http://45.153.184.141/api-token-auth/
    Content-Type: application/json; charset=utf-8
    Content-Length: 46
    --> END POST (46-byte body)
E/LoginActivity$login: LoadingState Observer triggered
    LOADING
D/DecorView: onWindowFocusChangedFromViewRoot hasFocus: true, DecorView@7175d32[LoginActivity]
W/Choreographer: Already have a pending vsync event.  There should only be one at a time.
V/ViewRootImpl: The specified message queue synchronization  barrier token has not been posted or has already been removed
W/Choreographer: Already have a pending vsync event.  There should only be one at a time.
I/okhttp.OkHttpClient: <-- 200 OK http://xx.xx.xx.xx/api-token-auth/ (237ms)
    Date: Wed, 03 Mar 2021 21:31:39 GMT
    Server: WSGIServer/0.2 CPython/3.8.2
    Content-Type: application/json
    Allow: POST, OPTIONS
    X-Frame-Options: DENY
    Content-Length: 52
    Vary: Cookie
    X-Content-Type-Options: nosniff
    <-- END HTTP (52-byte body)
W/r.myweedmanage: Accessing hidden method Lsun/misc/Unsafe;->getObject(Ljava/lang/Object;J)Ljava/lang/Object; (greylist, linking, allowed)
    Accessing hidden method Lsun/misc/Unsafe;->putObject(Ljava/lang/Object;JLjava/lang/Object;)V (greylist, linking, allowed)
W/r.myweedmanage: Accessing hidden method Lsun/misc/Unsafe;->getObject(Ljava/lang/Object;J)Ljava/lang/Object; (greylist, linking, allowed)
    Accessing hidden method Lsun/misc/Unsafe;->putInt(Ljava/lang/Object;JI)V (greylist, linking, allowed)
W/r.myweedmanage: Accessing hidden method Lsun/misc/Unsafe;->getLong(Ljava/lang/Object;J)J (greylist,core-platform-api, linking, allowed)
    Accessing hidden method Lsun/misc/Unsafe;->getLong(Ljava/lang/Object;J)J (greylist,core-platform-api, linking, allowed)
D/TransportRuntime.SQLiteEventStore: Storing event with priority=DEFAULT, name=FIREPERF for destination cct
D/TransportRuntime.JobInfoScheduler: Scheduling upload for context TransportContext(cct, DEFAULT, MSRodHRwczovL2ZpcmViYXNlbG9nZ2luZy1wYS5nb29nbGVhcGlzLmNvbS92MS9maXJlbG9nL2xlZ2FjeS9iYXRjaGxvZ1xBSXphU3lDY2traUg4aTJaQVJ3T3MxTEV6RktsZDE1YU9HOG96S28=) with jobId=877081683 in 30000ms(Backend next call timestamp 1614807010307). Attempt 1
I/okhttp.OkHttpClient: --> GET http://45.153.184.141/api/users/profile/
    Authorization: Token token
    --> END GET
D/OnePlusJankManager:  Chor uploadMDM JANK_TYPE_ONCE mViewTitle = com.weedmanager.myweedmanager/com.weedmanager.myweedmanager.authentication.LoginActivity--- jank level = 1
I/okhttp.OkHttpClient: <-- 200 OK http://45.153.184.141/api/users/profile/ (83ms)
    Date: Wed, 03 Mar 2021 21:31:40 GMT
    Server: WSGIServer/0.2 CPython/3.8.2
    Content-Type: application/json
    Vary: Accept
    Allow: GET, HEAD, OPTIONS
    X-Frame-Options: DENY
    Content-Length: 103
    X-Content-Type-Options: nosniff
    <-- END HTTP (103-byte body)
W/r.myweedmanage: Accessing hidden method Lsun/misc/Unsafe;->putObject(Ljava/lang/Object;JLjava/lang/Object;)V (greylist, linking, allowed)
W/r.myweedmanage: Accessing hidden method Lsun/misc/Unsafe;->getInt(Ljava/lang/Object;J)I (greylist, linking, allowed)
    Accessing hidden method Lsun/misc/Unsafe;->getObject(Ljava/lang/Object;J)Ljava/lang/Object; (greylist, linking, allowed)
E/LoginActivity$login: LoadingState Observer triggered
W/r.myweedmanage: Accessing hidden method Lsun/misc/Unsafe;->getLong(Ljava/lang/Object;J)J (greylist,core-platform-api, linking, allowed)
    Accessing hidden method Lsun/misc/Unsafe;->getLong(Ljava/lang/Object;J)J (greylist,core-platform-api, linking, allowed)
E/LoginActivity$login: LOADED
D/TransportRuntime.SQLiteEventStore: Storing event with priority=DEFAULT, name=FIREPERF for destination cct
D/DecorView: onWindowFocusChangedFromViewRoot hasFocus: true, DecorView@4a8ec73[LoginActivity]
D/TransportRuntime.JobInfoScheduler: Upload for context TransportContext(cct, DEFAULT, MSRodHRwczovL2ZpcmViYXNlbG9nZ2luZy1wYS5nb29nbGVhcGlzLmNvbS92MS9maXJlbG9nL2xlZ2FjeS9iYXRjaGxvZ1xBSXphU3lDY2traUg4aTJaQVJ3T3MxTEV6RktsZDE1YU9HOG96S28=) is already scheduled. Returning...
E/LoginActivity$login: LoadingState Observer triggered
    LOADED
E/LoginActivity$login: LoadingState Observer triggered
    LOADED
D/OnePlusJankManager:  Chor uploadMDM JANK_TYPE_ONCE mViewTitle = com.weedmanager.myweedmanager/com.weedmanager.myweedmanager.authentication.LoginActivity--- jank level = 1
V/FA: Recording user engagement, ms: 1494
W/ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@c6ecc8e
V/FA: Activity paused, time: 1057027342
D/FA: Event not sent since app measurement is disabled
V/FA: onActivityCreated
E/MainActivity: MainActivity onCreate

Now after a log out when the magic occurs:

E/LoginViewModel: enter try block outside viewModelScope.launch
D/FA: Event not sent since app measurement is disabled
E/LoginActivity$login: LoadingState Observer triggered
E/LoginActivity$login: LOADED
V/ViewRootImpl: The specified message queue synchronization  barrier token has not been posted or has already been removed
V/FA: Recording user engagement, ms: 8496
V/FA: Connecting to remote service
V/FA: Activity paused, time: 1057275561
W/Choreographer: Already have a pending vsync event.  There should only be one at a time.
D/FA: Event not sent since app measurement is disabled
W/ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@24faad3
E/MainActivity: MainActivity onCreate

So we can clearly see that it doesn't enter in the try block inside the viewModelScope.launch because the log is not displayed and the request are not made (profiler empty too) but no Exception is caught in the try/catch block that surrounds viewModelScope.launch

Indeed I discovered the JobCancellationException when I debugged my code with breakpoint and step over.

I tried to change my scope by changing from viewModelScope.launch to CoroutineScope(Dispatchers.IO).launch (just to test with this scope according to the comment below the question) and it's crashing.



from Kotlin Coroutine throws JobCancellationException and trigger observers

No comments:

Post a Comment