[SERVER-21921] Insert is taking huge time in wiretiger storage engine Created: 16/Dec/15  Updated: 16/Nov/21  Resolved: 09/Jan/16

Status: Closed
Project: Core Server
Component/s: WiredTiger
Affects Version/s: 3.0.6
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Rakesh Kumar Assignee: Kelsey Schubert
Resolution: Incomplete Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Participants:

 Description   

Hi,
Inserts are taking lots of time in wiretiger storage engine.
We are having around 6000 collections in this database and are using mongo 3.0.6 shard cluster with only one shard and database is not sharded in this cluster.
Is this the default behaviour or issue with wiretiger storage engine.

Queries are like this:

2015-12-16T10:32:13.146+0000 I COMMAND  [conn48] command abc.$cmd command: insert { ins: "56711241e4b0ac2aafd0114a_1450250822756", documents: [ { _id: ObjectId('56713dace4b007382af53e2e'), a: " XXXX", b: "XXX", c: XXX, d: "XXX", e: "123", f: "XXX@XXX.com" } ], g: XX, metadata: { shardName: "shard1", shardVersion: [ Timestamp 0|0, ObjectId('000000000000000000000000') ], session: 0 } } ntoreturn:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:140 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 1138240 } }, Collection: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 638ms

Mongostat O/P:

# mongostat --port 27012
insert query update delete getmore command % dirty % used flushes vsize   res qr|qw ar|aw netIn netOut conn    set repl     time
  1309   659    657     *0     728   814|0     0.3   80.0       0 22.4G 16.2G   0|0   1|1    1m     2m  167 shard1  PRI 11:10:57
  1154   509    512     *0     727   796|0     0.3   80.0       0 22.4G 16.2G   0|0   1|0    1m     1m  167 shard1  PRI 11:10:58
  1377   731    730     *0     719   827|0     0.3   80.0       0 22.4G 16.2G   0|0   1|0    1m     2m  167 shard1  PRI 11:10:59
  1262   607    606     *0     723   810|0     0.3   80.0       0 22.4G 16.2G   0|0   1|0    1m     2m  167 shard1  PRI 11:11:00

server : EC2 Instance Type: m4.xlarge



 Comments   
Comment by Kelsey Schubert [ 16/Dec/15 ]

Hi rakesh.mib.j,

Thanks for the report. We see that the operation is waiting for a lock before actually doing the insert. E.g. timeAcquiringMicros: { w: 1138240}

To help us better understand your system and what's going on here, could you please answer the following questions about your deployment and environment:

  1. Are you seeing inserts taking a long time on all collections?
  2. Can you please post the output of dbstats?
  3. Can you list the indexes on the the affected collections?
  4. Can you provide more information about the configuration of your storage system? What kind of block devices are you using? What file systems are you using?
  5. What other operations is your application doing when you observe this performance degredation? Are you doing other updates in addition to the inserts, or just reads?
  6. Is your observable speed consistent or is there variation? Is it faster some times and slower others?

Thank you,
Thomas

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