[SERVER-32082] dropDatabase reports success but db is still on disk of secondary Created: 24/Nov/17  Updated: 15/Mar/18  Resolved: 27/Nov/17

Status: Closed
Project: Core Server
Component/s: Replication, Storage
Affects Version/s: 3.4.6
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Kay Agahd Assignee: Dmitry Agranat
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
is duplicated by SERVER-31101 WT table not dropped after collection... Closed
Backwards Compatibility: Fully Compatible
Operating System: ALL
Participants:

 Description   

We are using 4 shards to store log data in daily created databases which will be dropped after some days. The reason not to use TTL is that dropDatabase is an instant operation freeing also diskspace immediately. However, the secondaries of 2 of the 4 shards do not wipe the dropped database from disk even though the dropDatabase command reported success.
The workaround described in SERVER-17397 (dropping the database from within the primary instead mongos) did not delete the database from the secondary event though the command reported success.
The dropped database is not shown by issuing the command show dbs on the secondary.

No matter if the command show dbs was issued through mongos, primary or secondary, it shows the same:

MongoDB server version: 3.4.6
mongos> show dbs
admin             0.000GB
config            0.010GB
log-2017-11-04   99.273GB
log-2017-11-05   84.237GB
log-2017-11-06   96.744GB
log-2017-11-07   96.260GB
log-2017-11-08  101.185GB
log-2017-11-09  109.233GB
log-2017-11-10  113.048GB
log-2017-11-11  110.611GB
log-2017-11-12   99.498GB
log-2017-11-13  100.777GB
log-2017-11-14  103.017GB
log-2017-11-15  118.151GB
log-2017-11-16  113.948GB
log-2017-11-17  111.382GB
log-2017-11-18  124.049GB
log-2017-11-19  102.645GB
log-2017-11-20  103.504GB
log-2017-11-21  120.029GB
log-2017-11-22  108.096GB
log-2017-11-23  111.556GB
log-2017-11-24   50.834GB
log-2017-11-25    0.000GB
log-2017-11-26    0.000GB
log-2017-11-27    0.000GB
log-2017-11-28    0.000GB
log-2017-11-29    0.000GB
log-2017-11-30    0.000GB
log-2017-12-01    0.000GB
stats             0.000GB
test              0.000GB
mongos>

These are our shards:

mongos> sh.status()
--- Sharding Status ---
  sharding version: {
	"_id" : 1,
	"minCompatibleVersion" : 5,
	"currentVersion" : 6,
	"clusterId" : ObjectId("598ab847e97e92ba40fa56ee")
}
  shards:
	{  "_id" : "offerHistory01",  "host" : "offerHistory01/mongo-016.db00.pro06.eu.idealo.com:27017,mongo-105.db00.pro05.eu.idealo.com:27017",  "state" : 1 }
	{  "_id" : "offerHistory02",  "host" : "offerHistory02/mongo-119.db00.pro06.eu.idealo.com:27017,mongo-120.db00.pro06.eu.idealo.com:27017",  "state" : 1 }
	{  "_id" : "offerHistory03",  "host" : "offerHistory03/mongo-121.db00.pro06.eu.idealo.com:27017,mongo-122.db00.pro06.eu.idealo.com:27017",  "state" : 1 }
	{  "_id" : "offerHistory04",  "host" : "offerHistory04/mongo-047.db00.pro06.eu.idealo.com:27017,mongo-123.db00.pro06.eu.idealo.com:27017",  "state" : 1 }
  active mongoses:
	"3.4.6" : 5
 autosplit:
	Currently enabled: yes
  balancer:
	Currently enabled:  no
	Currently running:  no


The balancer is disabled because our shardkey is well balanced (hashed).

Let's compare the data directories of primary and secondary of the 3rd shard:
Primary:

10:58:40]root@mongo-121.db00.pro06 # du -sch /data/offerHistory03/db/*
176K	/data/offerHistory03/db/admin
205M	/data/offerHistory03/db/diagnostic.data
4,2G	/data/offerHistory03/db/journal
42G	/data/offerHistory03/db/local
4,0K	/data/offerHistory03/db/log.452017.4507.4522.45zlib
4,0K	/data/offerHistory03/db/log.452017.4509.4513
4,0K	/data/offerHistory03/db/log.452017.4509.4527
4,0K	/data/offerHistory03/db/log.452017.4509.4528
4,0K	/data/offerHistory03/db/log.452017.4509.4529
4,0K	/data/offerHistory03/db/log.452017.4509.4530
4,0K	/data/offerHistory03/db/log.452017.4510.4501
4,0K	/data/offerHistory03/db/log.452017.4510.4502
4,0K	/data/offerHistory03/db/log.452017.4510.4503
4,0K	/data/offerHistory03/db/log.452017.4510.4504
4,0K	/data/offerHistory03/db/log.452017.4510.4505
4,0K	/data/offerHistory03/db/log.452017.4510.4506
4,0K	/data/offerHistory03/db/log.452017.4510.4507
4,0K	/data/offerHistory03/db/log.452017.4510.4508
4,0K	/data/offerHistory03/db/log.452017.4510.4509
4,0K	/data/offerHistory03/db/log.452017.4510.4510
4,0K	/data/offerHistory03/db/log.452017.4510.4511
4,0K	/data/offerHistory03/db/log.452017.4510.4512
4,0K	/data/offerHistory03/db/log.452017.4510.4513
4,0K	/data/offerHistory03/db/log.452017.4510.4514
4,0K	/data/offerHistory03/db/log.452017.4510.4515
4,0K	/data/offerHistory03/db/log.452017.4510.4516
4,0K	/data/offerHistory03/db/log.452017.4510.4517
4,0K	/data/offerHistory03/db/log.452017.4510.4518
4,0K	/data/offerHistory03/db/log.452017.4510.4519
4,0K	/data/offerHistory03/db/log.452017.4510.4520
4,0K	/data/offerHistory03/db/log.452017.4510.4521
4,0K	/data/offerHistory03/db/log.452017.4510.4522
4,0K	/data/offerHistory03/db/log.452017.4510.4523
4,0K	/data/offerHistory03/db/log.452017.4510.4524
4,0K	/data/offerHistory03/db/log.452017.4510.4525
4,0K	/data/offerHistory03/db/log.452017.4510.4526
4,0K	/data/offerHistory03/db/log.452017.4510.4527
4,0K	/data/offerHistory03/db/log.452017.4510.4528
4,0K	/data/offerHistory03/db/log.452017.4510.4529
4,0K	/data/offerHistory03/db/log.452017.4510.4530
4,0K	/data/offerHistory03/db/log.452017.4510.4531
4,0K	/data/offerHistory03/db/log.452017.4511.4501
4,0K	/data/offerHistory03/db/log.452017.4511.4502
4,0K	/data/offerHistory03/db/log.452017.4511.4503
25G	/data/offerHistory03/db/log.452017.4511.4504
22G	/data/offerHistory03/db/log.452017.4511.4505
25G	/data/offerHistory03/db/log.452017.4511.4506
25G	/data/offerHistory03/db/log.452017.4511.4507
26G	/data/offerHistory03/db/log.452017.4511.4508
28G	/data/offerHistory03/db/log.452017.4511.4509
29G	/data/offerHistory03/db/log.452017.4511.4510
28G	/data/offerHistory03/db/log.452017.4511.4511
25G	/data/offerHistory03/db/log.452017.4511.4512
26G	/data/offerHistory03/db/log.452017.4511.4513
26G	/data/offerHistory03/db/log.452017.4511.4514
30G	/data/offerHistory03/db/log.452017.4511.4515
29G	/data/offerHistory03/db/log.452017.4511.4516
28G	/data/offerHistory03/db/log.452017.4511.4517
32G	/data/offerHistory03/db/log.452017.4511.4518
26G	/data/offerHistory03/db/log.452017.4511.4519
26G	/data/offerHistory03/db/log.452017.4511.4520
30G	/data/offerHistory03/db/log.452017.4511.4521
28G	/data/offerHistory03/db/log.452017.4511.4522
28G	/data/offerHistory03/db/log.452017.4511.4523
13G	/data/offerHistory03/db/log.452017.4511.4524
20K	/data/offerHistory03/db/log.452017.4511.4525
20K	/data/offerHistory03/db/log.452017.4511.4526
20K	/data/offerHistory03/db/log.452017.4511.4527
20K	/data/offerHistory03/db/log.452017.4511.4528
20K	/data/offerHistory03/db/log.452017.4511.4529
20K	/data/offerHistory03/db/log.452017.4511.4530
20K	/data/offerHistory03/db/log.452017.4512.4501
36K	/data/offerHistory03/db/_mdb_catalog.wt
4,0K	/data/offerHistory03/db/mongod.lock
4,0K	/data/offerHistory03/db/perf
4,0K	/data/offerHistory03/db/perf2
64K	/data/offerHistory03/db/sizeStorer.wt
4,0K	/data/offerHistory03/db/storage.bson
4,0K	/data/offerHistory03/db/test
4,0K	/data/offerHistory03/db/_tmp
4,0K	/data/offerHistory03/db/WiredTiger
4,0K	/data/offerHistory03/db/WiredTigerLAS.wt
4,0K	/data/offerHistory03/db/WiredTiger.lock
4,0K	/data/offerHistory03/db/WiredTiger.turtle
452K	/data/offerHistory03/db/WiredTiger.wt
591G	insgesamt


Secondary:

[10:58:40]root@mongo-122.db00.pro06 # du -sch /data/offerHistory03/db/*
176K	/data/offerHistory03/db/admin
194M	/data/offerHistory03/db/diagnostic.data
400M	/data/offerHistory03/db/journal
42G	/data/offerHistory03/db/local
4,0K	/data/offerHistory03/db/log.452017.4507.4522.45zlib
4,0K	/data/offerHistory03/db/log.452017.4509.4513
4,0K	/data/offerHistory03/db/log.452017.4509.4527
4,0K	/data/offerHistory03/db/log.452017.4509.4528
4,0K	/data/offerHistory03/db/log.452017.4509.4529
4,0K	/data/offerHistory03/db/log.452017.4509.4530
4,0K	/data/offerHistory03/db/log.452017.4510.4501
4,0K	/data/offerHistory03/db/log.452017.4510.4502
4,0K	/data/offerHistory03/db/log.452017.4510.4503
4,0K	/data/offerHistory03/db/log.452017.4510.4504
4,0K	/data/offerHistory03/db/log.452017.4510.4505
4,0K	/data/offerHistory03/db/log.452017.4510.4506
4,0K	/data/offerHistory03/db/log.452017.4510.4507
4,0K	/data/offerHistory03/db/log.452017.4510.4508
4,0K	/data/offerHistory03/db/log.452017.4510.4509
4,0K	/data/offerHistory03/db/log.452017.4510.4510
4,0K	/data/offerHistory03/db/log.452017.4510.4511
4,0K	/data/offerHistory03/db/log.452017.4510.4512
4,0K	/data/offerHistory03/db/log.452017.4510.4513
4,0K	/data/offerHistory03/db/log.452017.4510.4514
4,0K	/data/offerHistory03/db/log.452017.4510.4515
4,0K	/data/offerHistory03/db/log.452017.4510.4516
4,0K	/data/offerHistory03/db/log.452017.4510.4517
4,0K	/data/offerHistory03/db/log.452017.4510.4518
4,0K	/data/offerHistory03/db/log.452017.4510.4519
4,0K	/data/offerHistory03/db/log.452017.4510.4520
4,0K	/data/offerHistory03/db/log.452017.4510.4521
4,0K	/data/offerHistory03/db/log.452017.4510.4522
4,0K	/data/offerHistory03/db/log.452017.4510.4523
4,0K	/data/offerHistory03/db/log.452017.4510.4524
4,0K	/data/offerHistory03/db/log.452017.4510.4525
4,0K	/data/offerHistory03/db/log.452017.4510.4526
4,0K	/data/offerHistory03/db/log.452017.4510.4527
4,0K	/data/offerHistory03/db/log.452017.4510.4528
4,0K	/data/offerHistory03/db/log.452017.4510.4529
4,0K	/data/offerHistory03/db/log.452017.4510.4530
4,0K	/data/offerHistory03/db/log.452017.4510.4531
4,0K	/data/offerHistory03/db/log.452017.4511.4501
17G	/data/offerHistory03/db/log.452017.4511.4502
22G	/data/offerHistory03/db/log.452017.4511.4503
25G	/data/offerHistory03/db/log.452017.4511.4504
22G	/data/offerHistory03/db/log.452017.4511.4505
25G	/data/offerHistory03/db/log.452017.4511.4506
25G	/data/offerHistory03/db/log.452017.4511.4507
26G	/data/offerHistory03/db/log.452017.4511.4508
28G	/data/offerHistory03/db/log.452017.4511.4509
28G	/data/offerHistory03/db/log.452017.4511.4510
28G	/data/offerHistory03/db/log.452017.4511.4511
25G	/data/offerHistory03/db/log.452017.4511.4512
26G	/data/offerHistory03/db/log.452017.4511.4513
26G	/data/offerHistory03/db/log.452017.4511.4514
30G	/data/offerHistory03/db/log.452017.4511.4515
29G	/data/offerHistory03/db/log.452017.4511.4516
28G	/data/offerHistory03/db/log.452017.4511.4517
32G	/data/offerHistory03/db/log.452017.4511.4518
26G	/data/offerHistory03/db/log.452017.4511.4519
26G	/data/offerHistory03/db/log.452017.4511.4520
31G	/data/offerHistory03/db/log.452017.4511.4521
27G	/data/offerHistory03/db/log.452017.4511.4522
28G	/data/offerHistory03/db/log.452017.4511.4523
13G	/data/offerHistory03/db/log.452017.4511.4524
20K	/data/offerHistory03/db/log.452017.4511.4525
20K	/data/offerHistory03/db/log.452017.4511.4526
20K	/data/offerHistory03/db/log.452017.4511.4527
20K	/data/offerHistory03/db/log.452017.4511.4528
20K	/data/offerHistory03/db/log.452017.4511.4529
20K	/data/offerHistory03/db/log.452017.4511.4530
20K	/data/offerHistory03/db/log.452017.4512.4501
40K	/data/offerHistory03/db/_mdb_catalog.wt
4,0K	/data/offerHistory03/db/mongod.lock
4,0K	/data/offerHistory03/db/perf
4,0K	/data/offerHistory03/db/perf2
64K	/data/offerHistory03/db/sizeStorer.wt
4,0K	/data/offerHistory03/db/storage.bson
4,0K	/data/offerHistory03/db/test
4,0K	/data/offerHistory03/db/WiredTiger
4,0K	/data/offerHistory03/db/WiredTigerLAS.wt
4,0K	/data/offerHistory03/db/WiredTiger.lock
4,0K	/data/offerHistory03/db/WiredTiger.turtle
384K	/data/offerHistory03/db/WiredTiger.wt
625G	insgesamt


You can see that the secondary still has data for databases log-2017-11-02 and log-2017-11-03:

17G	/data/offerHistory03/db/log.452017.4511.4502
22G	/data/offerHistory03/db/log.452017.4511.4503


whereas the primary deleted these database correctly from disk:

4,0K	/data/offerHistory03/db/log.452017.4511.4502
4,0K	/data/offerHistory03/db/log.452017.4511.4503

Our workaround is to restart the mongod process of the secondary. Once restarted, the orphaned databases are successfully deleted from disk:

[11:05:57]root@mongo-122.db00.pro06 # du -sch /data/offerHistory03/db/*
176K	/data/offerHistory03/db/admin
194M	/data/offerHistory03/db/diagnostic.data
271M	/data/offerHistory03/db/journal
42G	/data/offerHistory03/db/local
4,0K	/data/offerHistory03/db/log.452017.4507.4522.45zlib
4,0K	/data/offerHistory03/db/log.452017.4509.4513
4,0K	/data/offerHistory03/db/log.452017.4509.4527
4,0K	/data/offerHistory03/db/log.452017.4509.4528
4,0K	/data/offerHistory03/db/log.452017.4509.4529
4,0K	/data/offerHistory03/db/log.452017.4509.4530
4,0K	/data/offerHistory03/db/log.452017.4510.4501
4,0K	/data/offerHistory03/db/log.452017.4510.4502
4,0K	/data/offerHistory03/db/log.452017.4510.4503
4,0K	/data/offerHistory03/db/log.452017.4510.4504
4,0K	/data/offerHistory03/db/log.452017.4510.4505
4,0K	/data/offerHistory03/db/log.452017.4510.4506
4,0K	/data/offerHistory03/db/log.452017.4510.4507
4,0K	/data/offerHistory03/db/log.452017.4510.4508
4,0K	/data/offerHistory03/db/log.452017.4510.4509
4,0K	/data/offerHistory03/db/log.452017.4510.4510
4,0K	/data/offerHistory03/db/log.452017.4510.4511
4,0K	/data/offerHistory03/db/log.452017.4510.4512
4,0K	/data/offerHistory03/db/log.452017.4510.4513
4,0K	/data/offerHistory03/db/log.452017.4510.4514
4,0K	/data/offerHistory03/db/log.452017.4510.4515
4,0K	/data/offerHistory03/db/log.452017.4510.4516
4,0K	/data/offerHistory03/db/log.452017.4510.4517
4,0K	/data/offerHistory03/db/log.452017.4510.4518
4,0K	/data/offerHistory03/db/log.452017.4510.4519
4,0K	/data/offerHistory03/db/log.452017.4510.4520
4,0K	/data/offerHistory03/db/log.452017.4510.4521
4,0K	/data/offerHistory03/db/log.452017.4510.4522
4,0K	/data/offerHistory03/db/log.452017.4510.4523
4,0K	/data/offerHistory03/db/log.452017.4510.4524
4,0K	/data/offerHistory03/db/log.452017.4510.4525
4,0K	/data/offerHistory03/db/log.452017.4510.4526
4,0K	/data/offerHistory03/db/log.452017.4510.4527
4,0K	/data/offerHistory03/db/log.452017.4510.4528
4,0K	/data/offerHistory03/db/log.452017.4510.4529
4,0K	/data/offerHistory03/db/log.452017.4510.4530
4,0K	/data/offerHistory03/db/log.452017.4510.4531
4,0K	/data/offerHistory03/db/log.452017.4511.4501
4,0K	/data/offerHistory03/db/log.452017.4511.4502
4,0K	/data/offerHistory03/db/log.452017.4511.4503
25G	/data/offerHistory03/db/log.452017.4511.4504
22G	/data/offerHistory03/db/log.452017.4511.4505
25G	/data/offerHistory03/db/log.452017.4511.4506
25G	/data/offerHistory03/db/log.452017.4511.4507
26G	/data/offerHistory03/db/log.452017.4511.4508
28G	/data/offerHistory03/db/log.452017.4511.4509
28G	/data/offerHistory03/db/log.452017.4511.4510
28G	/data/offerHistory03/db/log.452017.4511.4511
25G	/data/offerHistory03/db/log.452017.4511.4512
26G	/data/offerHistory03/db/log.452017.4511.4513
26G	/data/offerHistory03/db/log.452017.4511.4514
30G	/data/offerHistory03/db/log.452017.4511.4515
29G	/data/offerHistory03/db/log.452017.4511.4516
28G	/data/offerHistory03/db/log.452017.4511.4517
32G	/data/offerHistory03/db/log.452017.4511.4518
26G	/data/offerHistory03/db/log.452017.4511.4519
26G	/data/offerHistory03/db/log.452017.4511.4520
31G	/data/offerHistory03/db/log.452017.4511.4521
27G	/data/offerHistory03/db/log.452017.4511.4522
28G	/data/offerHistory03/db/log.452017.4511.4523
13G	/data/offerHistory03/db/log.452017.4511.4524
20K	/data/offerHistory03/db/log.452017.4511.4525
20K	/data/offerHistory03/db/log.452017.4511.4526
20K	/data/offerHistory03/db/log.452017.4511.4527
20K	/data/offerHistory03/db/log.452017.4511.4528
20K	/data/offerHistory03/db/log.452017.4511.4529
20K	/data/offerHistory03/db/log.452017.4511.4530
20K	/data/offerHistory03/db/log.452017.4512.4501
40K	/data/offerHistory03/db/_mdb_catalog.wt
4,0K	/data/offerHistory03/db/mongod.lock
4,0K	/data/offerHistory03/db/perf
4,0K	/data/offerHistory03/db/perf2
64K	/data/offerHistory03/db/sizeStorer.wt
4,0K	/data/offerHistory03/db/storage.bson
4,0K	/data/offerHistory03/db/test
4,0K	/data/offerHistory03/db/WiredTiger
4,0K	/data/offerHistory03/db/WiredTigerLAS.wt
4,0K	/data/offerHistory03/db/WiredTiger.lock
4,0K	/data/offerHistory03/db/WiredTiger.turtle
384K	/data/offerHistory03/db/WiredTiger.wt
588G	insgesamt



 Comments   
Comment by Kay Agahd [ 15/Mar/18 ]

It's just to let you know that we've deployed mongodb v3.4.13 which fixes the db.dropDatabase() bug.
Thank you!

Comment by Kay Agahd [ 29/Nov/17 ]

Thanks milkie for pointing out.

Comment by Eric Milkie [ 29/Nov/17 ]

Hi Kay,
We don't use the fixVersion field like that for minor production releases, so there are still some tickets we'd like to get in to 3.4.11. This search shows some, but not all, of the candidates:
https://jira.mongodb.org/issues/?jql=project%3Dserver%20and%20fixversion%3D%223.4%20Required%22

Comment by Kay Agahd [ 29/Nov/17 ]

Thanks dmitry.agranat for the info. What are you waiting for to release v3.4.11? According to jira there are 0 issues in progress and also 0 issues to do since 39 of 39 issues are done already.

Comment by Dmitry Agranat [ 27/Nov/17 ]

Hi kay.agahd@idealo.de,

Based on the information you've provided, this issue is related to SERVER-31101 which is fixed in 3.4.11.
Once 3.4.11 is out, please upgrade your cluster and if it’s still a problem let us know.

Thank you,
Dima

Comment by Kaloian Manassiev [ 27/Nov/17 ]

kay.agahd@idealo.de, the symptoms that you described seem to be internal to the shard's replica set nodes and not to the database as it spans shards. Because of this I am removing the link to SERVER-17397.

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