Facebook login with Android SDK 3.0 causing ANRs or not working at all

Question

In order to log a user in to Facebook in an Android app, I'm trying to use the following code. After the user has been logged in, all their friends' locations should fetched.

Unfortunately, this code causes ANRs sometimes (as reported in the Google Play developer console) and sometimes it just doesn't work. If I remove the app inside Facebook (revoke permissions), the permission dialog is shown again on the next launch of the Android app. But if the app has the permissions already, it causes those ANRs or just quits without success.

Seems like parts are working and parts are wrong, doesn't it? Is the following code a correct way of logging in and fetching data?

package com.my.application;

import java.util.Arrays;
import java.util.List;
import org.json.JSONArray;
import org.json.JSONObject;
import android.app.Activity;
import android.app.ProgressDialog;
import android.content.Intent;
import android.os.Bundle;
import android.preference.PreferenceManager;
import com.facebook.*;
import com.facebook.Session.OpenRequest;
import com.facebook.Session.StatusCallback;

public class FBLocations extends Activity {

    private Session.StatusCallback fbStatusCallback = new Session.StatusCallback() {
        @Override
        public void call(Session session, SessionState state, Exception exception) { // callback for session state changes
            if (state.isOpened()) {
                Request.executeGraphPathRequestAsync(session, "me/friends/?access_token="+session.getAccessToken()+"&fields=id,name,location&limit=500", new Request.Callback() {
                    @Override
                    public void onCompleted(Response response) {
                        if (response != null) {
                            // do something with <response> now
                        }
                    }
                });
            }
        }
    };

    protected void onCreate(Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        try {
            openActiveSession(this, true, fbStatusCallback, Arrays.asList("friends_location"));
        }
        catch (Exception e) {
            e.printStackTrace();
        }
    }

    private static Session openActiveSession(Activity activity, boolean allowLoginUI, StatusCallback callback, List<String> permissions) {
        OpenRequest openRequest = new OpenRequest(activity).setPermissions(permissions).setLoginBehavior(SessionLoginBehavior.SSO_WITH_FALLBACK).setCallback(callback).setDefaultAudience(SessionDefaultAudience.FRIENDS);
        Session session = new Session.Builder(activity).build();
        if (SessionState.CREATED_TOKEN_LOADED.equals(session.getState()) || allowLoginUI) {
            Session.setActiveSession(session);
            session.openForRead(openRequest);
            return session;
        }
        return null;
    }

    @Override
    public void onActivityResult(int requestCode, int resultCode, Intent data) {
        super.onActivityResult(requestCode, resultCode, data);
        Session.getActiveSession().onActivityResult(this, requestCode, resultCode, data);
    }

}

I've also added the app's key hashes to Facebook, both debug and production. Wasn't sure if the padding = has to be written as well.

enter image description here

I couldn't follow Facebook's official tutorial as I won't use the SDK's login button nor do I use fragments in Android.

Edit (7th January 2013):

After Hartok suggested to replace session.isOpened() by state.isOpened() in the callback's call() method, things work in 50% of all test runs now. Nevertheless, there are some problems. In some cases, everything works fine, in some other cases (without me doing anything differently), there is the following error in LogCat:

01-07 01:55:29.882: W/System.err(30572): com.facebook.FacebookException: Log in attempt aborted.
at com.facebook.Session.close(Session.java:572)
at com.facebook.Session.setActiveSession(Session.java:755)
at my.app.package.FBImport.openActiveSession(FBImport.java:145) // this is: Session.setActiveSession(session);
at my.app.package.FBImport.access$5(FBImport.java:139)
at my.app.package.FBImport$4.run(FBImport.java:124)

What causes this error? Client problem or server problem? App seems to freeze (ANR) after that, by the way.

And if I try to connect twice in sequence, I see the following LogCat output:

java.lang.IllegalStateException: Cannot execute task: the task is already running.
at android.os.AsyncTask.executeOnExecutor(AsyncTask.java:550)
at android.os.AsyncTask.execute(AsyncTask.java:511)
at com.facebook.RequestAsyncTask.executeOnSettingsExecutor(RequestAsyncTask.java:186)
at com.facebook.Request.executeBatchAsync(Request.java:1094)
at com.facebook.Request.executeBatchAsync(Request.java:1073)
at com.facebook.Request.executeBatchAsync(Request.java:1055)
at com.facebook.Request.executeAsync(Request.java:852)

Why is that? Why is the task still running?

ANR description (ANR keyDispatchingTimedOut):

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)

"main" prio=5 tid=1 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4184e9a0 self=0x40011010
  | sysTid=19301 nice=0 sched=0/0 cgrp=apps handle=1074414556
  | state=S schedstat=( 906984000 397085000 2526 ) utm=66 stm=24 core=0
  #00 pc 00017ee4 /system/lib/libc.so (epoll_wait+12)
  #01 pc 00014b09 /system/lib/libutils.so (android::Looper::pollInner(int)+96)
  #02 pc 00014d71 /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+104)
  #03 pc 0005ed53 /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22)
  #04 pc 0001e290 /system/lib/libdvm.so (dvmPlatformInvoke+112)
  #05 pc 0004d411 /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+396)
  #06 pc 000276a0 /system/lib/libdvm.so
  #07 pc 0002b57c /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
  #08 pc 0005ff07 /system/lib/libdvm.so (dvmInvokeMethod(Object*, Method const*, ArrayObject*, ArrayObject*, ClassObject*, bool)+374)
  #09 pc 000677e1 /system/lib/libdvm.so
  #10 pc 000276a0 /system/lib/libdvm.so
  #11 pc 0002b57c /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184)
  #12 pc 0005fc31 /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+272)
  #13 pc 000499fb /system/lib/libdvm.so
  #14 pc 00046871 /system/lib/libandroid_runtime.so
  #15 pc 00047533 /system/lib/libandroid_runtime.so (android::AndroidRuntime::start(char const*, char const*)+390)
  #16 pc 00000db7 /system/bin/app_process
  #17 pc 0001271f /system/lib/libc.so (__libc_init+38)
  #18 pc 00000ae8 /system/bin/app_process
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:125)
  at android.os.Looper.loop(Looper.java:124)
  at android.app.ActivityThread.main(ActivityThread.java:5039)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:511)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:793)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:560)
  at dalvik.system.NativeStart.main(Native Method)

"AsyncTask #2" prio=5 tid=17 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4205f6d0 self=0x6742f940
  | sysTid=19354 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1732251672
  | state=S schedstat=( 82839000 103493000 646 ) utm=5 stm=3 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4205f7f0> (a java.lang.VMThread) held by tid=17 (AsyncTask #2)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"Binder_3" prio=5 tid=16 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41fed668 self=0x41838008
  | sysTid=19330 nice=0 sched=0/0 cgrp=apps handle=1742766600
  | state=S schedstat=( 1078000 818000 10 ) utm=0 stm=0 core=0
  #00 pc 00016fe4 /system/lib/libc.so (__ioctl+8)
  #01 pc 0002a97d /system/lib/libc.so (ioctl+16)
  #02 pc 00016ba1 /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+132)
  #03 pc 00017363 /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154)
  #04 pc 0001b15d /system/lib/libbinder.so
  #05 pc 00011267 /system/lib/libutils.so (android::Thread::_threadLoop(void*)+114)
  #06 pc 0004679f /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+66)
  #07 pc 00010dcd /system/lib/libutils.so
  #08 pc 0000e3d8 /system/lib/libc.so (__thread_entry+72)
  #09 pc 0000dac4 /system/lib/libc.so (pthread_create+160)
  at dalvik.system.NativeStart.run(Native Method)

"pool-1-thread-5" prio=5 tid=15 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x420423d0 self=0x673d8ab8
  | sysTid=19329 nice=0 sched=0/0 cgrp=apps handle=1732087560
  | state=S schedstat=( 6292000 7083000 36 ) utm=0 stm=0 core=2
  at java.lang.Object.wait(Native Method)
  - waiting on <0x42042528> (a java.lang.VMThread) held by tid=15 (pool-1-thread-5)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"pool-1-thread-4" prio=5 tid=14 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x42039040 self=0x673cb248
  | sysTid=19328 nice=0 sched=0/0 cgrp=apps handle=1732032152
  | state=S schedstat=( 8178000 7047000 32 ) utm=0 stm=0 core=3
  at java.lang.Object.wait(Native Method)
  - waiting on <0x42039160> (a java.lang.VMThread) held by tid=14 (pool-1-thread-4)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"pool-1-thread-3" prio=5 tid=13 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x42027140 self=0x673c95f8
  | sysTid=19327 nice=0 sched=0/0 cgrp=apps handle=1698808232
  | state=S schedstat=( 10642000 19156000 34 ) utm=1 stm=0 core=1
  at java.lang.Object.wait(Native Method)
  - waiting on <0x42027260> (a java.lang.VMThread) held by tid=13 (pool-1-thread-3)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"pool-1-thread-2" prio=5 tid=12 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4201d958 self=0x672cd008
  | sysTid=19326 nice=0 sched=0/0 cgrp=apps handle=1731988480
  | state=S schedstat=( 17725000 16571000 59 ) utm=1 stm=0 core=3
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4201da78> (a java.lang.VMThread) held by tid=12 (pool-1-thread-2)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"pool-1-thread-1" prio=5 tid=11 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x420156c8 self=0x65dc8818
  | sysTid=19325 nice=0 sched=0/0 cgrp=apps handle=1728232912
  | state=S schedstat=( 11166000 9311000 77 ) utm=0 stm=1 core=2
  at java.lang.Object.wait(Native Method)
  - waiting on <0x42015810> (a java.lang.VMThread) held by tid=11 (pool-1-thread-1)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
  at java.lang.Thread.run(Thread.java:856)

"AsyncTask #1" prio=5 tid=10 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41fb5990 self=0x63bd3008
  | sysTid=19318 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1748684416
  | state=S schedstat=( 24263000 18668000 33 ) utm=1 stm=1 core=1
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41fd07d0> (a java.lang.VMThread) held by tid=10 (AsyncTask #1)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor...

do you have a stack trace that you can paste from the developer console — Jesse Chen, Jan 02 '13 at 19:07
@gian1200: Authentication works, as I have described, so the keys should be okay. It's just that I included both, with padding "=" and without. — caw, Jan 03 '13 at 20:42
@JesseChen: The problem is that in the code above, `session.isOpened()` often returns `false` when it should return `true`, actually, as this is called to log the user in. So there's something wrong in the code. — caw, Jan 03 '13 at 21:20
Could you check the callback's exception parameter in this case? — Hartok, Jan 06 '13 at 06:53
It looks like the `OpenSession' callback is called every time the `SessionState` changes. So, it should be called when the state switch from `CREATED_TOKEN_LOADED` to `OPENING`. In this case, `session.isOpened()` will return false. It can only be a problem if you remove this callback with `Session.removeCallback()` before reaching an opened session. — Hartok, Jan 06 '13 at 07:23
@Hartok: Yes, the exception parameter was null. I hoped it was not null, would have been easier. — caw, Jan 06 '13 at 13:44
@Hartok: But in the callback's `call()` method there is no call to `OpenSession`, is it? Why should it be called every time the session state changes? — caw, Jan 06 '13 at 13:45
Sorry, I was talking about your `OpenRequest` callback. In Session.java:950, the callback is added to the callbacks queue then `postStateChange()` is called. And every time `postStateChange()` is called with a new state, all the callbacks in the callbacks queue are fired. — Hartok, Jan 06 '13 at 16:00
Yes, this is the intended behaviour, isn't it? In the end, the callback method should be fired for an opened session at least once, right? So `session.isOpened()` must be true in one of the calls. — caw, Jan 06 '13 at 16:41
Yes, it looks to be the intended behavior. And yes, in one of the calls, the Session should be opened. You could also check the `state.isOpened()` method in your callback. It should be the same result but perhaps the `SessionState` is updated before you receive the callback. — Hartok, Jan 06 '13 at 22:03
One of the calls SHOULD come up with an opened session, but none does. So something is going wrong. You suggest to replace `session.isOpened()` by `state.isOpened()` in the callback method? — caw, Jan 07 '13 at 00:38
@Hartok: Wow, thank you! It's not that everything is working fine now, but your correction improved things and now I see it working in 50% of all test runs. Please see my updated question above for more details. — caw, Jan 07 '13 at 01:02

score 3 · Accepted Answer · answered Jan 07 '13 at 04:49

3

Log in attempt aborted is fired because Session.setActiveSession() is called while a previous Session was currently opening.

Is it possible that you call Session.setActiveSession() two times?

You could try this code. It was not tested, but it partly comes from SessionLoginSample.

private static Session openActiveSession(Activity activity, boolean allowLoginUI, StatusCallback callback, List<String> permissions, Bundle savedInstanceState) {

    OpenRequest openRequest = new OpenRequest(activity).setPermissions(permissions).setLoginBehavior(SessionLoginBehavior.SSO_WITH_FALLBACK).setCallback(callback).setDefaultAudience(SessionDefaultAudience.FRIENDS);

    Session session = Session.getActiveSession();
    if (session == null) {
        if (savedInstanceState != null) {
            session = Session.restoreSession(this, null, fbStatusCallback, savedInstanceState);
        }
        if (session == null) {
            session = new Session(this);
        }
        Session.setActiveSession(session);
        if (session.getState().equals(SessionState.CREATED_TOKEN_LOADED) || allowLoginUI) {
            session.openForRead(openRequest);
            return session;
        }
    }

    return null;
}

answered Jan 07 '13 at 04:49

Hartok

2,147
20
37

Thank you! Can I use that code without ever writing any data to `savedInstanceState`, in particular data about the session? – caw Jan 07 '13 at 21:46
It seems to be the same with that code: As soon as one request has been executed, all subsequent requests are somehow blocked. The app is freezed again (ANR) and I cannot call this method again to do a new request. But what causes the ANR? I'm calling the method above from a new thread. – caw Jan 07 '13 at 22:07
What are your other requests? – Hartok Jan 08 '13 at 01:07
It only that single Facebook graph request, which did not work on the first attempt so so started it again. The full code is above, and the method `openActiveSession()` is triggered when a button is clicked. So when I click it again, it is triggered again. – caw Jan 08 '13 at 16:48
What's the ANR description on Google Play dashboard? – Hartok Jan 09 '13 at 02:13
I've added the complete description to the question above. – caw Jan 09 '13 at 10:11
Nothing interesting in the ANR description. Is there anything in logcat? – Hartok Jan 11 '13 at 01:46
No, the only thing that may be interesting in LogCat is that the login to Facebook could not be established. – caw Jan 13 '13 at 13:21

score 2 · Answer 2 · answered Jan 04 '13 at 17:08

2

If it's hanging up when the user has already authorized the permissions, try checking for the permissions and excluding code based on if the permissions exist. Something like:

if(!session.getReadPermissions.contains("friends_location"){
    //restore or start the session and ask for the permission
}
else{
    //do stuff that would happen after the permission is already granted
}

I'm not at my workstation so the method might be a little off but that's the general idea I would try.

answered Jan 04 '13 at 17:08

Wenger

989
2
12
35

Thank you! When I tried to implement your idea, it did not quite work. But I think what Hartok has suggested is roughly what you were talking about, isn't it? – caw Jan 08 '13 at 21:39
Similar. His checks the session state and access token. I would do that as well, but also check to confirm the appropriate permissions. – Wenger Jan 10 '13 at 15:10

score 1 · Answer 3 · answered Dec 31 '12 at 03:07

1

Replace your openActiveSession call with below code.

new Thread()
        {

            @Override
            public void run()
            {


openActiveSession(this, true, fbStatusCallback, Arrays.asList("friends_location"));


            }
        }.start();

answered Dec 31 '12 at 03:07

Changdeo Jadhav

706
9
23

Thank you! Is this really possible? Doesn't `openActiveSession()` maybe need to be called from the UI thread? – caw Dec 31 '12 at 14:04
use runOnUiThread or create a Handler on activity and use handler.postDelayed or handler.post methods for all blocking calls. – android2013 Jan 08 '13 at 10:29
You are refering to the way methods that change the UI must be called, right? Yes, simply calling `runOnUiThread()` in the code above will work. But I thought that maybe the Facebook code (which I cannot change) needs access to the UI. – caw Jan 08 '13 at 21:43

Facebook login with Android SDK 3.0 causing ANRs or not working at all

3 Answers3

Linked