Facebook (Android) VERY slow

davebollinger · May 31, 2014, 2:11pm

My integration was all working as of last week, so no known problems w release keys, hash’s, app id’s, or that sort of stuff.

As of yesterday (and perhaps a few days earlier? hard to say for sure), facebook.login() takes “forever” (about a minute), where a black screen with spinning circle just waits and waits. I have two apps w same symptoms, on multiple devices, all built w public 2189.

Even occur on the facebook sample (assuming you’re not already logged in when you start it up).

Here’s a logcat from a post photo via the sample, modified with the “###” prints with system.getTimer() (otherwise you couldn’t tell how long elapses). Note the 72917-7936 elapsed msecs between final .request/listener:

C:\Dev\>adb logcat -c C:\Dev\>adb logcat Corona:V \*:s --------- beginning of /dev/log/system --------- beginning of /dev/log/main V/Corona (16950): \> Class.forName: network.LuaLoader V/Corona (16950): \< Class.forName: network.LuaLoader V/Corona (16950): Loading via reflection: network.LuaLoader I/Corona (16950): Platform: Nexus 7 / ARM Neon / 4.4.2 / NVIDIA Tegra 3 / OpenG L ES 2.0 14.01003 V/Corona (16950): \> Class.forName: CoronaProvider.licensing.google.LuaLoader V/Corona (16950): \< Class.forName: CoronaProvider.licensing.google.LuaLoader V/Corona (16950): Loading via reflection: CoronaProvider.licensing.google.LuaLo ader I/Corona (16950): ### EXECUTING FIRST .login() AT: 212.808 I/Corona (16950): ### ENTERING LISTENER AT: 699.21 I/Corona (16950): Facebook Listener events: I/Corona (16950): type(session) I/Corona (16950): name(fbconnect) I/Corona (16950): expiration(1406683508) I/Corona (16950): phase(login) I/Corona (16950): token(CAAEmBVxzsqIBAKcTgYd ... #244) I/Corona (16950): isError(false) I/Corona (16950): response() I/Corona (16950): event.name fbconnect I/Corona (16950): event.type: session I/Corona (16950): isError: false I/Corona (16950): didComplete: nil I/Corona (16950): Session Status: login I/Corona (16950): ### EXECUTINGP POST PHOTO BUTTON'S .login() AT: 7934.182 I/Corona (16950): ### ENTERING LISTENER AT: 7935.036 I/Corona (16950): Facebook Listener events: I/Corona (16950): type(session) I/Corona (16950): name(fbconnect) I/Corona (16950): expiration(1406683508) I/Corona (16950): phase(login) I/Corona (16950): token(CAAEmBVxzsqIBAKcTgYd ... #244) I/Corona (16950): isError(false) I/Corona (16950): response() I/Corona (16950): event.name fbconnect I/Corona (16950): event.type: session I/Corona (16950): isError: false I/Corona (16950): didComplete: nil I/Corona (16950): Session Status: login I/Corona (16950): ### EXECUTING POST PHOTO'S .request() AT: 7936.896 I/Corona (16950): ### ENTERING LISTENER AT: 72917.152 I/Corona (16950): Facebook Listener events: I/Corona (16950): type(request) I/Corona (16950): name(fbconnect) I/Corona (16950): didComplete(false) I/Corona (16950): isError(false) I/Corona (16950): response({"id":"1000002006915 ... #40) I/Corona (16950): event.name fbconnect I/Corona (16950): event.type: request I/Corona (16950): isError: false I/Corona (16950): didComplete: false I/Corona (16950): photo I/Corona (16950): [id] = 100000200691575\_890064484343566

[/code]

Any ideas? Thanks!

rob · May 31, 2014, 8:22pm

Can you put together a small sample app that has this issue please? I just did an Android build and it didn’t seem painfully long (though uploading a 1.7mb image file did…), but . . .

Rob

davebollinger · May 31, 2014, 11:00pm

attached, though I doubt it will do any good. It’s essentially just the sample verbatim - all I did was add some print statements with system.getTimer()

if not already logged in, the sample immediately displays the black-screen-spinning-circle for about a minute while it does it’s initial login - same exact symptom as both my full apps. (if already logged in, then post photo/message will exhibit same problem)

(btw, i’m using real FB appid’s, but removed from uploaded code since it’s a public forum)

wonder if it has anything to do with the fact that both my FB apps are “recent”? maybe some api v2 issue? when you built your test, was it against a long-existing fb app? If I plug in either appID into the sample, then same problem as my full app (unfortunately I don’t have any “old” appID’s to test against)

And like I said before, it was working just fine a week ago… pretty sure everything is set up ok. correct package name, release key build, manually and meticulously step-by-step generated hash (with correct version of openssl) of release key, have sso enabled, native app, client and embedded oauth, … I can’t think of anything else to change on the FB end.??

Thanks for any ideas!

[edit: btw, fwiw, that 60s delay on my photo post wasn’t an upload - it was just the original sample pulling that “gold swirl” from coronalabs.com]

rob · June 1, 2014, 2:57am

With an older app, the code you provide run’s rather quickly. I finally got a V2 app setup, and boy what a pain Facebook is making things…

Anyway here are the timings from my Nexus 7 (1st gen)

I/Corona (23059): ### ENTERING LISTENER AT: 274.087      – Initial Login
I/Corona (23059): ### ENTERING LISTENER AT: 4454.763    – Beginning of Post Photo
I/Corona (23059): ### ENTERING LISTENER AT: 5998.172    – After post Photo
I/Corona (23059): ### ENTERING LISTENER AT: 9268.14      – beginning of post message
I/Corona (23059): ### ENTERING LISTENER AT: 9710.178    – after post message.

Since these times are in milliseconds, the photo post took 1.5 seconds and given it had to upload a photo that seems rather reasonable. The post message took under 500ms which also seems kinda reasonable.

Rob

davebollinger · June 1, 2014, 5:43pm

Thanks Rob, appreciate the effort you’ve put in for me. BTW, I’m testing on a Nexus 7 2012 too. Seems something’s definately wrong “somewhere” for me, tho I still have no clue what. Device itself doesn’t seem to have connectivity problems. I’ve tried it w/wo facebook app installed, tried removing app from my fb account and re-adding, I’ve even created a second new copy of the FB app and tried it with that appid (in case something in the fb app got munged) … same “slowness” no matter what, running out of ideas.

This is a logcat (edited only to remove magic values) from one of my (two) “real” apps, added similar getTimer() output this morning, still “slow” – second-phase login response at ~13seconds, post photo response at ~78 seconds (it’s an uploaded photo, but the file transfer itself does NOT take 65 ~seconds):

I/Corona (22202): #EGHZ# SOC postPhotoFacebook() LISTENER2 (@ 13379 ^ 5) I/Corona (22202): table: 0x6858ce98 { I/Corona (22202): [type]= "session" I/Corona (22202): [name]= "fbconnect" I/Corona (22202): [expiration]= 1406814268 I/Corona (22202): [phase]= "login" I/Corona (22202): [token]= "[..many seemingly random characters to enjoy..]" I/Corona (22202): [isError]= false I/Corona (22202): [response]= "" I/Corona (22202): } D/dalvikvm(22202): GC\_CONCURRENT freed 4272K, 35% free 8344K/12652K, paused 3ms+3ms, total 30ms I/SoundDecoder\_SetError(22202): Cannot operate on sample because already at EOF D/ConnectivityService( 517): handleInetConditionHoldEnd: net=1, condition=0, published condition=0 I/SoundDecoder\_SetError(22202): Cannot operate on sample because already at EOF D/dalvikvm(22202): GC\_CONCURRENT freed 394K, 35% free 8337K/12652K, paused 3ms+3ms, total 25ms I/Corona (22202): #EGHZ# SOC postPhotoFacebook() LISTENER2 (@ 78745 ^ 65365) I/Corona (22202): table: 0x6a1ccf08 { I/Corona (22202): [type]= "request" I/Corona (22202): [name]= "fbconnect" I/Corona (22202): [didComplete]= false I/Corona (22202): [isError]= false I/Corona (22202): [response]= "{"post\_id":"[..more characters..]","id":"[..and more..]"}" I/Corona (22202): } I/Corona (22202): #EGHZ# SOC postPhotoFacebook success, posted. (@ 78745 ^ 0)

Weird that it eventually “succeeds” (if you wait long enough, typical user wouldn’t), but is just ridiculously slow. (on fast wifi - when it was working, this was no more than about a two second process)

Maybe I need to find a working third-party published Corona app using facebook v2 and test their performance on my devices/my fb acct. This stuff is so hard to “isolate”.

Anyway, thanks again.

davebollinger · June 1, 2014, 11:13pm

ok, maybe i’m getting somewhere…

it’s not ALWAYS slow! same build, same fb app, same everything as far as i can tell, but maybe 10% of the time i get the old “fast” login (so fast, in fact, that if there IS a spinning circle displayed, then it’s so brief that i can’t notice it)

staring at logcat *:V’s is not fun, but, it *seems* that the following is present in the log on a slow login, and not present in a fast login:

W/fb4a(:\<default\>):ImmutableBundle( 1241): Unsupported value type in bundle for key fb4a\_new with value {"new\_version":"154780","min\_version":"148914","new\_vers ion\_url":"https://m.facebook.com/mobile\_builds?build\_number=154780&no\_fw=1","new \_version\_notes":"","everstore\_handle":"FuuCCQA5cQwCBxEkAFAANnxuPwYAAAA:"} W/fb4a(:\<default\>):ImmutableBundle( 1241): Unsupported value type in bundle for key fb4a\_master\_new with value {"new\_version":130613,"new\_version\_url":"https:// m.facebook.com/mobile\_builds?build\_number=130613&no\_fw=1"}

I have no idea what an “immutable bundle” is, but maybe i need a “mutable bundle” or an “immutable unbundled”. (If that’s a FB for Android version thing, I *should* have the latest - it was unintalled/reinstalled just days ago during testing this.)

But it’s hard to tell, since facebook is so “chatty” in the logcat, and half that stuff may be innocuous. I also get warnings about implicit intents not being safe, and invalid sticker pack exceptions, and the “BlueServiceQueue” chatting away, and some “katana” lib telling me all about why it can’t load itself cuz its already loaded, and these every few seconds while spinning:

W/fb4a(:\<default\>):ClientPeriodicEventReporterManager( 1241): Requested time int erval of 1200000 ms should be increased to at least 3600000 ms for DeviceStatusP eriodicReporter

Any idea about “immutable bundles”? Or is that just another logcat red herring? Thx

rob · June 2, 2014, 12:40am

immutable just means you can’t change it. I think it itself is a red herring but what I think may be a real clue to the problem is this:

https://m.facebook.com/mobile_builds?build_number=154780&no_fw=1

I’m tracking down an issue on iOS right now where the login process skips the native app or the iOS built in login’s in favor of using the web based login. For iOS this results in a very long pause before it finally decides to launch the web browser and do the login. That issue goes to a m.facebook.com (their mobile web site).

Rob

davebollinger · June 5, 2014, 2:44pm

just an FYI update… haven’t seen any sign of the “slowness” since yesterday

(that is, 6/4 was ok, no data for 6/2-6/3, last known problems on 6/1)

as far as i know, nothing under my control has changed

so am currently assuming it was something on fb’s end (that they’ve since resolved?)

rob · May 31, 2014, 8:22pm

Can you put together a small sample app that has this issue please? I just did an Android build and it didn’t seem painfully long (though uploading a 1.7mb image file did…), but . . .

Rob

davebollinger · May 31, 2014, 11:00pm

attached, though I doubt it will do any good. It’s essentially just the sample verbatim - all I did was add some print statements with system.getTimer()

if not already logged in, the sample immediately displays the black-screen-spinning-circle for about a minute while it does it’s initial login - same exact symptom as both my full apps. (if already logged in, then post photo/message will exhibit same problem)

(btw, i’m using real FB appid’s, but removed from uploaded code since it’s a public forum)

wonder if it has anything to do with the fact that both my FB apps are “recent”? maybe some api v2 issue? when you built your test, was it against a long-existing fb app? If I plug in either appID into the sample, then same problem as my full app (unfortunately I don’t have any “old” appID’s to test against)

And like I said before, it was working just fine a week ago… pretty sure everything is set up ok. correct package name, release key build, manually and meticulously step-by-step generated hash (with correct version of openssl) of release key, have sso enabled, native app, client and embedded oauth, … I can’t think of anything else to change on the FB end.??

Thanks for any ideas!

[edit: btw, fwiw, that 60s delay on my photo post wasn’t an upload - it was just the original sample pulling that “gold swirl” from coronalabs.com]

rob · June 1, 2014, 2:57am

With an older app, the code you provide run’s rather quickly. I finally got a V2 app setup, and boy what a pain Facebook is making things…

Anyway here are the timings from my Nexus 7 (1st gen)

I/Corona (23059): ### ENTERING LISTENER AT: 274.087      – Initial Login
I/Corona (23059): ### ENTERING LISTENER AT: 4454.763    – Beginning of Post Photo
I/Corona (23059): ### ENTERING LISTENER AT: 5998.172    – After post Photo
I/Corona (23059): ### ENTERING LISTENER AT: 9268.14      – beginning of post message
I/Corona (23059): ### ENTERING LISTENER AT: 9710.178    – after post message.

Since these times are in milliseconds, the photo post took 1.5 seconds and given it had to upload a photo that seems rather reasonable. The post message took under 500ms which also seems kinda reasonable.

Rob

davebollinger · June 1, 2014, 5:43pm

Thanks Rob, appreciate the effort you’ve put in for me. BTW, I’m testing on a Nexus 7 2012 too. Seems something’s definately wrong “somewhere” for me, tho I still have no clue what. Device itself doesn’t seem to have connectivity problems. I’ve tried it w/wo facebook app installed, tried removing app from my fb account and re-adding, I’ve even created a second new copy of the FB app and tried it with that appid (in case something in the fb app got munged) … same “slowness” no matter what, running out of ideas.

This is a logcat (edited only to remove magic values) from one of my (two) “real” apps, added similar getTimer() output this morning, still “slow” – second-phase login response at ~13seconds, post photo response at ~78 seconds (it’s an uploaded photo, but the file transfer itself does NOT take 65 ~seconds):

I/Corona (22202): #EGHZ# SOC postPhotoFacebook() LISTENER2 (@ 13379 ^ 5) I/Corona (22202): table: 0x6858ce98 { I/Corona (22202): [type]= "session" I/Corona (22202): [name]= "fbconnect" I/Corona (22202): [expiration]= 1406814268 I/Corona (22202): [phase]= "login" I/Corona (22202): [token]= "[..many seemingly random characters to enjoy..]" I/Corona (22202): [isError]= false I/Corona (22202): [response]= "" I/Corona (22202): } D/dalvikvm(22202): GC\_CONCURRENT freed 4272K, 35% free 8344K/12652K, paused 3ms+3ms, total 30ms I/SoundDecoder\_SetError(22202): Cannot operate on sample because already at EOF D/ConnectivityService( 517): handleInetConditionHoldEnd: net=1, condition=0, published condition=0 I/SoundDecoder\_SetError(22202): Cannot operate on sample because already at EOF D/dalvikvm(22202): GC\_CONCURRENT freed 394K, 35% free 8337K/12652K, paused 3ms+3ms, total 25ms I/Corona (22202): #EGHZ# SOC postPhotoFacebook() LISTENER2 (@ 78745 ^ 65365) I/Corona (22202): table: 0x6a1ccf08 { I/Corona (22202): [type]= "request" I/Corona (22202): [name]= "fbconnect" I/Corona (22202): [didComplete]= false I/Corona (22202): [isError]= false I/Corona (22202): [response]= "{"post\_id":"[..more characters..]","id":"[..and more..]"}" I/Corona (22202): } I/Corona (22202): #EGHZ# SOC postPhotoFacebook success, posted. (@ 78745 ^ 0)

Weird that it eventually “succeeds” (if you wait long enough, typical user wouldn’t), but is just ridiculously slow. (on fast wifi - when it was working, this was no more than about a two second process)

Maybe I need to find a working third-party published Corona app using facebook v2 and test their performance on my devices/my fb acct. This stuff is so hard to “isolate”.

Anyway, thanks again.

davebollinger · June 1, 2014, 11:13pm

ok, maybe i’m getting somewhere…

it’s not ALWAYS slow! same build, same fb app, same everything as far as i can tell, but maybe 10% of the time i get the old “fast” login (so fast, in fact, that if there IS a spinning circle displayed, then it’s so brief that i can’t notice it)

staring at logcat *:V’s is not fun, but, it *seems* that the following is present in the log on a slow login, and not present in a fast login:

W/fb4a(:\<default\>):ImmutableBundle( 1241): Unsupported value type in bundle for key fb4a\_new with value {"new\_version":"154780","min\_version":"148914","new\_vers ion\_url":"https://m.facebook.com/mobile\_builds?build\_number=154780&no\_fw=1","new \_version\_notes":"","everstore\_handle":"FuuCCQA5cQwCBxEkAFAANnxuPwYAAAA:"} W/fb4a(:\<default\>):ImmutableBundle( 1241): Unsupported value type in bundle for key fb4a\_master\_new with value {"new\_version":130613,"new\_version\_url":"https:// m.facebook.com/mobile\_builds?build\_number=130613&no\_fw=1"}

I have no idea what an “immutable bundle” is, but maybe i need a “mutable bundle” or an “immutable unbundled”. (If that’s a FB for Android version thing, I *should* have the latest - it was unintalled/reinstalled just days ago during testing this.)

But it’s hard to tell, since facebook is so “chatty” in the logcat, and half that stuff may be innocuous. I also get warnings about implicit intents not being safe, and invalid sticker pack exceptions, and the “BlueServiceQueue” chatting away, and some “katana” lib telling me all about why it can’t load itself cuz its already loaded, and these every few seconds while spinning:

W/fb4a(:\<default\>):ClientPeriodicEventReporterManager( 1241): Requested time int erval of 1200000 ms should be increased to at least 3600000 ms for DeviceStatusP eriodicReporter

Any idea about “immutable bundles”? Or is that just another logcat red herring? Thx

rob · June 2, 2014, 12:40am

immutable just means you can’t change it. I think it itself is a red herring but what I think may be a real clue to the problem is this:

https://m.facebook.com/mobile_builds?build_number=154780&no_fw=1

I’m tracking down an issue on iOS right now where the login process skips the native app or the iOS built in login’s in favor of using the web based login. For iOS this results in a very long pause before it finally decides to launch the web browser and do the login. That issue goes to a m.facebook.com (their mobile web site).

Rob

davebollinger · June 5, 2014, 2:44pm

just an FYI update… haven’t seen any sign of the “slowness” since yesterday

(that is, 6/4 was ok, no data for 6/2-6/3, last known problems on 6/1)

as far as i know, nothing under my control has changed

so am currently assuming it was something on fb’s end (that they’ve since resolved?)