WordPress Callback fails

[hknet]

Hi,
I registered successfully our diaspora pod as a wordpress app, but after the user authenticates it, the callback fails with 505 (yeah, I set it correctly to https://[pod.domain.tld]/auth/wordpress/callback ).

any help is appreciated,
hk

---

Want to back this issue? Post a bounty on it! We accept bounties via Bountysource.

[gabsoftware]

Hi,

I have the exact same issue on my pod (freehuman.fr) when I try to link my profile to my WordPress.com account. However my error number is 500, not 505.

[Flaburgan]

@gabsoftware could you please post the corresponding log?

[gabsoftware]

@Flaburgan
Sure, here it is:

[2016-02-22T11:48:44] INFO  PID-12605 TID-6345660 Rails: Started GET "/stream?_=1456138121732" for 78.195.2.20 at 2016-02-22 11:48:44 +0100
[2016-02-22T11:48:44] INFO  PID-12605 TID-6345660 ActionController::Base: Processing by StreamsController#multi as JSON
[2016-02-22T11:48:44] INFO  PID-12605 TID-6345660 ActionController::Base:   Parameters: {"_"=>"1456138121732"}
[2016-02-22T11:48:44] INFO  PID-6131 TID-6345660 Rails: Started POST "/api/v1/tokens" for 78.195.2.20 at 2016-02-22 11:48:44 +0100
[2016-02-22T11:48:44] INFO  PID-6131 TID-6345660 ActionController::Base: Processing by Api::V1::TokensController#create as JSON
[2016-02-22T11:48:45] INFO  PID-6131 TID-6345660 ActionController::Base: Completed 200 OK in 75ms (Views: 11.6ms | ActiveRecord: 20.8ms)
[2016-02-22T11:48:46] INFO  PID-12605 TID-6345660 ActionController::Base: Completed 200 OK in 1876ms (Views: 415.6ms | ActiveRecord: 1175.1ms)
[2016-02-22T11:48:49] INFO  PID-6131 TID-6345660 Rails: Started GET "/people/xxxxxxxxxxxxxxxxxxxxxxxx" for 78.195.2.20 at 2016-02-22 11:48:49 +0100
[2016-02-22T11:48:49] INFO  PID-6131 TID-6345660 ActionController::Base: Processing by PeopleController#show as HTML
[2016-02-22T11:48:49] INFO  PID-6131 TID-6345660 ActionController::Base:   Parameters: {"id"=>"xxxxxxxxxxxxxxxxxxxxxxxxxxx"}
  Rendered publisher/_aspect_dropdown.html.haml (4.2ms)
  Rendered shared/_public_explain.haml (5.0ms)
  Rendered publisher/_publisher.html.haml (159.8ms)
  Rendered shared/_modal.haml (0.6ms)
  Rendered people/show.html.haml within layouts/with_header (166.5ms)
  Rendered layouts/_header.html.haml (0.1ms)
  Rendered layouts/_open_graph.haml (2.6ms)
  Rendered layouts/application.html.haml (660.9ms)
[2016-02-22T11:48:50] INFO  PID-6131 TID-6345660 ActionController::Base: Completed 200 OK in 1008ms (Views: 221.0ms | ActiveRecord: 698.6ms)
[2016-02-22T11:48:50] INFO  PID-12605 TID-6345660 Rails: Started GET "/people/xxxxxxxxxxxxxxxxxxxxxx/stream?_=xxxxxxxxxxxxxxxx" for 78.195.2.20 at 2016-02-22 11:48:50 +0100
[2016-02-22T11:48:50] INFO  PID-12605 TID-6345660 ActionController::Base: Processing by PeopleController#stream as JSON
[2016-02-22T11:48:50] INFO  PID-12605 TID-6345660 ActionController::Base:   Parameters: {"_"=>"xxxxxxxxxxxxxxxx", "person_id"=>"xxxxxxxxxxxxxxxxxxxxx"}
[2016-02-22T11:48:52] INFO  PID-12605 TID-6345660 ActionController::Base: Completed 200 OK in 1949ms (Views: 885.9ms | ActiveRecord: 1023.1ms)
[2016-02-22T11:48:53] INFO  PID-12605 TID-6345660 Rails: Started GET "/profile/edit" for 78.195.2.20 at 2016-02-22 11:48:53 +0100
[2016-02-22T11:48:53] INFO  PID-12605 TID-6345660 ActionController::Base: Processing by ProfilesController#edit as HTML
  Rendered shared/_settings_nav.haml (1.4ms)
  Rendered photos/_new_profile_photo.haml (1.9ms)
  Rendered profiles/_edit_public.haml (4.2ms)
  Rendered profiles/_edit.haml (12.3ms)
  Rendered profiles/edit.haml within layouts/with_header_with_footer (23.5ms)
  Rendered shared/_links.haml (2.5ms)
  Rendered layouts/_footer.html.haml (2.7ms)
  Rendered layouts/_header.html.haml (0.1ms)
  Rendered layouts/_open_graph.haml (1.9ms)
  Rendered layouts/application.html.haml (58.3ms)
  Rendered layouts/with_header.html.haml (59.0ms)
[2016-02-22T11:48:53] INFO  PID-12605 TID-6345660 ActionController::Base: Completed 200 OK in 116ms (Views: 83.0ms | ActiveRecord: 9.2ms)
[2016-02-22T11:48:56] INFO  PID-6131 TID-6345660 Rails: Started GET "/services" for 78.195.2.20 at 2016-02-22 11:48:56 +0100
[2016-02-22T11:48:56] INFO  PID-6131 TID-6345660 ActionController::Base: Processing by ServicesController#index as HTML
  Rendered shared/_settings_nav.haml (6.1ms)
  Rendered services/_add_remove_services.haml (14.9ms)
  Rendered services/index.html.haml within layouts/with_header_with_footer (35.2ms)
  Rendered shared/_links.haml (3.5ms)
  Rendered layouts/_footer.html.haml (3.8ms)
  Rendered layouts/_header.html.haml (0.1ms)
  Rendered layouts/_open_graph.haml (3.0ms)
  Rendered layouts/application.html.haml (49.7ms)
  Rendered layouts/with_header.html.haml (50.4ms)
[2016-02-22T11:48:56] INFO  PID-6131 TID-6345660 ActionController::Base: Completed 200 OK in 249ms (Views: 228.8ms | ActiveRecord: 5.5ms)
[2016-02-22T11:48:56] INFO  PID-6131 TID-6345660 Rails: Started POST "/receive/public" for 46.4.207.244 at 2016-02-22 11:48:56 +0100
[2016-02-22T11:48:56] INFO  PID-6131 TID-6345660 ActionController::Base: Processing by DiasporaFederation::ReceiveController#public as */*
[2016-02-22T11:48:56] INFO  PID-6131 TID-6345660 ActionController::Base:   Parameters: {"xml"=>"[FILTERED]"}
[2016-02-22T11:48:56] INFO  PID-6131 TID-6345660 DiasporaFederation::ReceiveController: received a public message
  Rendered text template (0.0ms)
[2016-02-22T11:48:56] INFO  PID-6131 TID-6345660 ActionController::Base: Completed 202 Accepted in 2ms (Views: 0.6ms | ActiveRecord: 0.0ms)
[2016-02-22T11:48:58] INFO  PID-6131 TID-6345660 Rails: Started GET "/auth/wordpress" for 78.195.2.20 at 2016-02-22 11:48:58 +0100
[2016-02-22T11:49:04] INFO  PID-6131 TID-6345660 Rails: Started POST "/receive/public" for 176.9.185.156 at 2016-02-22 11:49:04 +0100
[2016-02-22T11:49:04] INFO  PID-6131 TID-6345660 ActionController::Base: Processing by DiasporaFederation::ReceiveController#public as */*
[2016-02-22T11:49:04] INFO  PID-6131 TID-6345660 ActionController::Base:   Parameters: {"xml"=>"[FILTERED]"}
[2016-02-22T11:49:04] INFO  PID-6131 TID-6345660 DiasporaFederation::ReceiveController: received a public message
  Rendered text template (0.0ms)
[2016-02-22T11:49:04] INFO  PID-6131 TID-6345660 ActionController::Base: Completed 202 Accepted in 2ms (Views: 0.4ms | ActiveRecord: 0.0ms)
[2016-02-22T11:49:14] INFO  PID-12605 TID-6345660 Rails: Started GET "/auth/wordpress/callback?code=xxxxxxx&state=xxxxxxxxxxxxxxxxxxxxxxxxxxxx" for 78.195.2.20 at 2016-02-22 11:49:14 +0100
[2016-02-22T11:49:15] FATAL PID-12605 TID-6345660 Rails:
OAuth2::Error (invalid_grant: Invalid authorization_code.
{"error":"invalid_grant","error_description":"Invalid authorization_code."}):
  lib/rack/chrome_frame.rb:39:in `call'
  lib/unicorn_killer.rb:35:in `call'

[gabsoftware]

This is the error I get:

I already double-checked that my config is correct in diaspora.yml:

    ## OAuth credentials for Wordpress
    wordpress: ## Section

      enable: true
      client_id: 'xxxxx'
      secret: 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'

My app is set up correctly, I believe:

[Joraeim]

I have the same issue. I'm not sure when it appeared, but it was sometime between V0.5.5.1 and now. Mine was working, but sometime in that time period/update period it stopped working.

I'm getting the same "Invalid authorization_code" error.

[Flaburgan]

@gabsoftware I see no 500 in the log you posted, this is not the corresponding logs.

[denschub]

@Flaburgan

[2016-02-22T11:49:15] FATAL PID-12605 TID-6345660 Rails:
OAuth2::Error (invalid_grant: Invalid authorization_code.
{"error":"invalid_grant","error_description":"Invalid authorization_code."}):
  lib/rack/chrome_frame.rb:39:in `call'
  lib/unicorn_killer.rb:35:in `call'

…

[gabsoftware]

Well is there another log than the production log then?

[Flaburgan]

@gabsoftware I just didn't know the error 500 page could be displayed without a "Completed 500" in the logs. Looks like I was wrong, sorry ;)

[denschub]

@Flaburgan That's only the case if we actually result the 500 ourselves (i.e. return a response with status: 500). If the request gets interrupted by an exception we don't handle, the request is technically never completed.

[cmrd-senya]

So here is what I've discovered.

Exception is raised from the request method of the OAuth2 client which in its turn is called from the get_token method.

opts parameter that is passed to the request method is roughly following:

{:raise_errors=>true, :parse=>:json, :body=>{"grant_type"=>"authorization_code", "code"=>"***", "client_id"=>"**", "client_secret"=>"****", :redirect_uri=>"http://development.diaspora.local/auth/wordpress/callback?code=***&state=****"}, :headers=>{"Content-Type"=>"application/x-www-form-urlencoded"}}

The request is POSTed to the https://public-api.wordpress.com/oauth2/token and the response is 400 with the body as informative as

{"error"=>"invalid_grant", "error_description"=>"Invalid authorization_code."}

This response raises an exception from this point.

I can't clearly say what it means right now.

[denschub]

Is this a blog on wordpress.com or a self-hosted one? Have you checked the credentials and the return url in the application preferences? Is this reproducible with a non-local pod? Could be they are blocking domains they cannot resolve.

[nbyun]

@cmrd-senya Did you solve that problem? {"error"=>"invalid_grant", "error_description"=>"Invalid authorization_code."}

[cmrd-senya]

I didn't have a chance to test on a non-local pod yet. I'll retest it as soon as possible, if nobody fix it before.

[Joraeim]

Just out of curiosity, has anyone been able to make any progress on this error? I've been seeing it on my Pod as well and have not made any headway.

[sfatfarma]

I had the same issue with this.

The solution was to make sure that the 'redirect_uri' parameter is the same between subsequent calls to the authorization method.

When the 'redirect_uri' is passed to the https://public-api.wordpress.com/oauth2/authorize endpoint, it should be URL encoded.
When the same 'redirect_uri' is passed to the https://public-api.wordpress.com/oauth2/token (in post fields), it shouldn't be URL encoded.

In my case, when I got this error, both were URL encoded. Sending the normal URL to the second call solved this issue for me.

Hope this helps.

Regards,
Szabi - CodeRevolution.

[piraz]

@sfatfarma do you have a patch for that or this is only a configuration issue?

[sfatfarma]

@piraz To be honest, I stumbled upon this error in the code I wrote (I am not using Diaspora). I found this threat only when I was browsing to find a fix for the issue from my code. I made the fix directly in my code.

[realkinetix]

Hi all - new pod owner here and this bug lives on in 0.7.3.1. I'd be happy to help diagnose from an admin standpoint as best as I can. It's completely reproducible here.

• I setup an account on wordpress.com
• Followed the steps to setup the app at wordpress for my pod
• Diaspora accepted the config without issue
• When a user goes to try and connect their account to their wordpress account, errors as per above