search

26rairden / oauth-signpost

Automatically exported from code.google.com/p/oauth-signpost
0 stars 0 forks source link

Unable to retireve Request Token in Aug 31 Snapshot (java) #20

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
What steps will reproduce the problem?
1. Add Aug 31 snapshot to build path (java)
2. Clear any existing user data / tokens
3. Attempt to get login url and request token
Kaboom!
4. Switch build path to use Julyu snapshot
5. attempt to get login url and r. token
Success!

What is the expected output? What do you see instead?

Expected: the Login Url with parameters, and request token set.
Instead: I get an exception
oauth.signpost.exception.OAuthCommunicationException: Communication
with the service provider failed: Received authentication challenge is
null
   at oauth.signpost.basic.DefaultOAuthProvider.retrieveToken
(DefaultOAuthProvider.java:152)
   at oauth.signpost.basic.DefaultOAuthProvider.retrieveRequestToken
(DefaultOAuthProvider.java:69) 

What version of the product are you using? On what operating system?

Aug 31 Snapshot (kaboom) vs July Snapshot(works fine) - Android

Please provide any additional information below.

This can be consistently resolved / repeated by switching my build path
info to use the different snapshots. Another user has reported a similar
error on the groups.

Once I have the access token stored locally, either jar works just fine.
The issue is limited to the getToken method of the provider.

Original issue reported on code.google.com by OlliTech on 16 Oct 2009 at 12:56

GoogleCodeExporter commented 9 years ago 
Issue 21 has been merged into this issue.

Original comment by m.kaepp...@gmail.com on 20 Oct 2009 at 2:00

GoogleCodeExporter commented 9 years ago 
Just a follow up with some possibly useful info.

I pulled down the source from various revisions, and it seems that r47 might be 
the
last revision before the issue arose.  Perhaps it was the changes that were 
made to
the signing classes around r50?

Original comment by OlliTech on 21 Oct 2009 at 12:13

GoogleCodeExporter commented 9 years ago 
Hi,

I was unable to reproduce this issue with the latest snapshot JAR. All example 
projects work for me (Google, Twitter and FireEagle), and I also use the latest 
snapshot JAR in our app, where it works, too.

I'd like you to do two things:
1) I just committed a fix. Please grab the latest JAR and see if that fixes 
your 
problem. Are you using Commons Codec 1.4? Because I fixed a problem that 
prevented 
Signpost to work with CC 1.4, which may have caused the 401s you were getting.

2) If that doesn't help, please give me all details about your exact working 
environment. What Java version, what version of commons codec, what platform 
(OS and 
plain Java or Android), etc. pp.

Original comment by m.kaepp...@gmail.com on 28 Oct 2009 at 8:23

GoogleCodeExporter commented 9 years ago 
Mathias,

I appreciate your efforts here. I have tried to make this work as you have 
explained.
I am still not getting correct behavior.

Here are the details.

As you suggested, I downloaded the latest JARS from here. There were two that 
were
only three days old, so I think I got the right ones. i.e. the 1.4 codec.

I am interested in running this in Android. I am using the 1.6 version of the 
SDK,
building on Windows XP. I did run your example under regular Java and it 
appeared to
all work correctly.

I took your FireEagle example code which is built against plain Java and 
modified it
a bit so I could interface through Android - all I really did was change the
system.outs to Log.is. Then I put up an edit box to accept the code from 
FireEagle.

I have attached my project, which uses the .jars from your latest build - I am
assuming now that .jars built under "regular" Java work fine on Android. I 
think that
generally true, unless Android doesn't have an underlying library that regular 
java
has, but that isn't the case here.

Below is the logcat output I am getting.

I am getting the access token code now (with an error thrown), but I am still 
not
getting authorization for some reason.

Thanks for your attention

***BEGIN LOGCAT OUTPUT***
11-01 14:33:37.157: DEBUG/AndroidRuntime(1192): >>>>>>>>>>>>>> AndroidRuntime 
START
<<<<<<<<<<<<<<
11-01 14:33:37.157: DEBUG/AndroidRuntime(1192): CheckJNI is ON
11-01 14:33:37.416: DEBUG/AndroidRuntime(1192): --- registering native 
functions ---
11-01 14:33:37.426: INFO/jdwp(1192): received file descriptor 20 from ADB
11-01 14:33:37.697: DEBUG/ddm-heap(1192): Got feature list request
11-01 14:33:38.276: DEBUG/PackageParser(584): Scanning package: 
/data/app/vmdl15362.tmp
11-01 14:33:38.416: INFO/PackageManager(584): Removing non-system 
package:com.example
11-01 14:33:38.416: DEBUG/PackageManager(584): Removing package com.example
11-01 14:33:38.416: DEBUG/PackageManager(584):   Activities: com.example.Test
11-01 14:33:38.588: DEBUG/PackageManager(584): Scanning package com.example
11-01 14:33:38.588: INFO/PackageManager(584): /data/app/vmdl15362.tmp changed; 
unpacking
11-01 14:33:38.597: DEBUG/installd(555): DexInv: --- BEGIN 
'/data/app/vmdl15362.tmp' ---
11-01 14:33:38.976: DEBUG/dalvikvm(1199): DexOpt: load 45ms, verify 151ms, opt 
2ms
11-01 14:33:38.997: DEBUG/installd(555): DexInv: --- END 
'/data/app/vmdl15362.tmp'
(success) ---
11-01 14:33:38.997: DEBUG/PackageManager(584):   Activities: com.example.Test
11-01 14:33:39.007: DEBUG/ActivityManager(584): Uninstalling process com.example
11-01 14:33:39.007: DEBUG/ActivityManager(584): Force removing process
ProcessRecord{43983638 1181:com.example/10027} (com.example/10027)
11-01 14:33:39.046: INFO/Process(584): Sending signal. PID: 1181 SIG: 9
11-01 14:33:39.117: WARN/UsageStats(584): Unexpected resume of 
com.android.launcher
while already resumed in com.example
11-01 14:33:39.176: INFO/WindowManager(584): WIN DEATH: Window{437e4350
com.example/com.example.Test paused=false}
11-01 14:33:39.176: DEBUG/ActivityManager(584): Received spurious death 
notification
for thread android.os.BinderProxy@438c9318
11-01 14:33:39.246: WARN/InputManagerService(584): Got RemoteException sending
setActive(false) notification to pid 1181 uid 10027
11-01 14:33:39.426: INFO/installd(555): move
/data/dalvik-cache/data@app@vmdl15362.tmp@classes.dex ->
/data/dalvik-cache/data@app@com.example.apk@classes.dex
11-01 14:33:39.426: DEBUG/PackageManager(584): New package installed in
/data/app/com.example.apk
11-01 14:33:39.597: DEBUG/AndroidRuntime(1192): Shutting down VM
11-01 14:33:39.597: DEBUG/dalvikvm(1192): DestroyJavaVM waiting for non-daemon
threads to exit
11-01 14:33:39.617: DEBUG/ActivityManager(584): Uninstalling process com.example
11-01 14:33:39.617: DEBUG/dalvikvm(1192): DestroyJavaVM shutting VM down
11-01 14:33:39.617: DEBUG/dalvikvm(1192): HeapWorker thread shutting down
11-01 14:33:39.617: DEBUG/dalvikvm(1192): HeapWorker thread has shut down
11-01 14:33:39.626: DEBUG/jdwp(1192): JDWP shutting down net...
11-01 14:33:39.626: DEBUG/jdwp(1192): +++ peer disconnected
11-01 14:33:39.626: INFO/dalvikvm(1192): Debugger has detached; object registry 
had 1
entries
11-01 14:33:39.636: DEBUG/dalvikvm(1192): VM cleaning up
11-01 14:33:39.687: DEBUG/dalvikvm(1192): LinearAlloc 0x0 used 664844 of 
4194304 (15%)
11-01 14:33:40.056: DEBUG/dalvikvm(584): GC freed 8940 objects / 533672 bytes 
in 304ms
11-01 14:33:40.158: WARN/ResourceType(584): No package identifier when getting 
value
for resource number 0x7f060001
11-01 14:33:40.167: WARN/ResourceType(584): No package identifier when getting 
value
for resource number 0x7f060000
11-01 14:33:40.377: DEBUG/dalvikvm(638): GC freed 122 objects / 4736 bytes in 
297ms
11-01 14:33:40.377: DEBUG/HomeLoaders(638): application intent received:
android.intent.action.PACKAGE_REMOVED, replacing=true
11-01 14:33:40.386: WARN/ResourceType(584): No package identifier when getting 
value
for resource number 0x7f060001
11-01 14:33:40.386: DEBUG/HomeLoaders(638):   --> package:com.example
11-01 14:33:40.396: WARN/ResourceType(584): No package identifier when getting 
value
for resource number 0x7f060000
11-01 14:33:40.396: DEBUG/HomeLoaders(638): application intent received:
android.intent.action.PACKAGE_ADDED, replacing=true
11-01 14:33:40.408: DEBUG/HomeLoaders(638):   --> package:com.example
11-01 14:33:40.408: DEBUG/HomeLoaders(638):   --> update package com.example
11-01 14:33:40.966: DEBUG/AndroidRuntime(1206): >>>>>>>>>>>>>> AndroidRuntime 
START
<<<<<<<<<<<<<<
11-01 14:33:40.976: DEBUG/AndroidRuntime(1206): CheckJNI is ON
11-01 14:33:41.236: DEBUG/AndroidRuntime(1206): --- registering native 
functions ---
11-01 14:33:41.236: INFO/jdwp(1206): received file descriptor 20 from ADB
11-01 14:33:41.507: DEBUG/ddm-heap(1206): Got feature list request
11-01 14:33:42.066: INFO/ActivityManager(584): Starting activity: Intent {
flg=0x10000000 cmp=com.example/.Test }
11-01 14:33:42.146: DEBUG/AndroidRuntime(1206): Shutting down VM
11-01 14:33:42.146: DEBUG/dalvikvm(1206): DestroyJavaVM waiting for non-daemon
threads to exit
11-01 14:33:42.158: DEBUG/dalvikvm(1206): DestroyJavaVM shutting VM down
11-01 14:33:42.158: DEBUG/dalvikvm(1206): HeapWorker thread shutting down
11-01 14:33:42.158: DEBUG/dalvikvm(1206): HeapWorker thread has shut down
11-01 14:33:42.158: DEBUG/jdwp(1206): JDWP shutting down net...
11-01 14:33:42.167: DEBUG/jdwp(1206): +++ peer disconnected
11-01 14:33:42.167: INFO/dalvikvm(1206): Debugger has detached; object registry 
had 1
entries
11-01 14:33:42.177: DEBUG/dalvikvm(1206): VM cleaning up
11-01 14:33:42.197: INFO/ActivityManager(584): Start proc com.example for 
activity
com.example/.Test: pid=1213 uid=10027 gids={3003}
11-01 14:33:42.297: DEBUG/dalvikvm(1206): LinearAlloc 0x0 used 676436 of 
4194304 (16%)
11-01 14:33:42.397: DEBUG/dalvikvm(553): GC freed 276 objects / 10512 bytes in 
196ms
11-01 14:33:42.487: INFO/jdwp(1213): received file descriptor 20 from ADB
11-01 14:33:42.537: ERROR/jdwp(1213): Failed sending reply to debugger: Broken 
pipe
11-01 14:33:42.537: INFO/dalvikvm(1213): Debugger has detached; object registry 
had 2
entries
11-01 14:33:42.597: DEBUG/dalvikvm(553): GC freed 52 objects / 2232 bytes in 
189ms
11-01 14:33:42.716: DEBUG/dalvikvm(553): GC freed 2 objects / 56 bytes in 119ms
11-01 14:33:43.007: WARN/Resources(1213): Converting to string:
TypedValue{t=0x12/d=0x0 a=2 r=0x7f050000}
11-01 14:33:43.017: INFO/TEST(1213): Fetching request token from Fire Eagle...
11-01 14:33:43.506: INFO/jdwp(1213): received file descriptor 27 from ADB
11-01 14:33:43.517: DEBUG/ddm-heap(1213): Got feature list request
11-01 14:33:43.876: INFO/global(1213): Default buffer size used in 
BufferedReader
constructor. It would be better to be explicit if an 8k-char buffer is required.
11-01 14:33:43.886: INFO/TEST(1213): Request token: OHEXtpwfrNRo
11-01 14:33:43.886: INFO/TEST(1213): Token secret: 
RjagazaLR52hQ4S4alczjxQgqjd0tvrH
11-01 14:33:43.886: INFO/TEST(1213): Now visit:
11-01 14:33:43.886: INFO/TEST(1213):
https://fireeagle.yahoo.net/oauth/authorize?oauth_token=OHEXtpwfrNRo
11-01 14:33:43.886: INFO/TEST(1213): ... and grant this app authorization
11-01 14:33:43.886: INFO/TEST(1213): Enter the verification code and hit ENTER 
when
you're done
11-01 14:33:44.117: INFO/ActivityManager(584): Displayed activity 
com.example/.Test:
1998 ms (total 1998 ms)
11-01 14:33:49.227: DEBUG/dalvikvm(638): GC freed 3130 objects / 177584 bytes 
in 97ms
11-01 14:33:54.207: DEBUG/dalvikvm(970): GC freed 6 objects / 176 bytes in 76ms
11-01 14:34:47.786: WARN/KeyCharacterMap(1213): No keyboard for id 0
11-01 14:34:47.786: WARN/KeyCharacterMap(1213): Using default keymap:
/system/usr/keychars/qwerty.kcm.bin
11-01 14:34:56.466: INFO/TEST(1213): Fetching access token from Fire Eagle...
11-01 14:34:56.497: INFO/global(1213): Default buffer size used in 
BufferedReader
constructor. It would be better to be explicit if an 8k-char buffer is required.
11-01 14:34:56.507: WARN/System.err(1213):
oauth.signpost.exception.OAuthExpectationFailedException: Request token or token
secret not set in server reply. The service provider you use is probably buggy.
11-01 14:34:56.517: WARN/System.err(1213):     at
oauth.signpost.basic.DefaultOAuthProvider.retrieveToken(DefaultOAuthProvider.jav
a:140)
11-01 14:34:56.517: WARN/System.err(1213):     at 
xtView.onTouchEvent(TextView.java:6504)
11-01 14:34:56.527: WARN/System.err(1213):     at
android.view.Viewoauth.signpost.basic.DefaultOAuthProvider.retrieveAccessToken(D
efaultOAuthProvider.java:98)
11-01 14:34:56.517: WARN/System.err(1213):     at
com.example.Test$1.onClick(Test.java:89)
11-01 14:34:56.527: WARN/System.err(1213):     at
android.view.View.performClick(View.java:2344)
11-01 14:34:56.527: WARN/System.err(1213):     at
android.view.View.onTouchEvent(View.java:4133)
11-01 14:34:56.527: WARN/System.err(1213):     at
android.widget.Te.dispatchTouchEvent(View.java:3672)
11-01 14:34:56.527: WARN/System.err(1213):     at
android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:882)
11-01 14:34:56.527: WARN/System.err(1213):     at
android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:882)
11-01 14:34:56.527: WARN/System.err(1213):     at
android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:882)
11-01 14:34:56.536: WARN/System.err(1213):     at
android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:882)
11-01 14:34:56.536: WARN/System.err(1213):     at
com.android.internal.policy.impl.PhoneWindow$DecorView.superDispatchTouchEvent(P
honeWindow.java:1712)
11-01 14:34:56.536: WARN/System.err(1213):     at
com.android.internal.policy.impl.PhoneWindow.superDispatchTouchEvent(PhoneWindow
.java:1202)
11-01 14:34:56.536: WARN/System.err(1213):     at
android.app.Activity.dispatchTouchEvent(Activity.java:1987)
11-01 14:34:56.536: WARN/System.err(1213):     at
com.android.internal.policy.impl.PhoneWindow$DecorView.dispatchTouchEvent(PhoneW
indow.java:1696)
11-01 14:34:56.536: WARN/System.err(1213):     at
android.view.ViewRoot.handleMessage(ViewRoot.java:1658)
11-01 14:34:56.536: WARN/System.err(1213):     at
android.os.Handler.dispatchMessage(Handler.java:99)
11-01 14:34:56.546: WARN/System.err(1213):     at 
android.os.Looper.loop(Looper.java:123)
11-01 14:34:56.546: WARN/System.err(1213):     at
android.app.ActivityThread.main(ActivityThread.java:4203)
11-01 14:34:56.546: WARN/System.err(1213):     at
java.lang.reflect.Method.invokeNative(Native Method)
11-01 14:34:56.546: WARN/System.err(1213):     at
java.lang.reflect.Method.invoke(Method.java:521)
11-01 14:34:56.546: WARN/System.err(1213):     at
com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:791)
11-01 14:34:56.546: WARN/System.err(1213):     at
com.android.internal.os.ZygoteInit.main(ZygoteInit.java:549)
11-01 14:34:56.546: WARN/System.err(1213):     at
dalvik.system.NativeStart.main(Native Method)
11-01 14:34:56.546: INFO/TEST(1213): Access token: OHEXtpwfrNRo
11-01 14:34:56.556: INFO/TEST(1213): Token secret: 
RjagazaLR52hQ4S4alczjxQgqjd0tvrH
11-01 14:34:56.677: DEBUG/dalvikvm(1213): GC freed 5169 objects / 400976 bytes 
in 105ms
11-01 14:34:56.688: INFO/global(1213): Default buffer size used in 
BufferedReader
constructor. It would be better to be explicit if an 8k-char buffer is required.
11-01 14:34:56.707: INFO/TEST(1213): Sending update request to Fire Eagle...
11-01 14:34:57.278: DEBUG/dalvikvm(1213): GC freed 3473 objects / 277192 bytes 
in 77ms
11-01 14:34:57.278: DEBUG/OpenSSLSessionImpl(1213): Freeing OpenSSL session
11-01 14:34:57.557: WARN/DefaultRequestDirector(1213): Authentication error: 
Unable
to respond to any of these challenges: {}
11-01 14:34:57.557: INFO/TEST(1213): Response: 401 Unauthorized

Original comment by dfel...@yahoo.com on 1 Nov 2009 at 7:47

Attachments:

GoogleCodeExporter commented 9 years ago 
[deleted comment]
GoogleCodeExporter commented 9 years ago 
Mathias:

Sorry for the delay.  I just tried the latest snapshot and the same error was
produced. Reverted to r47 and all is well again.

This is Android framework, both 1.5 and 1.6.  I am not sure of the httpcommons
version, but I can look into the Android references.

*This is different than dfel's injection above*, as I see in his stacktrace 
that both
a token and secret exists, but is failing on an actual signed call.  I am 
unable to
get pass hurdle 1, get request token and auth url.

However if I cheat and use r47 to save the access token and secret, and then 
upgrade
to the latest snapshot I can successfully make post, get, and delete calls using
signpost and commons.

The issue therefore I believe may not be part of a larger authentication issue, 
but
something isolated to the get token methods that changed recently.

Regards,

Eddie

Original comment by OlliTech on 1 Nov 2009 at 9:36

GoogleCodeExporter commented 9 years ago 
As I said, I cannot reproduce these problems so I cannot actually do anything 
without
having you do some detective work yourself.

Please download the source code, link it to the JARs and debug into the
retrieveToken() method of DefaultServiceProvider. The library is really small 
and
there is no magic happening there, so it shouldn't be too difficult to see 
what's
going on. It's just a signed GET request to the URL you specify.

In the case where you get the "no token set in server response" reply, the 
server
obviously didn't answer as expected. Please dissect the server reply and check 
what
it actually contains (status code and body).

Thanks for your help.

Original comment by m.kaepp...@gmail.com on 2 Nov 2009 at 9:06

GoogleCodeExporter commented 9 years ago 
I think I have at least gotten a work-around working with this code. The 
problem may
actually be with Yahoo not the OAuth library.

Essentially the crux of the matter is that the first request for an Access Token
always seems to fail. You asked to "dissect the server reply". Well, the reply 
is
completely empty. It has a status code of -1, which appears to be the default. 
So it
seems the server isn't sending anything back outside of an ACK or something. Its
possible that the underlying HTTP implementation isn't waiting for the full 
return
message or something...I don't know.

However, if I repeat the request for the Access Token, it appears to work. Then 
I am
able to set my location to "Hamburg, Germany" as the test example does. So far I
basically make the set location request knowing it will fail with the "401
unauthorized" code at first, and then rerun the request for access, and then 
that
goes through successfully. All subsequent requests to set the location seem to 
work
then as well.

I have not honed down what exactly I need to do again to make it work - I may 
not
need to try to set the location and fail, or if there is simply a time period 
that
needs to go by to get authenticated or what. But I thought I'd share this 
discovery.

-Dave

Original comment by dfel...@yahoo.com on 3 Nov 2009 at 1:47

GoogleCodeExporter commented 9 years ago 
I think I have located the source of the problem:

It turns out that the HttpURLConnection implementation on Android (which is 
part of 
Apache Harmony, the open source Java implementation used by Android) turns HTTP 
headers into lower case; that's a violation of the HTTP 1.1 spec, and certain 
service 
providers may ignore a lower-case Authorization header, hence answering with 
401 
(Unauthorized).

To prevent this issue, I will provide an OAuthProvider implementation that uses 
Apache HttpClient, as part of the signpost-commonshttp4.jar package.

Original comment by m.kaepp...@gmail.com on 5 Nov 2009 at 9:49

GoogleCodeExporter commented 9 years ago 
Interesting (and great news).  What changed since r47 that would have previously
allowed this to work if the issue is isolated to android's implementation of
HttpURLConnection?  Was HUC not used previously?

Regards,

Eddie

Original comment by OlliTech on 5 Nov 2009 at 10:20

GoogleCodeExporter commented 9 years ago 
Well, there have been plenty of changes since r47, it's difficult to say which 
may
have caused it. Some of them were related to OAuth 1.0a support, some to
serialization, and others were bug fixes.

Maybe your problem is entirely unrelated to that of Eddie's. The error you're 
seeing
("authentication challenge is null") simply means that the HTTP server replied 
with a
401 status code, which could mean anything from there was no auth header to 
wrong
signature or whatever.

Original comment by m.kaepp...@gmail.com on 6 Nov 2009 at 8:53

GoogleCodeExporter commented 9 years ago 
By the way, which service provider are we talking about anyway? Wouldn't be the 
first
time that it turned out to be a buggy service endpoint instead of the library.

Also, which version of Android?

Original comment by m.kaepp...@gmail.com on 6 Nov 2009 at 9:01

GoogleCodeExporter commented 9 years ago 
Will there be a fix in the near future for the lower case auth headers?

Original comment by festival...@googlemail.com on 29 Dec 2009 at 10:49

GoogleCodeExporter commented 9 years ago 
"fixed" in 1.2-SNAPSHOT in the sense that there is now a 
CommonsHttpOAuthConsumer 
which doesn't suffer from that problem.

It's generally not truly fixable, since it's a bug in Android/Apache Harmony, 
not 
Signpost.

You can download the latest build here: 
http://github.com/kaeppler/signpost/downloads

or depend on 1.2-SNAPSHOT in Maven.

If you find problems with the new provider implementation, please open a new 
ticket.

Original comment by m.kaepp...@gmail.com on 30 Dec 2009 at 1:22