[SERVER-37798] Crash after dropping a unique index. Created: 29/Oct/18  Updated: 27/Nov/18  Resolved: 27/Nov/18

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

Type: Bug Priority: Major - P3
Reporter: Antònia Tugores Assignee: Danny Hatcher (Inactive)
Resolution: Cannot Reproduce Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File drop_index.py     Text File ls.txt     File mongod.log.2018-10-29T12-07-50    
Operating System: ALL
Steps To Reproduce:

 

Fresh MongoDB 4.0.2 with wired tiger, ssl and authentication (user/pwd)

Create collection with some indices, one of them unique.

Insert data in this collection from pymongo 3.7.1

Drop the unique index from pymongo 3.7.1

MongoDB crashes (even when both data and index are owned by mongod:mongod and permissions are 700).

Restart the server and "version is too new for this mongod" arises.

 

 

Participants:

 Description   

 

In a fresh MongoDB 4.0.2 installation with wiredtiger, ssl and user/pwd authentication a unique index is dropped and the server crashes (with a permission denied error but both data and indices folder's owner is mongodb:mongodb and permissions are 700).

018-10-29T12:17:43.640+0100 I ACCESS [conn2072] Successfully authenticated as principal twins on twitter_2014
2018-10-29T12:17:43.642+0100 I COMMAND [conn2072] CMD: dropIndexes DBNAME.COLLNAME
2018-10-29T12:17:43.780+0100 E STORAGE [conn2072] WiredTiger error (13) [1540811863:779697][16638:0x7f63132d8700], WT_SESSION.drop: __posix_fs_remove, 216: /var/lib/mongodb/index/3-8048314178193759520.wt: file-remove: unlink: Permission denied Raw: [1540811863:779697][16638:0x7f63132d8700], WT_SESSION.drop: __posix_fs_remove, 216: /var/lib/mongodb/index/3-8048314178193759520.wt: file-remove: unlink: Permission denied
2018-10-29T12:17:43.780+0100 E STORAGE [conn2072] WiredTiger error (13) [1540811863:780261][16638:0x7f63132d8700], WT_SESSION.drop: __meta_track_apply, 156: metadata remove dropped file index/3-8048314178193759520.wt: Permission denied Raw: [1540811863:780261][16638:0x7f63132d8700], WT_SESSION.drop: __meta_track_apply, 156: metadata remove dropped file index/3-8048314178193759520.wt: Permission denied
2018-10-29T12:17:43.780+0100 E STORAGE [conn2072] WiredTiger error (13) [1540811863:780286][16638:0x7f63132d8700], WT_SESSION.drop: __wt_meta_track_off, 352: failed to apply or unroll all tracked operations: Permission denied Raw: [1540811863:780286][16638:0x7f63132d8700], WT_SESSION.drop: __wt_meta_track_off, 352: failed to apply or unroll all tracked operations: Permission denied
2018-10-29T12:17:43.780+0100 E STORAGE [conn2072] WiredTiger error (-31804) [1540811863:780302][16638:0x7f63132d8700], WT_SESSION.drop: __wt_panic, 523: the process must exit and restart: WT_PANIC: WiredTiger library panic Raw: [1540811863:780302][16638:0x7f63132d8700], WT_SESSION.drop: __wt_panic, 523: the process must exit and restart: WT_PANIC: WiredTiger library panic
2018-10-29T12:17:43.780+0100 F - [conn2072] Fatal Assertion 50853 at src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp 401
2018-10-29T12:17:43.780+0100 F - [conn1978] Fatal Assertion 28559 at src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp 62
2018-10-29T12:17:43.780+0100 F - [conn35] Fatal Assertion 28559 at src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp 62

When trying to restart the service, another error arises: 

2018-10-29T12:30:14.590+0100 I STORAGE [initandlisten] Placing a marker at optime Oct 29 12:08:58:811 2018-10-29T12:30:18.023+0100 E STORAGE [initandlisten] WiredTiger error (-31803) [1540812618:23278][25646:0x7f4985626a00], file:WiredTiger.wt, WT_CURSOR.next: __schema_create_collapse, 111: metadata information for source configuration "colgroup:index/0-6878827104047333897" not found: WT_NOTFOUND: item not found Raw: [1540812618:23278][25646:0x7f4985626a00], file:WiredTiger.wt, WT_CURSOR.next: __schema_create_collapse, 111: metadata information for source configuration "colgroup:index/0-6878827104047333897" not found: WT_NOTFOUND: item not found 2018-10-29T12:30:18.177+0100 I STORAGE [initandlisten] Expected index data is missing, rebuilding. Collection: DBNAME.COLLNAME Index: id_1 2018-10-29T12:30:18.179+0100 I STORAGE [initandlisten] not rebuilding interrupted indexes 2018-10-29T12:30:20.127+0100 F - [initandlisten] Fatal assertion 28579 UnsupportedFormat: Unable to find metadata for table:index/3-8048314178193759520 Index: {name: id_1, ns: DBNAME.COLLNAME} - version too new for this mongod. See http://dochub.mongodb.org/core/4.2-downgrade-index for detailed instructions on how to handle this error. at src/mongo/db/storage/wiredtiger/wiredtiger_index.cpp 294 2018-10-29T12:30:20.127+0100 F - [initandlisten] ***aborting after fassert() failure

As this is a fresh install, it cannot be an upgrade/downgrade issue, how is it possible to have inconsistent index version in this case?

Server is finally restarted by removing the corrupted index file.

 

 

 

 



 Comments   
Comment by Danny Hatcher (Inactive) [ 27/Nov/18 ]

Hello Antònia,

Unfortunately, as neither of us can reproduce the issue, I am going to close this ticket as "Cannot Reproduce". If you do happen to encounter this error again please let us know on this ticket and we can resume the investigation.

Thank you,

Danny

Comment by Antònia Tugores [ 27/Nov/18 ]

 

In the RS that crashed there was no downgrade, it was a fresh 4.0.2 install.

And when I tried to reproduce it we did the same steps: three servers with a fresh Ubuntu 18.04 server installation (ntp,  no THP, and ad-hoc ulimits), added your repo and installed 4.0.2  (we followed the instructions in your documentation page), added authorization (user/pwd), certificates, moved to preferSSL,  and configured the RS (two computers with data + one arbiter). There was no downgrade, no other versions were installed in any case (as in the production environment). In fact we tried reproducing it with 2+arbiter and 2+0arbiters (in both cases we installed/configured it from scratch, OS included)

 

Comment by Danny Hatcher (Inactive) [ 26/Nov/18 ]

Hello Antònia,

The redirect to the 4.2 documentation is because the old link was pointing to a version of 3.4 which is the last time that index compatibility between versions changed. It appears that this was a change introduced in 4.0.2 per SERVER-32994. However, you should not have experienced this message if there was no downgrade from a 4.1 development branch.

Unfortunately, I have been unable to reproduce your problem. You mentioned that you have been unable to reproduce as well; were your reproduction attempts also on 4.0.2 or were they on a different version?

Thank you,

Danny

Comment by Antònia Tugores [ 20/Nov/18 ]

Hello,

Sorry for the delay.

We tried but we were not able to reproduce it even though we used the original scripts to configure the db and imported the same data (but just a few gigabytes).

The error message (version too new for this mongod) and the redirection to the 4.2 help page confuse me. Is there any mismatch between 4.0.* internal data? The redirection can be a simple error with the link completion (by using the last available version), but what about the version mismatch error?

Comment by Danny Hatcher (Inactive) [ 14/Nov/18 ]

Hello Antònia,

Have you been able to reproduce the issue?

Thank you,

Danny

Comment by Antònia Tugores [ 30/Oct/18 ]

 

Hello Daniel,

This morning we tried to reproduce it but we could not (we were using the same installation, but yesterday afternoon we upgraded the RS to 4.0.3). We'll try with an standalone 4.0.2 server asap.

  • Log after crash (we restarted with indexBuildRetry=False): mongod.log.2018-10-29T12-07-50
  • And  ls -l. It's been run this morning, we don't have yesterday's ls, but all files were owned by mongodb:mongodb: ls.txt
  • The main lines of the Python app that dropped the index. It was run in an environment with pymongo 3.7.1: drop_index.py

Thanks,

 antònia

Comment by Danny Hatcher (Inactive) [ 29/Oct/18 ]

Hello Antònia,

I have been unable to reproduce the problem following the steps that you provided. Can you please confirm if you are able to reproduce the issue when following the above steps? Please also provide the following:

  • The mongod log covering the first startup of the server through the restart
  • The output of ls -l run against the relevant data directories
  • The code in your Python application that you are using to drop the index

Thank you,

Danny

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