search

keybase / keybase-issues

A single repo for managing publicly recognized issues with the keybase client, installer, and website.
900 stars 37 forks source link

problem logging in - chrome just hanging #30

Closed malgorithms closed 10 years ago

malgorithms commented 10 years ago

A user (hughes) reports the following experience when trying to login or signup via the website. It worked fine via the command line (that's how he joined).

https://mediacru.sh/_GXy956gxnZj

On the network side of things, it's hanging after getting the salt; no network calls to login attempted.

hughes commented 10 years ago

Machine specs: macbook pro from early 2011. 2.7Ghz i7, 4GB ram. Chrome is 33.0.1750.117

The request to getsalt.json succeeds.

hughes commented 10 years ago

Firefox on the same machine logs in without a problem!

malgorithms commented 10 years ago

Thanks @hughes

A few questions:

Last, can you try it again with https://keybase.io/?no_minify=1 -- and pause it in your debugger a couple more times and see if it's always in the same spot? That version doesn't minify our JS.

fedepo commented 10 years ago

I've had the same issue and had to create my account on Firefox. Even with the account created, login on Chrome still doesn't work. Tried with incognito window, same. The only way I could login on Chrome=following the email activation/verification url received after registration.

gwillen commented 10 years ago

I had the same problem when trying to sign up in Chrome 33.0.1750.117 on OS X 10.9.1. (When pressing the 'join' button after supplying my desired username/password, it hung for an extended length of time, but eventually finished while I was off in an IRC window complaining about it.)

If it repros when I log out and in, I will gather more data for you.

gwillen commented 10 years ago

Am I crazy to make the assumption that it's just hanging while scrypting the passphrase client-side?

When logging in, it actually says 'scrypting' while it hangs. (Before it just said 'joining'.) It could probably do with being clearer -- it's totally reasonable for it to take awhile, since it's doing client-side crypto, but it's not obvious that's what it's doing, and it hangs the browser tab because chrome can't cope with JS using the CPU that intensively. (I.e. right-click and all page interactions stop working.)

gwillen commented 10 years ago

Both times I've tried it's stopped on line 6241 of sitewide-js.js, to wit:

  Deferrals.prototype._fulfill = function(id, trace) {

Unfortunately it seems like I don't get a good stack trace, probably because of continuation-passing event-magic, so I can't immediately figure out how to get a lot more out of it.

Also, I have to close and reopen the browser window once I do that -- the debugger really struggles and can't seem to manage to pause it a second time.

gwillen commented 10 years ago

I've been fiddling with chrome profiling tools. (You can access the JS profiler in the 'profiles' tab of dev tools, and the chrome internal/native profiler -- which I don't have a great understanding of -- in chrome://profiler .)

The JS profiler reports essentially 100% of time in '(program)', which is unhelpful, but I'm told it includes native code execution. The other profiler .... gives pretty much identical output whether or not I'm trying to log in.

gwillen commented 10 years ago

Ok, proper stack trace (then I will stop spamming the bug):

Object {parent: function, filename: "/home/max/src/triplesec/src/util.iced", lineno: 39} Object {parent: function, filename: "/home/max/src/triplesec/src/scrypt.iced", funcname: "Scrypt.smix", lineno: 170} Object {parent: function, filename: "/home/max/src/triplesec/src/scrypt.iced", funcname: "Scrypt.run", lineno: 225} Object {parent: function, filename: "/home/max/src/triplesec/src/enc.iced", funcname: "Base.kdf", lineno: 121} Object {parent: null, filename: "/home/max/src/triplesec/src/enc.iced", funcname: "Encryptor.resalt", lineno: 375} "/home/max/src/triplesec/src/enc.iced" 375 "Encryptor.resalt"

malgorithms commented 10 years ago

hey this is very helpful, thanks.

@gwillen - in all your cases:

your expectation that it's scrypt-related is probably right. There's an immense amount of client-side work being done in order to generate your password hash. (On purpose.) We felt we picked appropriate values for this. For example, a login or join on my iPhone typically takes < 5 seconds. What's alarming is that it's taking so long on a desktop running windows.

scrypt by design is memory constrained. Maybe you're out of RAM and paging. What do you think?

gwillen commented 10 years ago

@malgorithms In all the cases where I waited: 1) the kill dialog never appeared; 2) it eventually finished each time, I didn't time it but I can try; 3) that's an EXCELLENT question, I'll check; 4) let me try disabling them all and see what happens.

I'm quite sure I'm not paging; I have 16 gigs of RAM, and like 4 of that is free. But it's possible that Chrome is limiting the amount of memory available to an app running the JS sandbox, and this is causing a similar issue?

This is Chrome on OSX, FYI, not windows. (Have the devs tried that configuration? I.e. is it just some machines that respond this way, or is it ALL Chrome OS X users?)

(I handwave/speculate that the kill dialog only appears if you're spinning in JS code, whereas you are repeatedly calling into native code to perform crypto, and yielding to the browser in doing so.)

gwillen commented 10 years ago

Disabling all extensions and not opening dev tools on that tab, no difference. According to chrome task manager, it's using about 200 MB of RAM and about 10% of one (out of my 4) CPU. This time it IS repeatedly asking me if I want to kill it; not sure if that's suppressed with Dev Tools open, or because it's not the foreground page, or what.

Could you guys release a standalone scrypt benchmark webpage that just reports (to the user, and also to you) the browser version, whatever other configuration data you think would be useful to gather, and the scrypt rate?

gwillen commented 10 years ago

We're at 8 minutes and counting, incidentally. I am quite sure it's succeeded before; I know I've logged in successfully, multiple times. Not sure if each of those was a case of leaving it alone forever and eventually coming back to success, or if it's finishing much faster some times than other times.

I've never had it finish before I went away and came back, though.

EDIT: 17 minutes... I feel like there must be another factor here, I'm sure I've seen it faster than this (and I don't think it was periodically asking me to kill the tab, which it is now.)

EDIT EDIT: Ohhhh, the times are bogus because as soon as I put the tab in the background, it's restricting it to essentially zero CPU.

EDIT EDIT EDIT: Oh, I think it finally succeeded after just over 20 minutes:

"Unknown error: BAD_SESSION / for uid 5a84458b1e39e5cb961186153888bc00: Expired 1095s ago"

Of course, as mentioned above, the time is bogus because every time I put the window in the background, Chrome was taking away all its CPU time.

maxtaco commented 10 years ago

Great suggestion about the scrypt standalone. We were discussing that this morning.

On Thu, Feb 27, 2014 at 8:26 PM, gwillen notifications@github.com wrote:

We're at 8 minutes and counting, incidentally. I am quite sure it's succeeded before; I know I've logged in successfully, multiple times. Not sure if each of those was a case of leaving it alone forever and eventually coming back to success, or if it's finishing much faster some times than other times.

I've never had it finish before I went away and came back, though.

Reply to this email directly or view it on GitHubhttps://github.com/keybase/keybase-issues/issues/30#issuecomment-36312994 .

malgorithms commented 10 years ago

hey @gwillen -- we're likely to get a standalone test page up soon. But it just occurred to me that in the meantime, you could generate a warp wallet on our site to test scrypt, and tell me how long it takes. Just enter a BS passphrase:

https://keybase.io/warp

That's designed to take a while. It takes 14 seconds in Chrome on my computer. (you'll have to note the clock yoursef.)

Btw, have you been putting it in the background every time?

We're also running Chrome / OSX as our default browsers. For some reason it's fast for me, even on old shitty macbook airs. This issue is so confusing.

malgorithms commented 10 years ago

hey @gwillen @hughes @fedepo - I added some good logging, and I'm wondering if you can do a login test on the site and report your results back here.

To do the test:

  1. visit the site
  2. open developer console.
  3. enter do_dlog = true
  4. perform a login
  5. paste the results back into here.
  6. oh right, also get me your window.navigator.userAgent by typing that in the console. (I should've logged that.)

UPDATE: moved to gist:

https://gist.github.com/malgorithms/9277821

Thanks!

hughes commented 10 years ago

Done! https://gist.github.com/hughes/9276118

malgorithms commented 10 years ago

@hughes wow, that is very helpful and it's clearly scrypt. I cannot fathom how it could possibly be doubling in time with linear steps in scrypt work.

While I think about this, can you do two things:

  1. try the same thing with all extensions turned off (just to make sure) and the console window closed, and confirm it still fails for you.
  2. try that warp wallet page (https://keybase.io/warp) and confirm you're unable to generate a warp wallet.

Looking forward to @fedepo and @gwillen console logs, too.

This is such a mystery.

hughes commented 10 years ago
  1. With all extensions disabled and the console window closed, I am unable to log in to keybase.
  2. Strangely, I am able to generate a warp wallet without problems.
malgorithms commented 10 years ago

What's so shocking here is that WarpWallet does 8 times as much scrypt work as a Keybase login. Hmm!

Ok, one more scrypt test. What if you try to do a demo encryption/decryption on triplesec: https://keybase.io/triplesec ? Just paste random junk in the encrypt and passphrase field. Thanks @hughes

hughes commented 10 years ago

Encrypt and decrypt both work (takes 2-3 seconds) on triplesec.

hughes commented 10 years ago

This is not a problem with Scrypt. It's a problem with CSS and rendering.

I am able to log in when I first execute the following to disable css:

for (i=0; i<document.styleSheets.length; i++) {
  document.styleSheets[i].disabled = true;
}

edit: definitely something in sitewide-css.css

fedepo commented 10 years ago

my output: my output: do_dlog = true; true 0 1393615923891 "running pw_to_login" sitewide-js.js:39 0 1393615923892 "about to pw_to_pwh" sitewide-js.js:42 1 1393615923893 "about to getsalt" sitewide-js.js:42 759 1393615924652 "done getting salt" sitewide-js.js:42 1 1393615924653 "about to scrypt_hash_passphrase" sitewide-js.js:42 24 1393615924677 Object {what: "pbkdf2 (pass 1)", total: 32, i: 0} sitewide-js.js:42 0 1393615924679 Object {what: "pbkdf2 (pass 1)", total: 32, i: 0} sitewide-js.js:42 2 1393615924681 Object {what: "pbkdf2 (pass 1)", total: 32, i: 1} sitewide-js.js:42 0 1393615924681 Object {what: "pbkdf2 (pass 1)", total: 32, i: 1} sitewide-js.js:42 1 1393615924683 Object {what: "pbkdf2 (pass 1)", total: 32, i: 2} sitewide-js.js:42 1 1393615924684 Object {what: "pbkdf2 (pass 1)", total: 32, i: 2} sitewide-js.js:42 0 1393615924684 Object {what: "pbkdf2 (pass 1)", total: 32, i: 3} sitewide-js.js:42 0 1393615924685 Object {what: "pbkdf2 (pass 1)", total: 32, i: 3} sitewide-js.js:42 1 1393615924687 Object {what: "pbkdf2 (pass 1)", total: 32, i: 4} sitewide-js.js:42 0 1393615924688 Object {what: "pbkdf2 (pass 1)", total: 32, i: 4} sitewide-js.js:42 0 1393615924688 Object {what: "pbkdf2 (pass 1)", total: 32, i: 5} sitewide-js.js:42 0 1393615924689 Object {what: "pbkdf2 (pass 1)", total: 32, i: 5} sitewide-js.js:42 0 1393615924690 Object {what: "pbkdf2 (pass 1)", total: 32, i: 6} sitewide-js.js:42 0 1393615924691 Object {what: "pbkdf2 (pass 1)", total: 32, i: 6} sitewide-js.js:42 0 1393615924692 Object {what: "pbkdf2 (pass 1)", total: 32, i: 7} sitewide-js.js:42 0 1393615924693 Object {what: "pbkdf2 (pass 1)", total: 32, i: 7} sitewide-js.js:42 0 1393615924695 Object {what: "pbkdf2 (pass 1)", total: 32, i: 8} sitewide-js.js:42 0 1393615924696 Object {what: "pbkdf2 (pass 1)", total: 32, i: 8} sitewide-js.js:42 0 1393615924698 Object {what: "pbkdf2 (pass 1)", total: 32, i: 9} sitewide-js.js:42 0 1393615924699 Object {what: "pbkdf2 (pass 1)", total: 32, i: 9} sitewide-js.js:42 0 1393615924700 Object {what: "pbkdf2 (pass 1)", total: 32, i: 10} sitewide-js.js:42 0 1393615924702 Object {what: "pbkdf2 (pass 1)", total: 32, i: 10} sitewide-js.js:42 0 1393615924703 Object {what: "pbkdf2 (pass 1)", total: 32, i: 11} sitewide-js.js:42 1 1393615924705 Object {what: "pbkdf2 (pass 1)", total: 32, i: 11} sitewide-js.js:42 0 1393615924706 Object {what: "pbkdf2 (pass 1)", total: 32, i: 12} sitewide-js.js:42 0 1393615924708 Object {what: "pbkdf2 (pass 1)", total: 32, i: 12} sitewide-js.js:42 0 1393615924709 Object {what: "pbkdf2 (pass 1)", total: 32, i: 13} sitewide-js.js:42 0 1393615924712 Object {what: "pbkdf2 (pass 1)", total: 32, i: 13} sitewide-js.js:42 0 1393615924713 Object {what: "pbkdf2 (pass 1)", total: 32, i: 14} sitewide-js.js:42 0 1393615924715 Object {what: "pbkdf2 (pass 1)", total: 32, i: 14} sitewide-js.js:42 0 1393615924716 Object {what: "pbkdf2 (pass 1)", total: 32, i: 15} sitewide-js.js:42 0 1393615924717 Object {what: "pbkdf2 (pass 1)", total: 32, i: 15} sitewide-js.js:42 0 1393615924719 Object {what: "pbkdf2 (pass 1)", total: 32, i: 16} sitewide-js.js:42 0 1393615924720 Object {what: "pbkdf2 (pass 1)", total: 32, i: 16} sitewide-js.js:42 0 1393615924721 Object {what: "pbkdf2 (pass 1)", total: 32, i: 17} sitewide-js.js:42 0 1393615924722 Object {what: "pbkdf2 (pass 1)", total: 32, i: 17} sitewide-js.js:42 0 1393615924724 Object {what: "pbkdf2 (pass 1)", total: 32, i: 18} sitewide-js.js:42 0 1393615924725 Object {what: "pbkdf2 (pass 1)", total: 32, i: 18} sitewide-js.js:42 0 1393615924727 Object {what: "pbkdf2 (pass 1)", total: 32, i: 19} sitewide-js.js:42 0 1393615924729 Object {what: "pbkdf2 (pass 1)", total: 32, i: 19} sitewide-js.js:42 0 1393615924730 Object {what: "pbkdf2 (pass 1)", total: 32, i: 20} sitewide-js.js:42 0 1393615924731 Object {what: "pbkdf2 (pass 1)", total: 32, i: 20} sitewide-js.js:42 0 1393615924732 Object {what: "pbkdf2 (pass 1)", total: 32, i: 21} sitewide-js.js:42 0 1393615924734 Object {what: "pbkdf2 (pass 1)", total: 32, i: 21} sitewide-js.js:42 0 1393615924737 Object {what: "pbkdf2 (pass 1)", total: 32, i: 22} sitewide-js.js:42 0 1393615924739 Object {what: "pbkdf2 (pass 1)", total: 32, i: 22} sitewide-js.js:42 0 1393615924741 Object {what: "pbkdf2 (pass 1)", total: 32, i: 23} sitewide-js.js:42 0 1393615924744 Object {what: "pbkdf2 (pass 1)", total: 32, i: 23} sitewide-js.js:42 0 1393615924745 Object {what: "pbkdf2 (pass 1)", total: 32, i: 24} sitewide-js.js:42 0 1393615924746 Object {what: "pbkdf2 (pass 1)", total: 32, i: 24} sitewide-js.js:42 0 1393615924748 Object {what: "pbkdf2 (pass 1)", total: 32, i: 25} sitewide-js.js:42 0 1393615924749 Object {what: "pbkdf2 (pass 1)", total: 32, i: 25} sitewide-js.js:42 0 1393615924750 Object {what: "pbkdf2 (pass 1)", total: 32, i: 26} sitewide-js.js:42 0 1393615924751 Object {what: "pbkdf2 (pass 1)", total: 32, i: 26} sitewide-js.js:42 0 1393615924753 Object {what: "pbkdf2 (pass 1)", total: 32, i: 27} sitewide-js.js:42 0 1393615924754 Object {what: "pbkdf2 (pass 1)", total: 32, i: 27} sitewide-js.js:42 0 1393615924755 Object {what: "pbkdf2 (pass 1)", total: 32, i: 28} sitewide-js.js:42 0 1393615924757 Object {what: "pbkdf2 (pass 1)", total: 32, i: 28} sitewide-js.js:42 0 1393615924758 Object {what: "pbkdf2 (pass 1)", total: 32, i: 29} sitewide-js.js:42 0 1393615924759 Object {what: "pbkdf2 (pass 1)", total: 32, i: 29} sitewide-js.js:42 0 1393615924761 Object {what: "pbkdf2 (pass 1)", total: 32, i: 30} sitewide-js.js:42 0 1393615924762 Object {what: "pbkdf2 (pass 1)", total: 32, i: 30} sitewide-js.js:42 0 1393615924763 Object {what: "pbkdf2 (pass 1)", total: 32, i: 31} sitewide-js.js:42 0 1393615924764 Object {what: "pbkdf2 (pass 1)", total: 32, i: 31} sitewide-js.js:42 0 1393615924766 Object {what: "pbkdf2 (pass 1)", total: 32, i: 32} sitewide-js.js:42 0 1393615924767 Object {what: "pbkdf2 (pass 1)", total: 32, i: 32} sitewide-js.js:42 37 1393615924805 Object {i: 2048, what: "scrypt", total: 65536} sitewide-js.js:42 612 1393615925419 Object {i: 4096, what: "scrypt", total: 65536} sitewide-js.js:42 1602 1393615927022 Object {i: 6144, what: "scrypt", total: 65536} sitewide-js.js:42 2930 1393615929952 Object {i: 8192, what: "scrypt", total: 65536} sitewide-js.js:42 5197 1393615935150 Object {i: 10240, what: "scrypt", total: 65536} sitewide-js.js:42 12949 1393615948100 Object {i: 12288, what: "scrypt", total: 65536} 23634 1393615971735 Object {i: 14336, what: "scrypt", total: 65536}

fedepo commented 10 years ago

agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_9_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/33.0.1750.117 Safari/537.36

malgorithms commented 10 years ago

hey guys, this is all awesome info. it's nice to see you're having exactly the same prob.

I just disabled the only CSS thing that really does anything during the scrypt process (the little spinning gear on the disabled button, which is managed by a FontAwesome class). Maybe this is the problem.

Any chance this fixes it?

If not, I'm going to start doing some kind of crazy binary search across our CSS. Bleah. I wish I could reproduce this on my end. I appreciate the help.

fedepo commented 10 years ago

it works!!!

fedepo commented 10 years ago

it was the damn spinning wheel of death!

hughes commented 10 years ago

It works for me now too.

malgorithms commented 10 years ago

Fuuuuuuuuuuuuuuuck! Yeeeehah!

Closing. I'll come up with something else to indicate work being done that doesn't require the spinning death wheel.

You're all great - thanks for the debugging / help.

hughes commented 10 years ago

@fedepo does this page lock up when you scroll to the fa-spin example? I think we might have found a bug in chrome.

fedepo commented 10 years ago

yes! when I scroll down and find the first tiny wheel, it slows down like hell... when I scroll further to the three bigger wheels, it's suddendly looks like I'm running windows98. had to close the tab. tried a couple of times, same behavior.

malgorithms commented 10 years ago

@hughes @fedepo -- one last thing. I made a really classy spinner of my own. Maybe try logging in on the latest version of the site and tell me if it still works. Thanks!

hughes commented 10 years ago

@malgorithms works for me :+1:

@fedepo can you check this minimal example for freezing up? http://jsfiddle.net/Nqtz2/1/

gwillen commented 10 years ago

@hughes That example does hang (or massively slow) the tab in Chrome for me, FWIW.

gwillen commented 10 years ago

@malgorithms Works great, thanks so much. :D

malgorithms commented 10 years ago

great, everyone. I just realized there's another place where I'm using font awesome spinners: the key generation step. I'll be cleaning that up next.

fedepo commented 10 years ago

yep, in fact first time I had problem was generating the key, due to the damn spin.

your new fancy spin with plus works just fine :)

2014-02-28 12:53 GMT-08:00 Chris Coyne notifications@github.com:

great, everyone. I just realized there's another place where I'm using font awesome spinners: the key generation step. I'll be cleaning that up next.

Reply to this email directly or view it on GitHubhttps://github.com/keybase/keybase-issues/issues/30#issuecomment-36393270 .