Closed Bug 1429560 Opened 2 years ago Closed 3 months ago

Unresponsive Script: passwordmgr/content/passwordManager.js

Categories

(Toolkit :: Password Manager, defect, P3)

58 Branch
defect

Tracking

()

RESOLVED WONTFIX

People

(Reporter: git, Unassigned)

References

Details

(Keywords: regression, regressionwindow-wanted, Whiteboard: [fxperf:p3])

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:58.0) Gecko/20100101 Firefox/58.0
Build ID: 20180108140638

Steps to reproduce:

Running 58.0b15 (64-bit) Linux (tar install on Debian 9)

Open Page Info from context menu, select Security, then View Saved Passwords.

Problem persists after restart and after disabling all plugins. I have somewhere just shy of 100 passwords saved.


Actual results:

The Saved Logins window takes up to a minute to open depending on whether that page has any saved passwords, locking the entire session. Clearing the search field to find all result actually results in a "Warning: Unresponsive script" error after an even longer delay, citing:

Script: chrome://passwordmgr/content/passwordManager.js:269 

After dismissing this warning everything seems to have been populated just fine, but the delay repeats every time an entry is deleted, or a new search is done.

I also have to the `kill` Stored Login window (I'm doing this with the i3wm kill keybinding) to get rid of the window as the Close button doesn't work.

I navigated to passwordManager.js in Firefox and it appears the line it is complaining about is the rot function: table.sort(compareFunc);

Nothing jumps out at me as being immediately wrong with that function (with my limited JS knowledge). Furthermore, it appears to be the exact same code as the used in the working version in LMDE2.

function compareFunc(a, b) {
    let valA, valB;
    switch (column) {
      case "hostname":
        let realmA = a.httpRealm;
        let realmB = b.httpRealm;
        realmA = realmA == null ? "" : realmA.toLowerCase();
        realmB = realmB == null ? "" : realmB.toLowerCase();

        valA = a[column].toLowerCase() + realmA;
        valB = b[column].toLowerCase() + realmB;
        break;
      case "username":
      case "password":
        valA = a[column].toLowerCase();
        valB = b[column].toLowerCase();
        break;

      default:
        valA = a[column];
        valB = b[column];
    }

    if (valA < valB)
      return -1;
    if (valA > valB)
      return 1;
    return 0;
  }





Expected results:

The window should open quickly without impacting the performance of the parent window. This works perfectly fine in 57.0.4 as distributed with LMDE2, so it seems to be a recent-ish bug.
Perhaps a noteworthy difference between the problem version and the LMDE version I tested is that the passwords stored are not the same. The LMDE machine is a family members which has fewer (around 30) and the actual passwords are much simpler (complexity on the order of keyword123). The majority of the hundred or so passwords on mine are randomly generated 64 character strings with special characters (similar to something like: _"#r3T[f)*;ZM|e01TsLsr78W2W4O>?hw.Q,EF-V{l#LM<1Zk8ST76m&QZ[d9Le2 ).
User Agent  Mozilla/5.0 (X11; Linux x86_64; rv:58.0) Gecko/20100101 Firefox/58.0
Firefox: 58.0b16, Build ID  20180111124119

I have tested this issue on Ubuntu 14.04 x64 and also on Debian 9.2.1 using a Virtual Machine, but I haven't managed to reproduce it. Tested on latest Firefox Beta 58.0b16 an latest Nightly (59.0a1) build.
I have saved more than 100 passwords, half of them with special characters like those described in comment 2, but I never get the "Unresponsive Script" error.
Here is screen recording: https://goo.gl/jrZ8Bg

Can you please try to test this issue on Safe Mode (https://goo.gl/AR5o9d) and report back the results?
Flags: needinfo?(git)
Cosmin,

Thank you very much for looking into this.

> Can you please try to test this issue on Safe Mode (https://goo.gl/AR5o9d)
> and report back the results?

My apologies, this is what I meant by "Problem persists after [...] disabling all plugins". 

I have a habit of using 'plugin' and 'add-on' interchangably. This is erroneous I'm sure.

I end up clearing a bunch of passwords last week and testing again, the delay is still very long and it still times out when not in Safe Mode, but when in Safe Mode it continues to be unresponsive until it gets the results rather than actually timing out.

See the screenshots with explanations here:

    https://john.me.tz/bugzilla/1429560.html

I have `top` open mostly just for time tracking. Firefox is generally the number one consumer or cpu and ram during the process, but this is normal during regular usage as well.

I notice that the entries show up in a different order, presumably because the part of the script that was stopped was the "sort" function, as indicated; the safe mode version has all of the IPs sorted first alphabetically, the non-safe mode has them seemingly randomly.

I really don't use a lot of add-ons (see last screenshot).

I will attempt to replicate this from my home computer tonight to see if it is something particular to my workstation. The home computer is basically the exact same setup with the same version of Firefox and the same password database.

If this cannot be replicated then it's a minor annoyance that I'm willing to ignore.
Flags: needinfo?(git)
Update: The problem does NOT exist on my home computer. They share the exact same OS and browser versions, same password database and same add-ons.

I also installed the stable version of firefox on my workstation and the problem doesn't exist there either. Given the inability to reproduce outside of the specific installation this can probably be rejected. I will leave that to the triage team as this is my first bug report and I don't want to go against preferred procedure.

If anyone wants to pursue this further I'm happy to do more debugging.
Thanks for retesting this!
Probably the issue was caused by some configurations or some prefs changed. If you still have the version of Firefox where the issue is reproducible you can compare the "Important Modified Preferences" section from "about:support" page with the one of the stable version.

There is also a chance that the previously build of Firefox had some issues. From where did you downloaded the Firefox 58.0b15 build?
Flags: needinfo?(git)
Hi Folks, 

I got the same issue here. It has to be a problem in the effected users userprofile. After I created a new profile for this user everything was fine except of an empty password database.

Maybe there was a change of the storage/encrytion of the database. As far as I know the passwords are stored in the logins.json file in combination with the key3.db file. The newly created profile now has a key4.db file (ist this a hint?). 

Is there a chance to export and import the passwords from one profile to the other (without firefox sync)?

Name 	Firefox
Version 	58.0
Build-ID 	20180118215408

Update-Kanal 	release
User-Agent 	Mozilla/5.0 (X11; Linux x86_64; rv:58.0) Gecko/20100101 Firefox/58.0
Betriebssystem 	Linux 4.9.0-5-amd64 Debian 9

Have a nice weekend
It seems that the issue is reproducible on certain profiles but it's not reproducible on new ones. I haven't managed to reproduce this issue on my created profiles on Debian 9.2.1 or Ubuntu 14.04 x64.

Unfortunately I don't have the necessary knowledge to answer Stefan's questions. Considering this I am assigning a component to this issue in order to involve the development team and get an opinion on this.
Component: Untriaged → Password Manager
Product: Firefox → Toolkit
Folks: Today I found it on my one Firefox instance in 59.0.2. “Saved Login", when clicked, freezes for a while until a pop-up window reporting unresponsive script is seen. 
I downgraded it to different versions and found the issue is first seen on 58.0. It's not in 57.
Pls fix it! Thank!
See Also: → 1468301
(In reply to Matthew N. [:MattN] (PM me if requests are blocking you) from bug 1490584 comment #7)
> (In reply to Mike Conley (:mconley) (:⚙️) from bug 1490584 comment #6)
> > The profile from comment 4 shows we're talking to an SQLite database on the
> > main thread:
> > 
> > https://perfht.ml/2RtEHXE
> 
> There is no SQLite in password manager but yes, we read JSON once
> asynchronously and then keep it in memory for the session, unless we need
> synchronous access before it's done initializing.

Yes, but there's a master password set, and isn't that stuff stored in a sqlite file? Is it possible we're reading that repeatedly to decrypt the logins one-by-one, or something, and maybe that's slow?

> This bug is already duped to bug 1429560 btw.

Continuing this conversation here, then. :-)
Flags: needinfo?(MattN+bmo)
Whiteboard: [fxperf]
Status: UNCONFIRMED → NEW
Ever confirmed: true
(In reply to :Gijs (he/him) from comment #11)
> Yes, but there's a master password set, and isn't that stuff stored in a
> sqlite file? Is it possible we're reading that repeatedly to decrypt the
> logins one-by-one, or something, and maybe that's slow?

I should mention that the profile in question is on NFS.
(In reply to Linus Kardell from comment #12)
 
> I should mention that the profile in question is on NFS.

This may be a total coincidence, but I believe mine would have also been NFS at the time. Shortly after that I reinstalled and mounted my home locally and I have never had the problem since.
Flags: needinfo?(git)
(In reply to John Mertz from comment #13)
> (In reply to Linus Kardell from comment #12)
>  
> > I should mention that the profile in question is on NFS.
> 
> This may be a total coincidence, but I believe mine would have also been NFS
> at the time. Shortly after that I reinstalled and mounted my home locally
> and I have never had the problem since.

This would make sense - the performance info (confusingly also called "profile") linked in comment #11 shows a lot of time being taken by main-thread IO. So the main (UI) thread is busy trying to access this file, which may be slow over NFS (or perhaps the code accessing it is doing something specific that is slow on NFS?).

One thing that'd be interesting, given this was reported as being a regression for 58, would be to find a narrow regression window of exactly when this became so slow (on the nightly channel, between 57 and 58). It's likely to be a little bit tricky because the automated tool we'd normally use for this ( https://mozilla.github.io/mozregression/ ) normally creates clones of any user profile you tell it to use, in the system's tmp dir (which to me at least seems like it won't normally be on NFS, and indeed, if you put it on NFS, I would not be surprised if you found other perf issues). The other thing that might be tricky is that we changed some of the NSS/encryption stuff in a later (60+) release. Something like this should work, in theory:

1. download a copy of Firefox 57, start it with the profile manager (-P commandline switch)
2. create a new testing profile.
3. run that testing profile, create a master password, store maybe 5 or 10 passwords
4. download a copy of 58, verify that if you run it with that profile (-P commandline switch, pass the name you gave the profile to that and it'll open immediately with that profile) the password manager is slow to open
5. run: mozregression --good 57 --bad 58 --profile-persistence reuse --profile /path/to/test-profile-on-nfs

This should spit out a regression window (if you're not sure what to look for, complete terminal output is fine).

Linus, would you be in a position to help find a regression window? Alternatively, Cosmin, do QA have (or can they set up) Linux systems set up with NFS that you could use to find a regression window?
Flags: needinfo?(linus.kardell+mozillabugs)
Flags: needinfo?(cosmin.muntean)
(In reply to :Gijs (he/him) from comment #14)
> 5. run: mozregression --good 57 --bad 58 --profile-persistence reuse
> --profile /path/to/test-profile-on-nfs
> 
> This should spit out a regression window (if you're not sure what to look
> for, complete terminal output is fine).

Eh, sorry, a bit abridged there: this will basically run a bisection by downloading builds, running them with the profile in question, and then allowing you to specify if the build was "broken" or not). At the end, it should come up with a small window of when things went busted.
(In reply to :Gijs (he/him) from comment #11)
> (In reply to Matthew N. [:MattN] (PM me if requests are blocking you) from
> bug 1490584 comment #7)
> > (In reply to Mike Conley (:mconley) (:⚙️) from bug 1490584 comment #6)
> > > The profile from comment 4 shows we're talking to an SQLite database on the
> > > main thread:
> > > 
> > > https://perfht.ml/2RtEHXE
> > 
> > There is no SQLite in password manager but yes, we read JSON once
> > asynchronously and then keep it in memory for the session, unless we need
> > synchronous access before it's done initializing.
> 
> Yes, but there's a master password set, and isn't that stuff stored in a
> sqlite file? Is it possible we're reading that repeatedly to decrypt the
> logins one-by-one, or something, and maybe that's slow?

Yeah, I thought the profile link was supposedly to be showing SQLite usage but I didn't see any in the visible stacks. I notice now that there was a "sqlite" filter applied so it was referring to the NSS sqlite usage (which is outside of password manager).

If the issue is only over NFS then this seems related to bug 1444943. Reporters could try manually setting the environment variable `NSS_SDB_USE_CACHE=yes` and launching Firefox in that environment to see if it fixes the issue.
Flags: needinfo?(MattN+bmo)
@Gijs we have multiple Linux systems but none of them is set with NFS. I have talked with the IT guys and they can set a system with NFS but unfortunately, it will take a few days.

If Linus cannot test this, I will try to reproduce the issue and find the regression window in the next days.
I now tested with NSS_SDB_USE_CACHE=yes, and it cuts the time to open the password manager to some 5 seconds, which is still bad, but it's a significant improvement. It's hard to get an opportunity to bisect it though, because this is on my work computer.
Whiteboard: [fxperf] → [fxperf:p3]
We managed to set up a NFS configuration on a machine and we started testing. Unfortunately we haven't managed to reproduce the issue. We tested the scenario described in comment 14, on Firefox 57, 58, 60 and also latest Firefox 63.0.0 release, but the password manager is displayed almost instantly and we haven't observe any slowness.

The NFS server is set up on a machine with Debian 9 and the client part is set up on another machine with Ubuntu 18.04. We ran the Firefox browser versions with a profile that was created on the shared directory but we haven't managed to reproduce the issue. 

Please let me know if you need more information.
Flags: needinfo?(cosmin.muntean)

Linus, we've been unable to reproduce this here, so if you are able to get the regression info requested in comment #14 it would still be a great help.

The time to open the password manager has gotten significantly better after we upgraded the NFS server. It no longer throws unresponsive scripts, though it still takes a few seconds to open.

I have a couple hundred passwords in the affected profile, so I can't really match that manually. I tried copying the password files from the profile, but that doesn't work for Firefox 57.

Bugbug thinks this bug is a regression, but please revert this change in case of error.

Keywords: regression

(In reply to Linus Kardell from comment #22)

I have a couple hundred passwords in the affected profile, so I can't really match that manually. I tried copying the password files from the profile, but that doesn't work for Firefox 57.

If you copy logins.json + key4.db it should work. The unresponsive script warning should go away and decryption should be somewhat faster (we do it as a batch now) with the new about:logins page which is only in Firefox Nightly. Feel free to test in a duplicate profile with Nightly (since you cannot downgrade to 57 after) and confirm that it's better. If you still see the unresponsive script bar/dialog then please re-open.

Status: NEW → RESOLVED
Closed: 3 months ago
Flags: needinfo?(linus.kardell+mozillabugs)
Resolution: --- → WONTFIX
You need to log in before you can comment on or make changes to this bug.