1080073 - Lost 10% of my passwords since the conversion to logins.json

Status: RESOLVED WORKSFORME

(Toolkit :: Password Manager, defect)

Description

[Matthew N. [:MattN]]

Attachment: Bad username JSON prettified

I had 481 passwords in logins.json after an initial conversion but recently I noticed I was missing many passwords that were previously saved but it wasn't all sites. I created a new profile and re-migrated from signons.sqlite and 50 logins (10%) that weren't in my normal profile were in the new conversion.

I *think* this problem started sometime after the conversion but I also use Sync so I don't know if we are failing to serialize some logins to disk sometimes or if Sync is losing my passwords.

One of the weird things with logins.json is this one login which had 婚 (\u5a5a) repeated 34816 times in the middle of one of the property names and seems to be the result of munging two logins together:

{"id":416,"hostname":"https://bug583578.bugzilla.mozilla.org","httpRealm":null,"formSubmitURL":"https://bug583578.bugzilla.mozilla.org","usernameField":"log","passwordField":"pwd","encryptedUsername":"MEoEEPgAAAAAAAAAAAAAAAAAAAEwFAYIKoZIhvcNAwcECDLHnHDCN+gDBCBj0TL/fxGliYL1ChE6GD5ZC49RJto/hF8rdpFkgyM7Gg==","encryptedPassword":"MDoEEPgAAAAAAAAAAAAAAAAAAAEwFAYIKoZIhvcNAwcECP8XQ8SZ0LO+BBCzVGG+EoySFsStEef6HcSn","guid":"{a5346f59-9e09-c545-b03d-87e1a50d2b04}","encType":1,"ti婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚婚…婚婚婚婚婚婚婚formSubmitURL":"https://wordpress.com","timeCreated":1398114900272,"timeLastUsed":1398791579777,"timePasswordChanged":1398114900272,"timesUsed":2},

Note the duplicated formSubmitURL property.

Yoric, do you know of any OS.File bug which could cause this? The code is in https://mxr.mozilla.org/mozilla-central/source/toolkit/components/passwordmgr/LoginStore.jsm

Comment 1

[David Teller [:Yoric] - still alive but not very active]

Interesting. I do not know of any OS.File bugs that could cause this, but if there is one, I am seriously interested.

Comment 2

[David Teller [:Yoric] - still alive but not very active]

Have you tried reproducing this already, btw?

Comment 3

[Matthew N. [:MattN]]

I haven't tried to reproduce. The only ideas I have would be to crash in the middle of writing or something. I didn't look at the code closely. The initial conversion works fine if I copy the sqlite file to a new profile so it may have happened after that during everyday use but I don't know when it happened or what caused it.

Comment 4

[David Teller [:Yoric] - still alive but not very active]

The write takes place as follows:
- write (in a single libc call) to a temporary file;
- rename the temporary file to its destination.

So, a process crash should not be able to corrupt anything, and a OS crash/power outage only has a very small window of opportunity to corrupt anything.

Now, I notice in the source code of LoginStore.jsm that the, while the file is always written by OS.File, it may be read by the main thread. I don't know if this can have caused your issue, but it seems a little dangerous to me.

Comment 5

[Matthew N. [:MattN]]

OK, so the two issues (婚 [\u5a5a] and the 50 lost passwords) are the same problem. The corrupted login had id=416 and every login after that one was lost so it seems like after the corruption happened, we didn't read the rest of the file.

Comment 6

[David Teller [:Yoric] - still alive but not very active]

Corruption in the middle of the file could be a hardware issue, too, btw.

Comment 7

[Matthew N. [:MattN]]

[Tracking Requested - why for this release]: It seems like there is a problem in 32 which may not be fixed in 33.

Yeah, it's possible.

There are other reports of missing passwords which may or may not be related:

https://input.mozilla.org/en-US/dashboard/response/4647432
https://input.mozilla.org/en-US/dashboard/response/4644848
https://input.mozilla.org/en-US/dashboard/response/4643967
https://input.mozilla.org/en-US/dashboard/response/4643403
https://input.mozilla.org/en-US/dashboard/response/4636302
https://input.mozilla.org/en-US/dashboard/response/4630546
https://input.mozilla.org/en-US/dashboard/response/4628390
https://input.mozilla.org/en-US/dashboard/response/4627209
https://input.mozilla.org/en-US/dashboard/response/4626287
https://input.mozilla.org/en-US/dashboard/response/4623049
https://input.mozilla.org/en-US/dashboard/response/4622636
https://input.mozilla.org/en-US/dashboard/response/4622266
https://input.mozilla.org/en-US/dashboard/response/4622218
https://input.mozilla.org/en-US/dashboard/response/4620455
https://input.mozilla.org/en-US/dashboard/response/4620445
https://input.mozilla.org/en-US/dashboard/response/4617394
https://input.mozilla.org/en-US/dashboard/response/4617281
https://input.mozilla.org/en-US/dashboard/response/4617154
https://input.mozilla.org/en-US/dashboard/response/4616800
https://input.mozilla.org/en-US/dashboard/response/4616325
https://input.mozilla.org/en-US/dashboard/response/4616228
…

Multiple of these mention the browser locking up. Many of them mentioning the passwords being lost upon upgrading to Firefox 32. A lot of these also mention sync.

I missed that this was mentioned by user advocacy upon the release of 32:
"Firefox users losing passwords upon upgrade

Due to the recent changes in how we store passwords in Firefox, there has been a slight increase in complaints around lost passwords. Again, not a significant amount of feedback, but concerning in that users who lose their data also lose all reason to continue using Firefox. Fortunately this issue has an easy workaround, and we haven’t narrowed down a single reproducible case."
from "Firefox 32 Week 1 Report"

Comment 8

[Sylvestre Ledru [:Sylvestre]]

David, do you see something you could do here? I guess it is too late for 33.1 but we could take a patch for 34. Thanks

Comment 9

[David Teller [:Yoric] - still alive but not very active]

I have spent some more time looking at the code, and I can't see any visible bug.

The first possibility is that we have a big problem somewhere in OS.File, TextEncoder, JSON.stringify or mozStorage. Unlikely, but possible.

The second possibility is that this is due to an external factor, such as a hardware issue, the OS or an anti-virus. Also unlikely but possible.

My third scenario, which I believe is more possible, is the following:
- using the old API, a blob of characters was written to the database as a string, but for some reason, this blob of characters is not a valid Unicode string, perhaps due to an encoding issue;
- when we import this blob, for some reason, we do not provide the right encoding, so the decoding results in something that is not a proper Unicode string (JS strings can contain non-proper Unicode strings);
- finally, when we call JSON.stringify, the result is corrupted.

Marco, Paolo, does this seem possible to you?

If this third hypothesis is correct, the bad change is probably around bug 853549.

I made another pass at understanding what's going on, and I have no clue what caused the error, I'm afraid.

The code looks good, so afaict, either we have a big problem somewhere in the implementation of OS.File, TextEncoder or JSON.stringify, or it's an external factor such as hardware issue, an antivirus, etc.

Either way, we are not going to have anything in time for 34, unless we find out what's wrong.

Comment 10

[:Paolo Amadini]

(In reply to David Rajchenbach-Teller [:Yoric] (use "needinfo") from comment #9)
> something that is not a proper Unicode
> string (JS strings can contain non-proper Unicode strings);
> - finally, when we call JSON.stringify, the result is corrupted.

In Matt's case, the corruption crossed the boundary between a property value and another property's name, so it doesn't seem related to the contents of a single string.

> The code looks good, so afaict, either we have a big problem somewhere in
> the implementation of OS.File, TextEncoder or JSON.stringify, or it's an
> external factor such as hardware issue, an antivirus, etc.

Seems more likely to me.

Also, we have no evidence that the increase in reports about lost passwords is in any way related to Matt's issue described in this bug. A variety of edge cases may happen - and some of them, like the same profile being routinely used with multiple versions of Firefox, are known not to work, and supporting them in the product was a non-goal from the start (there are advanced techniques to recover passwords in these cases).

Comment 11

[David Teller [:Yoric] - still alive but not very active]

> In Matt's case, the corruption crossed the boundary between a property value and another property's name, so it doesn't seem related to the contents of a single string.

Why? JSON.stringify certainly doesn't check its input, so if it has non-Unicode JS strings, it will happily produce a non-Unicode JS string. I'm pretty sure that TextEncoder assumes that the string is correct, without further checks, so it will output something that is garbled, but which may well be parseable as JSON – except the resulting JSON will not match the original data.

Comment 12

[Sylvestre Ledru [:Sylvestre]]

> Either way, we are not going to have anything in time for 34, unless we find out what's wrong.
Ok. I am going to untrack them.
Please resubmit for tracking if you have a clue!

Comment 13

[Nicolas B. Pierron [:nbp]]

<nbp> what is 5a5a5a5a
<firebot> iirc, 5a5a5a5a is freed memory

Comment 14

[Emanuel Hoogeveen [:ehoogeveen]]

That's a good point - memory poisoning for small allocations was enabled in bug 860254, so perhaps the corruption is caused by a use-after-free that used to be harmless most of the time (simply because the memory was still mapped by jemalloc and not yet overwritten).

Comment 15

[Nicolas B. Pierron [:nbp]]

Note that 0x5a corresponds to "Z", so the fact that it appears as 婚 (\u5a5a) suggests that the string was already encoded in UTF-16 at the time of the corruption.  I assume, that such JSON file is more likely to be encoded in ASCII when it is being manipulated by the JS engine.

If the corruption happened before the creation of the JSON file, then we should expect that the encoding of the UTF-16 string would be terminated by 0, as the key precisely ends on "fromSubmitURL".   Which sounds unlikely, and thus suggests that the corruption happened after the creation of the JSON file content.

So, in any case, I think that we successfully produced the result of JSON.stringify.  I guess, we should look where the result of JSON.stringify is copied into, and ensure that the buffers in which this text it is copied into cannot be freed before we copy into it.

> had 婚 (\u5a5a) repeated 34816 times

Side note, this implies that the size of the memory allocation is 0x11000 or smaller.

Comment 16

[:Paolo Amadini]

(In reply to David Rajchenbach-Teller [:Yoric] (use "needinfo") from comment #11)
> Why? JSON.stringify certainly doesn't check its input, so if it has
> non-Unicode JS strings, it will happily produce a non-Unicode JS string. I'm
> pretty sure that TextEncoder assumes that the string is correct, without
> further checks, so it will output something that is garbled, but which may
> well be parseable as JSON – except the resulting JSON will not match the
> original data.

Probably we're saying the same thing... what I'm saying is that this doesn't look like an encoding problem (like losing a character because of an unmatched UTF-16 lead surrogate), and also that looking at the start and end points ("ti婚 which would be one of the "time" properties, and 婚formSubmitURL" which is another property) it seems unlikely this happened on the input side of "stringify", so this isn't where I would look first.

What you're saying, as I understand it, is that there could be a serious bug in one of TextEncoder or JSON.stringify, maybe triggered by unmatched pairs, which I also deem possible. Regardless of the exact cause, per comments 13 and 14, this may be an allocation bug, and it could be at any point in the code path, including OS.File.

Comment 17

[[:philipp]]

there is now also an unusual amount of users reporting lost passwords after updating to firefox 33 on the SUMO forum - i've filed bug 1091854 for it.

Comment 18

[Lukas Blakk [:lsblakk] use ?needinfo]

We've had no significant volume of input from users about this issue, untracking.