[SERVER-12208] Got "exception: btree: key+recloc already in index code:10287". Related document vanished Created: 26/Dec/13  Updated: 23/Feb/15  Resolved: 18/Mar/14

Status: Closed
Project: Core Server
Component/s: Index Maintenance
Affects Version/s: 2.4.4
Fix Version/s: None

Type: Bug Priority: Critical - P2
Reporter: Fernando Dobladez Assignee: Unassigned
Resolution: Cannot Reproduce Votes: 0
Labels: index, update
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Ubuntu 12.04 - On Digital Ocean - Single MongoDB node - Very low load, very small DB,


Operating System: Linux
Steps To Reproduce:

N/A

Participants:

 Description   

We got the following on mongodb.log:

Thu Dec 26 14:48:51.331 [conn265] update reef.companies query: { _id: ObjectId('521f7f99e4b00b44b9987a59') } update: { $push: { capitals: { legal: { proceeding: { re
fid: null, state: "none" } }, id: "ecb646fa-9cb8-4a53-bdf0-1b4821ca4f4e", shareholders: [ { entity: { company: { refid: "52bc3f7fe4b07f4f0a49fc4a", name: "EOG Canada
 Holdings ULC (CANCELADA)" } }, amount_mo: 2125000000 }, { entity: { company: { refid: "52bc2d36e4b07f4f0a49fc29", name: "EOG Canada Investments ULC" } }, amount_mo:
 6375000000 } ], total_mo: 8500000000, since_dd: new Date(1323226800000), inc_mo: 8500000000, is_statute_change: true, is_art299: true } } } idhack:1 keyUpdates:0 ex
ception: btree: key+recloc already in index code:10287 locks(micros) w:1905 1ms

Then, right after that operation, the referenced document disappeared from the DB. Running db.companies.find({"_id" : ObjectId("521f7f99e4b00b44b9987a59")}); returns no results.

We tried db.runCommand({validate:"companies"}); and everything looks OK.

We also run a reIndex() on the collection. No errors. The document still gone.

We know the doc was lost due to the above error because that's exactly when it disappeared. And our application codebase does not include a single "remove/delete" operation (we only do "soft" deletes).

Additional info:

  • HINT: We DO have textSearchEnabled=true
  • It's running on a VM (on Digital Ocean)
  • It's a single node installation
  • Very very low load (a single user entering data via a UI)
  • Only 15 documents on that collection
  • The one being updated with $push (which was lost) was 3521 bytes
  • Config file:

    $ cat /etc/mongodb.conf 
    logappend=true
    master=true
    setParameter=textSearchEnabled=true
    rest=true
    logpath=/var/log/mongodb/mongodb.log
    dbpath=/var/lib/mongodb

Right now we restored the lost document from our last backup. However, we are very concerned about losing data in the future. Specially since this is our first project using MongoDB and with very little volume and load we've already lost data.

Thanks



 Comments   
Comment by Maniappan R [ 23/Feb/15 ]

We hit this problem on a 32bit 2.4 version instance and on removing the indices we were able to add the document. All the four indices were integer and not a single one was text index. We also observed page fault exception before this error(randomly), but not sure if that could have contributed to this bug happening.

Comment by Stennie Steneker (Inactive) [ 18/Mar/14 ]

Hi Fernando,

Given that we have thus far been unable to reproduce this issue, I'm going to close it out.

If you do see any further recurrences, please feel free to reopen with additional details.

Thanks,
Stephen

Comment by random user [ 14/Jan/14 ]

FYI: we had the very same issue, db.collection.reIndex() resolved it.
we have textSearchEnabled disabled.

Comment by Gianfranco Palumbo [ 30/Dec/13 ]

There are 4 occurrences of the function that asserts that message in this file:
https://github.com/mongodb/mongo/blob/v2.4/src/mongo/db/btree.cpp

I'll leave this unassigned so the server engineers will be able to better and more quickly look at this

Comment by Fernando Dobladez [ 30/Dec/13 ]

Nope. Unfortunately, I was unable to reproduce it either .

I see two issues here:

1. The fact that we got the "key+recloc already in index", which I guess should never happen, and:
2. The fact that after 1., the document being updated "disappeared"

IMHO, issue #2 is the biggest problem.... may be you should concentrate on the code path that goes through your "key+recloc already in index"` error handling... for some weird reason the associated document was totally lost.

I will definitely add more details here if it ever happens again.

Thanks

Comment by Gianfranco Palumbo [ 30/Dec/13 ]

Hi Fernando,

I downloaded the datafiles and tried to run the update operation but I couldn't reproduce this.

Do you have more information or have you seen this happening again?

Thanks,
Gianfranco

Comment by Daniel Pasette (Inactive) [ 28/Dec/13 ]

Those steps for disabling FTS are correct. However, you should be able to disable the FTS without shutting down mongod by setting textSearchEnabled:false at runtime:

db.adminCommand({setParameter:1, textSearchEnabled:false})

Comment by Fernando Dobladez [ 27/Dec/13 ]

Done uploading. Let me know if you need anything else.

Could you please validate the following steps to disable FTS gracefully?

  1. Drop all FTS indexes
  2. stop mongod
  3. remove parameter textSearchEnabled from config file
  4. re-start mongod

Thanks

Comment by Eliot Horowitz (Inactive) [ 27/Dec/13 ]

This seems likely related to the fts index, just unclear as to what.

Yes, the directory will definitely be useful.

Can you send it to our anonymous upload only scp?

scp -P 722 <filename> server12208@www.mongodb.com:

just hit enter when prompted for password

Comment by Fernando Dobladez [ 26/Dec/13 ]

Unfortunately, we don't have a snapshot of the directory right after seeing the issue.

We did take one but after re-inserting the document lost... and after upgrading to 2.4.8 and restarting. If you think it might still be useful, I have it. The tgz is 391M.

Thanks

Comment by Fernando Dobladez [ 26/Dec/13 ]

> db.companies.getIndexes()
[
        {
                "v" : 1,
                "key" : {
                        "_id" : 1
                },
                "ns" : "reef.companies",
                "name" : "_id_"
        },
        {
                "v" : 1,
                "key" : {
                        "_fts" : "text",
                        "_ftsx" : 1
                },
                "ns" : "reef.companies",
                "name" : "companies_text_index",
                "default_language" : "spanish",
                "weights" : {
                        "$**" : 1
                },
                "language_override" : "language",
                "textIndexVersion" : 1
        }
]

Comment by Eliot Horowitz (Inactive) [ 26/Dec/13 ]

What indexes do you have on the collection?
Did you happen to take a snapshot of the data directory before restoring so we could look at it?

Generated at Thu Feb 08 03:27:54 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.