2018-09-12 OAuth and Mastodon

This page is mostly about trying to debug OAuth for Mastodon. Here’s the thing: I have a web application called Trunk. When you use it, you can mass-follow a number of accounts.

Trunk

Sadly, I see OAuth issues piling up. I get the impression that my app mostly works, but every day I see reports by users getting “Client authentication failed due to unknown client, no client authentication included, or unsupported authentication method”. The 3 instances I looked at reported their version to be 2.5.0 according to `/api/v1/instances`. What do you think I should do? How to debug this?

reports

This is why I started writing this page. I’m hoping that some Mastodon client developer can look at the flow of things and tell me where I’m doing it wrong. Or perhaps they are running into similar issues and found a way around it? Perhaps register the app every single time? Who knows. All I know is that I’m seeing multiple reports.

If you want to look at the source code while you read this, you can find it in my repository.

in my repository

The basic overview of the OAuth flow is this:

1. Create your app in the instance and make sure you use the same scopes and redirect URL later. This gives you the client credentials `client_id` and `client_secret`.

2. Redirect your user to the instance using the same scopes, redirect URL, and client credentials.

3. If all went well, you’ll your redirection URL gets visited with a `code` parameter. Transform it into an access token ASAP (using the same parameters as before).

4. Use the token as bearer token for each call to the mastodon API.

Here’s what this looks like in my app.

You start out with `/follow_confirm`. The web site says:

**Please confirm**
We’re going to use kensanata@octodon.social to follow all the accounts in Test.
*Let’s do this*
If you’d like to help us find the authorisation problems we’ve been having, please use the following link instead:
*Let’s log this*

When you click the link, you’re sent to the `/auth` route. There, we’re going to get ourselves a client. We check if the client is already registered. We do this by checking our file with all the client credentials and look for the `octodon.social` credentials. If we don’t find them, we’re going to register the client. in this case this is not necessary.

The `/auth` route now has a client. We’re going to authorise it. This means storing a bunch of cookies in the browser and then redirecting to the oauth URL of `octodon.social`. If the browser has the `octodon.social` cookie set, then no action is required. Otherwise, I need to click the big *Authorize* button. `octodon.social` then redirects back to our application, i.e. the `/` route, with an *authorisation code*.

I think this is where people are getting the error: “Client authentication failed due to unknown client, no client authentication included, or unsupported authentication method”. They get the error from the instance, not from my web application, after all.

Screenshot of the error message

Anyway, assuming everything worked as intended... We’re back at `/` and we need to figure out what to do. If we are being called without a code, then we’re just going to show our main page. But in this case, we did get a code. So now we look at our cookies in order to discover what it was I was trying to accomplish. Ah! I was trying to follow the *Test* list, right. So we’re going to redirect to `/do/follow`.

main page

The `/do/follow` route looks at the cookie and the parameters, again. Yep, got an account, got a list name, got a code... So now we’re going to get ourselves a client! You know how it is. The HTTP protocol is stateless. So we have to redo it all: get the client credentials from the file. This time we have a code, which is cool, so authorise the client again. Now we get the real deal: the *authorisation token*. Well, in my case the `Mastodon::Client` library handles all the painful details. But here we are, now. We have a client with the token. We’re good to go!

Now the application starts remote-following the accounts in the list. We end our journey on the `/do/follow` route. The URL actually contains the code but not the token. I still replaced the client_id and the authorisation code in the log with `XXX`.

Here’s what the log says:

[Wed Sep 12 22:58:24 2018] [debug] GET "/follow_confirm" (4fa2b1fd)
[Wed Sep 12 22:58:24 2018] [debug] Routing to a callback
[Wed Sep 12 22:58:24 2018] [debug] Rendering cached template "follow_confirm.html.ep" from DATA section
[Wed Sep 12 22:58:24 2018] [debug] Rendering cached template "layouts/default.html.ep" from DATA section
[Wed Sep 12 22:58:24 2018] [debug] 200 OK (0.003705s, 269.906/s)
[Wed Sep 12 22:58:32 2018] [debug] GET "/auth" (9f1d8f22)
[Wed Sep 12 22:58:32 2018] [debug] Routing to a callback
[Wed Sep 12 22:58:32 2018] [debug] kensanata@octodon.social wants to authorize the 'follow' action for the Test list
[Wed Sep 12 22:58:32 2018] [debug] kensanata@octodon.social found client credentials for octodon.social: id yes, secret yes
[Wed Sep 12 22:58:32 2018] [debug] kensanata@octodon.social has a client: yes
[Wed Sep 12 22:58:32 2018] [debug] kensanata@octodon.social is being redirected to https://octodon.social/oauth/authorize?redirect_uri=http%3A%2F%2Flocalhost%3A3000&response_type=code&client_id=XXX&scope=follow+read+write
[Wed Sep 12 22:58:32 2018] [debug] 302 Found (0.024886s, 40.183/s)
[Wed Sep 12 22:58:32 2018] [debug] GET "/" (8a14f8db)
[Wed Sep 12 22:58:32 2018] [debug] Routing to a callback
[Wed Sep 12 22:58:32 2018] [debug] kensanata@octodon.social is authorized for the 'follow' action using the Test list, redirecting to /do/follow?code=XXX&account=kensanata%40octodon.social&name=Test&logging=ok
[Wed Sep 12 22:58:32 2018] [debug] 302 Found (0.000799s, 1251.564/s)
[Wed Sep 12 22:58:32 2018] [debug] GET "/do/follow" (b79fbbdb)
[Wed Sep 12 22:58:32 2018] [debug] Routing to a callback
[Wed Sep 12 22:58:32 2018] [debug] kensanata@octodon.social found client credentials for octodon.social: id yes, secret yes
[Wed Sep 12 22:58:32 2018] [debug] kensanata@octodon.social has a client: yes
[Wed Sep 12 22:58:32 2018] [debug] kensanata@octodon.social authorizing using a code: yes
[Wed Sep 12 22:58:33 2018] [debug] kensanata@octodon.social begins to follow 2 accounts from list Test
[Wed Sep 12 22:58:33 2018] [debug] kensanata@octodon.social followed 2 accounts from list Test
[Wed Sep 12 22:58:33 2018] [debug] Rendering template "follow_done.html.ep" from DATA section
[Wed Sep 12 22:58:33 2018] [debug] Rendering cached template "layouts/default.html.ep" from DATA section
[Wed Sep 12 22:58:33 2018] [debug] 200 OK (0.762821s, 1.311/s)

​#Mastodon

Comments

(Please contact me if you want to remove your comment.)

Did you try with scope written with %20 instead of +?

"&scope=follow+read+write"

Other than that this call fail:

redirect_uri=https%3A%2F%2Fcommunitywiki.org%2Ftrunk&response_type=code&client_id=xxxxxxxxxxxxxxxxxxx&scope=follow+read+write

If it’s not the scope, your client_id is no longer known by the instance. Did you try to register the app each time to see if the problem comes from your way of storing app clients?

https://github.com/tootsuite/documentation/blob/master/Using-the-API/API.md#apps

– tom79 2018-09-13 05:41 UTC

---

It also fails with a fresh client id due to a server side error on this callback for code:

https://communitywiki.org/trunk?code=XXXXXXXXXXXXXXXXXXXXXXX

Header:

Location: /trunk/do/follow?code=XXXXXXXXXXXXXXXXXXXXXXX&account=tom79%40ins.mastalab.app&name=Biology&logging=

– tom79 2018-09-13 05:54 UTC

---

Hm, I need better logging at that point: I see in my logs that you got a 500 error:

[Thu Sep 13 07:51:40 2018] [info] 178.209.50.237 GET http://communitywiki.org:8080/trunk/do/follow?code=XXXXXXXXXXXXXXXXXXXXXXX&account=tom79%40ins.mastalab.app&name=Biology&logging= 500 0.1443s

But that’s it. As far as I can tell from here, the flow looks correct: you did get authorised or the instance would not have sent you back to the redirect URL with a code. But it did, so that worked. So now the code is about to do this:

1. get the authorisation *token* using the code it just got

2. use the token to create the list, follow people and add these people to the list

– Alex Schroeder 2018-09-13 07:03 UTC

---

OK, I found a problem! I currently have 159 client credentials but when I look for *duplicates*, there’s a problem:

qoto.org 4
mastodon.social 23
ins.mastalab.app 2
mastodon.art 3
mstdn.io 2

This is obviously a problem because only *one* of them is going to be the correct `client_secret`.

Well, at least here’s a clue!

– Alex Schroeder 2018-09-13 07:16 UTC

---

OK, here’s something else: I while ago I tried to follow the Test list using `kensanata@octodon.social` and got the error “Authorisation failed. Did you try to reload the page? This will not work since we’re not saving the access token.” And just now I tried again and it worked. Clearly not the same error (since the authorisation seems to work) but disconcerting none the less.

– Alex Schroeder 2018-09-13 07:50 UTC

---

Improved logging, tried following the Test list using my account on `humanities.one`.

“Client authentication failed due to unknown client, no client authentication included, or unsupported authentication method”

The log:

[Thu Sep 13 10:12:49 2018] [info] 178.209.50.237 GET http://communitywiki.org:8080/trunk/follow_confirm?account=kensanata%40humanities.one&name=Test 200 0.0223s
...
[Thu Sep 13 10:12:54 2018] [debug] GET "/trunk/auth" (8d6b9c08)
[Thu Sep 13 10:12:54 2018] [debug] Routing to a callback
[Thu Sep 13 10:12:54 2018] [debug] kensanata@humanities.one wants to authorize the 'follow' action for the Test list
[Thu Sep 13 10:12:54 2018] [debug] kensanata@humanities.one found client credentials for humanities.one: id yes, secret yes
[Thu Sep 13 10:12:54 2018] [debug] kensanata@humanities.one has a client: yes
[Thu Sep 13 10:12:54 2018] [debug] kensanata@humanities.one is being redirected to https://humanities.one/oauth/authorize?redirect_uri=https%3A%2F%2Fcommunitywiki.org%2Ftrunk&response_type=code&client_id=XXX&scope=follow+read+write
...
[Thu Sep 13 10:12:54 2018] [info] 178.209.50.237 GET http://communitywiki.org:8080/trunk/auth?account=kensanata%40humanities.one&action=follow&logging=ok&name=Test 302 0.0516s
...

And that’s the end of it! OK, let’s compare this with the flow I described: We have a client and we want to authorize it. We’re going to redirect the user to their instance. If they have the instance’s cookie set, they’re authorized immediately and should get back to our redirect URL (the `/` route).

But this is not what happens. We’re not being sent back to the redirect URL and the error is shown instead.

– Alex Schroeder 2018-09-13 08:27 UTC

---

I’m looking at some info @NicolasConstant kindly sent me and the URLs he uses are:

@NicolasConstant

create new app:
    FORM POST
    https://[instance]/api/v1/apps

    form data:

    client_name
    redirect_uris
    scopes
    website

redirect sign-in url:
     https://[instance]/oauth/authorize?scope=[scopes]&response_type=code&redirect_uri=[redirect_uri]&client_id=[client_id]

access_token retrieval
    POST
    https://[instance]/oauth/token?client_id=[client_id]&client_secret=[client_secret]&grant_type=authorization_code&code=[code]&redirect_uri=[redirect_uri]

API access :
    In the headers:
    'Authorization': 'Bearer [access_token]'

In this case, we’re not yet at the `access_token` retrieval stage. We’re at the “redirect sign-in URL” stage: `https://humanities.one/oauth/authorize?redirect_uri=https%3A%2F%2Fcommunitywiki.org%2Ftrunk&response_type=code&client_id=XXX&scope=follow+read+write` matches `https://[instance]/oauth/authorize?scope=[scopes]&response_type=code&redirect_uri=[redirect_uri]&client_id=[client_id]`.

So why is the server rejecting it?

Let’s try the following:

Just do it again. A temporary fluke? → fail

[Thu Sep 13 11:06:46 2018] [debug] Routing to a callback
[Thu Sep 13 11:06:46 2018] [debug] kensanata@humanities.one wants to authorize the 'follow' action for the Test list
[Thu Sep 13 11:06:46 2018] [debug] kensanata@humanities.one found client credentials for humanities.one: id yes, secret yes
[Thu Sep 13 11:06:46 2018] [debug] kensanata@humanities.one has a client: yes
[Thu Sep 13 11:06:46 2018] [debug] kensanata@humanities.one is being redirected to https://humanities.one/oauth/authorize?redirect_uri=https%3A%2F%2Fcommunitywiki.org%2Ftrunk&response_type=co
de&client_id=XXX&scope=follow+read+write
[Thu Sep 13 11:06:46 2018] [debug] 302 Found (0.04456s, 22.442/s)
[Thu Sep 13 11:06:46 2018] [info] 178.209.50.237 GET http://communitywiki.org:8080/trunk/auth?account=kensanata%40humanities.one&action=follow&logging=ok&name=Test 302 0.0488s

Delete the client credentials and do it again. Perhaps the `client_id` is no longer valid? → fail

[Thu Sep 13 11:07:21 2018] [debug] kensanata@humanities.one wants to authorize the 'follow' action for the Test list
[Thu Sep 13 11:07:21 2018] [debug] kensanata@humanities.one found no client credentials for YYY
[Thu Sep 13 11:07:22 2018] [debug] kensanata@humanities.one registered client and got new credentials for YYY: id yes, secret yes
[Thu Sep 13 11:07:22 2018] [debug] kensanata@humanities.one has a client: yes
[Thu Sep 13 11:07:22 2018] [debug] kensanata@humanities.one is being redirected to https://humanities.one/oauth/authorize?redirect_uri=https%3A%2F%2Fcommunitywiki.org%2Ftrunk&response_type=code&client_id=XXX&scope=follow+read+write
[Thu Sep 13 11:07:22 2018] [debug] 302 Found (0.182976s, 5.465/s)

Oops! What’s `YYY` doing here? I wonder. My log writing got confused. Will rewrite this section and try again.

– Alex Schroeder 2018-09-13 09:13 UTC

---

Still borked:

[Thu Sep 13 11:28:07 2018] [debug] GET "/trunk/auth" (a8dae4dc)
[Thu Sep 13 11:28:07 2018] [debug] Routing to a callback
[Thu Sep 13 11:28:07 2018] [debug] kensanata@humanities.one wants to authorize the 'follow' action for the Test list
[Thu Sep 13 11:28:07 2018] [debug] kensanata@humanities.one found client credentials for humanities.one: id yes, secret yes
[Thu Sep 13 11:28:07 2018] [debug] kensanata@humanities.one has a client: yes
[Thu Sep 13 11:28:07 2018] [debug] kensanata@humanities.one is being redirected to https://humanities.one/oauth/authorize?redirect_uri=https%3A%2F%2Fcommunitywiki.org%2Ftrunk&response_type=code&client_id=XXX&scope=follow+read+write
[Thu Sep 13 11:28:07 2018] [debug] 302 Found (0.043568s, 22.953/s)
[Thu Sep 13 11:28:07 2018] [info] 178.209.50.237 GET http://communitywiki.org:8080/trunk/auth?account=kensanata%40humanities.one&action=follow&logging=ok&name=Test 302 0.0520s

And after removing the credentials – it worked‽

[Thu Sep 13 11:29:38 2018] [debug] GET "/trunk/auth" (353e6e43)
[Thu Sep 13 11:29:38 2018] [debug] Routing to a callback
[Thu Sep 13 11:29:38 2018] [debug] kensanata@humanities.one wants to authorize the 'follow' action for the Test list
[Thu Sep 13 11:29:38 2018] [debug] kensanata@humanities.one found no client credentials for humanities.one
[Thu Sep 13 11:29:38 2018] [debug] kensanata@humanities.one registered client and got new credentials for humanities.one: id yes, secret yes
[Thu Sep 13 11:29:38 2018] [debug] kensanata@humanities.one has a client: yes
[Thu Sep 13 11:29:38 2018] [debug] kensanata@humanities.one is being redirected to https://humanities.one/oauth/authorize?redirect_uri=https%3A%2F%2Fcommunitywiki.org%2Ftrunk&response_type=co
de&client_id=XXX&scope=follow+read+write
[Thu Sep 13 11:29:38 2018] [debug] 302 Found (0.591784s, 1.690/s)
[Thu Sep 13 11:29:38 2018] [info] 178.209.50.237 GET http://communitywiki.org:8080/trunk/auth?account=kensanata%40humanities.one&action=follow&logging=ok&name=Test 302 0.6006s
[Thu Sep 13 11:29:42 2018] [debug] GET "/trunk" (2ca628ab)
[Thu Sep 13 11:29:42 2018] [debug] Routing to a callback
[Thu Sep 13 11:29:42 2018] [debug] kensanata@humanities.one is authorized for the 'follow' action using the Test list, redirecting to /trunk/do/follow?code=XXX&account=kensanata%40humanities.
one&name=Test&logging=ok
[Thu Sep 13 11:29:42 2018] [debug] 302 Found (0.001252s, 798.722/s)
[Thu Sep 13 11:29:42 2018] [info] 178.209.50.237 GET http://communitywiki.org:8080/trunk?code=XXX 302 0.0078s
[Thu Sep 13 11:29:42 2018] [debug] GET "/trunk/do/follow" (1d4bad6a)
[Thu Sep 13 11:29:42 2018] [debug] Routing to a callback
[Thu Sep 13 11:29:42 2018] [debug] kensanata@humanities.one found client credentials for humanities.one: id yes, secret yes
[Thu Sep 13 11:29:42 2018] [debug] kensanata@humanities.one has a client: yes
[Thu Sep 13 11:29:42 2018] [debug] kensanata@humanities.one authorizing using a code: yes
[Thu Sep 13 11:29:42 2018] [debug] kensanata@humanities.one begins to follow 4 accounts from list Test
[Thu Sep 13 11:29:45 2018] [debug] kensanata@humanities.one followed 4 accounts from list Test
[Thu Sep 13 11:29:45 2018] [debug] Rendering template "follow_done.html.ep" from DATA section
[Thu Sep 13 11:29:45 2018] [debug] Rendering cached template "layouts/default.html.ep" from DATA section
[Thu Sep 13 11:29:45 2018] [debug] 200 OK (3.888279s, 0.257/s)
[Thu Sep 13 11:29:45 2018] [info] 178.209.50.237 GET http://communitywiki.org:8080/trunk/do/follow?code=XXX&account=kensanata%40humanities.one&name=Test&logging=ok 200 3.8928s

Hm. I am convinced that my rewriting just changed the way things are being logged. Just to be sure, though, I will delete all the client credentials (except for the one I just saved) and we’ll see whether the situation improves.

– Alex Schroeder 2018-09-13 09:38 UTC

---

I tested and it now works as expected.

– tom79 2018-09-13 11:15 UTC

---

Amazing. 🤷‍♂️

– Alex Schroeder 2018-09-13 13:51 UTC