IndieAuth auth code verification fails for Bridgy

[snarfed]

cross posting here from snarfed/bridgy#809 (comment) . we don't yet know if this is a bridgy bug, a known bug, or something else altogether. there's some discussion there (further down) about single user mode and home page vs user profile URLs, but no conclusion yet. cc @mapkyca @skddc. thanks in advance for looking!

While trying to do this:

Open https://brid.gy/ , click the Instagram button (you won't need an Instagram account), enter a Known site's URL into the IndieAuth box, and try to log in with IndieAuth.

I encountered this error:

bridgy redirects to known like this:

https://updates.kip.pe/indieauth/auth?me=https%3A%2F%2Fupdates.kip.pe&state=%257B%2522endpoint%2522%253A%2522https%253A%252F%252Fupdates.kip.pe%252Findieauth%252Fauth%2522%252C%2522me%2522%253A%2522https%253A%252F%252Fupdates.kip.pe%2522%257D&redirect_uri=https%3A%2F%2Fbrid.gy%2Finstagram%2Fcallback&client_id=https%3A%2F%2Fbrid.gy%2F

known then redirects back to bridgy with an auth code:

https://brid.gy/instagram/callback?code=CODE&state=%257B%2522endpoint%2522%253A%2522https%253A%252F%252Fupdates.kip.pe%252Findieauth%252Fauth%2522%252C%2522me%2522%253A%2522https%253A%252F%252Fupdates.kip.pe%2522%257D&me=https%3A%2F%2Fupdates.kip.pe%2Fprofile%2Fbasti

bridgy tries to verify the auth code:

POST https://updates.kip.pe/indieauth/auth
me=https%3A%2F%2Fupdates.kip.pe&state=&code=CODE&client_id=https%3A%2F%2Fbrid.gy%2F&redirect_uri=https%3A%2F%2Fbrid.gy%2Finstagram%2Fcallback

Known responds:

HTTP/1.1 400 Bad Request
error=Invalid+auth+code

i tried this simpler verification request, without the escaping or the non-standard me and state parameters, and it gets the same result:

POST https://updates.kip.pe/indieauth/auth
code=CODE&client_id=https://brid.gy/&redirect_uri=https://brid.gy/instagram/callback

Some other notes:

• this happens for @skddc with Known version ec0752d

[mapkyca]

I've added some extra logging to this, so that hopefully we can pin down what is actually causing the error.

This includes a better return message, plus some logging on the server.

[snarfed]

friendly ping @skddc, mind trying again with the new logging @mapkyca added?

[raucao]

Wow, so I just found out what broke it. Not exactly why or how, but at least what.

After reporting the issue with brid.gy login I recently also started to run into issues with just logging in on my own site itself. However, using a private browsing window it still worked. Then I updated Known and checked the logs, which contained a similar error about a token being invalid:

[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error - Token was not valid:
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error - 
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error - Debug:Array
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error - (
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error -     [time] => 1532355850
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error -     [token] => 5f8[...]24f60
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error -     [action] => /session/login
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error -     [site_secret] => 7cc[...]1083b
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error -     [session_id] => as7[...]9of60
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error -     [expected-token] => 904[...]910de
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error -     [expected-token-no-action] => 015[...]109ee
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error - )
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): error - 
[23-Jul-2018 14:24:22 UTC] Known (updates.kip.pe): critical - Invalid token. [/var/www/updates.kip.pe/Idno/Common/Page.php:354]

This lead me to investigate my browser extensions, which I didn't suspect at first because they would usually just mess with JavaScript, and I couldn't see how Known's login would depend on JS. However, I found this non-descriptive new feature in Ghostery (lower left corner):

I found this, because Ghostery said it blocked 1 tracker, even though my personal site is not using any kind of tracker or external widget. Upon pressing this button to deactivate the feature, it showed me that now it is not blocking any trackers anymore, and after reloading I could both log in to my site as well as connect brid.gy without a problem.

Now, as I said, I have no idea what token is meant there and how and why an extension would be able to mess with it, but it seems to me like this Ghostery feature could modify cookies that it perceives as tracking cookie or something.

So, I guess the moral of the story is to investigate extensions first, then open issues on GitHub later. But this could still be helpful information for anyone running into this issue after me in the future, of course. So thank you all very much for helping, and also for adding the extended logging there. I'm sure it won't hurt. And sorry for not trying this in a clean browser window before reporting the issue! 😊

[snarfed]

wow, thanks for the detailed sleuthing @skddc! glad you figured it out.

[mapkyca]

Ohhhh.... now that is interesting!

I wonder what could be causing the false positive here. Good to know anyway!

Glad you got it sorted.