fission-codes / auth-lobby

The authentication service that Fission services run.
https://auth.fission.codes
GNU Affero General Public License v3.0
12 stars 1 forks source link

Increase logging for each step of auth process #84

Closed walkah closed 1 year ago

walkah commented 3 years ago

This is my attempt to combine bits of conversations with @therealjeffg and @expede (who should both feel welcome to add additional details), but right now: authentication will periodically fail for people and there is no error surfaced to the end user. Also, often, there is nothing in the console logs either. This also makes support difficult because there's no indication where in the process we encountered a failure.

I think there are three pieces here:

expede commented 3 years ago

Add a console.log() for the begin / end of each step

Minor detail, but a tweak could be to use console.warn/console.info/console.debug, and let the user filter what they want in the console:

Screen Shot 2021-07-09 at 08 58 34

Give better error reporting / progress indicators to the end user (beyond just "Warming up filesystem")

Yes please: more live progress exposed to the user instead of the static message! 🙏

matheus23 commented 3 years ago

FIY: There's cs.debug = true which you can set once the auth lobby starts listening on the websocket, which will print lots of valuable information. We could make this on by default?

jeffgca commented 3 years ago

FIY: There's cs.debug = true which you can set once the auth lobby starts listening on the websocket, which will print lots of valuable information. We could make this on by default?

1/ this should be enabled in staging if it isn't already.

2/ can we try this config change for prod for next week ( and I will take some time to do some testing ) and see where we get to? It's the simplest change and will at least tell us whether cs.debug = true is too much info. It probably is.

The top-level goal here is to log enough info to the console from auth lobby so that developers who are testing their app with it get informational feedback from the process - to either fix their own bugs or to enable them to file better issues when they find bugs in auth lobby.

icidasset commented 3 years ago

Which part are people having trouble with, linking devices or authenticating apps?

Couple notes:

jeffgca commented 3 years ago

Which part are people having trouble with, linking devices or authenticating apps?

As I understand it, the problem is authenticating apps - I could link devices just fine with the broken account but I couldn't load drive.

icidasset commented 3 years ago

@therealjeffg Would you be able to test that faulty account again? I've added more detailed loading messages to the app authentication, would be interesting to know which step it's getting stuck at.

jeffgca commented 3 years ago

It's still a bit mysterious:

  1. I logged in using that account
  2. I loaded drive

For step 2/ I got as far as getting back to drive.fission.codes and got this message in the console:

📓 DNSLink is up to date: bafybeib5zzsu33eukldl2gcmu5ehewty6u5fs5phjdzz446qyrg5bsjaby ... webnative.js:53

The page shows a spinner and the message 'Just a moment, loading the filesystem.' Then nothing else happens and I see no additional output on the devtools console.

I'm going to let it spin and see if anything happens, will update as events warrant.

( using macOS and latest Edge browser )

jeffgca commented 3 years ago

@therealjeffg Would you be able to test that faulty account again? I've added more detailed loading messages to the app authentication, would be interesting to know which step it's getting stuck at.

Is this supposed to be on prod? My faulty account is on Prod. Is there something I need to set to see additional logging? So far I don't see anything.

I also tried:

  1. deleted all IndexedDB databases in Edge
  2. re-linked browser from the cli
  3. re-authenticated Drive

Currently the process is stuck at the auth URL "warming up the filesystem"

https://auth.fission.codes/?didExchange=did%3Akey%3Az13V3Sog2YaUKhdGCmgx9UZuW1o1ShFJYc6DvGYe7NTt689NoL2eKPygrMjKLdnKcG6WeRqfRb5JbLoHFuzZnzzvcHWURBrowE3Gb4rsUnP2htK23tnFdAHbz2VZyiaVcqaNkgbEqsCWqcRkEEw5hUznezCYTjnbcix9eycAanueKTbH65MVf39KqMvX67zcgCNvKGxfavpFWEUMLqbrEYWmpTo4aTXe9bBvC9Gm67jnQVJMHCbo7NDanzsaWvQPztFLmqwaZP7PG55PF5f23u16MD3JcmSR5tjQAyACa9AosjG8HyhdUUoBSoHoVWgo1Y4f5p3QBGgA1sSTXFEtfVLL7T6w2Vc16M5X7TMCmQeVfEQrn4thKCcbBs5vrsqerrsANq433rvvBSZXHJ7tgCG&didWrite=did%3Akey%3Az13V3Sog2YaUKhdGCmgx9UZuW1o1ShFJYc6DvGYe7NTt689NoL2rpbK6X2SvbhtP35ovfQcvtsY6fMaWfKGn65Fhq95FSq48uR59ymMVhQjzXqQchP9cXZuxXYydLgXCCYCrZ2b6dxmDSF9ontacBmQWDhn9Buf8TtxUefoUwfpRJ4wuyTftW3pE1nY87i7qmk1QANtjCxjxTdkfkp3zK9T5Nfe5J1MBgesQjGp8kd2AuENnt4iSrojpUMKGtSxn8w8YNw4Acxeb3D2ZeEzoeMQeCta9GqRjJY4SXgzqgGZSurvfEu8u25FwEvjzSVBBkwprs5bGJmxXx3WowSv9DZiCAZSD8sjW6nMs4cizD71GvXCJzo5yqWHQjw7rSqsDJWkFg65cYhF8FA3rq5tqR9a&redirectTo=https%3A%2F%2Fdrive.fission.codes%2F&sdk=0.24.0&sharedRepo=t&appFolder=Fission%2FDrive&privatePath=%2F&publicPath=%2F
icidasset commented 3 years ago

@therealjeffg Yeah it's on prod. You might need to refresh a couple of times to get the update. It downloads the new version in the background, and when it's done and you refresh, only then you'll get the new version.

You should no longer see the "warming up" message, but more detailed indicators of what's happening.

I'll work on a "update/updating lobby" banner soon. More details on that here: https://talk.fission.codes/t/updating-one-of-your-used-webnative-apps/2098


Regarding Drive, you can try this https://talk.fission.codes/t/debugging-webnative-traffic/1440 to debug it further. Specifically the "Want list" part, because it sounds like it's stuck loading something. If that's the case, if you could get me that CID that'd be great 🙏

icidasset commented 3 years ago

Latest auth lobby version should be 1626374949 (you can check this by typing VERSION in the console, or hovering over the 'AUTH' tag until you see a tooltip).

jeffgca commented 3 years ago

I seem to have that version and logging into that account on Edge ( current version ) I still don't get much feedback in the console:

Screen Shot 2021-07-23 at 9 42 47 AM

jeffgca commented 3 years ago

I created a new firefox profile just to make sure I wasn't hitting caching profile problems. Here's the output after agreeing to auth in drive:

Successfully compiled asm.js code (total compilation time 6ms) webnative.js
generating 2048-bit (rsa only) RSA keypair... ipfs.min.js:560:48109
asm.js type error: expecting argument type declaration for 't' of the form 'arg = arg|0' or 'arg = +arg' or 'arg = fround(arg)' webnative.js:50:109518
Opening channel deviceLink#did:key:z13V3Sog2YaUKhdGCmgx9UZuW1o1ShFJYc6DvGYe7NTt689NoL2raRJD6T8ob5wedkNBHC6RoUwSErg1u6Br7RmMfyJMNTT1emjntKZAUuea81Yi7DNuCYt4McQt6Lj9zEWiQJqaYQuFDo1W6FYLdjeRkmJ5y9CgGum3Cvc79Z8aMuHk6tAutbjPN9jPnU4cYrikb4EUuKCgxhJsxdFE8zqF3hY4UM2j9WtrJL3tmeVhMnWshxdWMQYgqDBsnXcBVwXjgWKG1BKCUdjYNDnokX7Wvwa7RDcktszK3iyRWyJ33R6KjsVxAvV5bar5tm2hiGgJRB5osALzgMyaekoqpRYRndhDAFHNhtv4enpa6C9Gnawcq8MC8zj3E3FhCAHTo9knTWpmpQJHtckgxRLCi1N index.js:1:7693
🚀 Started IPFS node worker.min.js:5014:13
🪐 Connected to /dns4/production-ipfs-cluster-us-east-1-node0.runfission.com/tcp/4003/wss/p2p/12D3KooWFSAbpiAeKHnVyqMqrdvAtu8C3veePHi36bZGNM2qv42q worker.min.js:5050:17
🪐 Connected to /dns4/production-ipfs-cluster-us-east-1-node2.runfission.com/tcp/4003/wss/p2p/12D3KooWQ2hL9NschcJ1Suqa1TybJc2ZaacqoQMBT3ziFC7Ye2BZ worker.min.js:5050:17
🪐 Connected to /dns4/production-ipfs-cluster-us-east-1-node1.runfission.com/tcp/4003/wss/p2p/12D3KooWNntMEXRUa2dNgkQsVgzao6zGSYxm1oAs83YtRy6uBuxv worker.min.js:5050:17
🪐 Connected to /dns4/production-ipfs-cluster-eu-north-1-node1.runfission.com/tcp/4003/wss/p2p/12D3KooWRwbRrSN2cPAKz4yt1vxBFdh53CpgWjSFK5hZPkzHHz5h worker.min.js:5050:17
🪐 Connected to /dns4/node.fission.systems/tcp/4003/wss/p2p/QmVLEz2SxoNiFnuyLpbXsH6SvjPTrHNMU88vCQZyhgBzgw worker.min.js:5050:17
🪐 Connected to /dns4/production-ipfs-cluster-eu-north-1-node0.runfission.com/tcp/4003/wss/p2p/12D3KooWDTUTdVJfW7Rwb6kKhceEwevTatPXnavPwkfZp2A6r1Fn worker.min.js:5050:17
VERSION
"1626374949"
icidasset commented 3 years ago

The lobby can't give more feedback at that point, ie. when it's loading the filesystem. It's up to IPFS to bring in the necessary data for the filesystem, which you can debug this way:

You basically have to open the shared worker and go in there to debug.