[SERVER-13444] Long locked flush without inserts and updates Created: 01/Apr/14  Updated: 08/Jul/14  Resolved: 08/Jul/14

Status: Closed
Project: Core Server
Component/s: Performance
Affects Version/s: 2.4.9, 2.6.0-rc2
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Nikita Tarasov Assignee: Mark Benvenuto
Resolution: Duplicate Votes: 0
Labels: flush, lock
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Windows Server 2008R2 SP1, 128GB RAM, 3TB HHD, 12Cores


Attachments: File mongod.log.2014-04-03T05-17-46     File mongodb_log_000001.7z     Text File mongostat log.txt    
Issue Links:
Depends
depends on SERVER-13681 MongoDB stalls during background flus... Closed
depends on SERVER-13725 Reads & Writes are blocked during Mem... Closed
depends on SERVER-13729 Reads & Writes are blocked during dat... Closed
Duplicate
is duplicated by SERVER-10591 Database is locked (or freezed) when ... Closed
Related
related to SERVER-9868 heartbeats not responded to during mm... Closed
related to SERVER-12880 Server pauses on requests every 60 se... Closed
is related to SERVER-12401 Improve the memory-mapped files flush... Closed
Operating System: Windows
Participants:

 Description   

Every 60 seconds, Mongo stops processing all requests and pauses for X seconds, where X depended on Memory Working Set. For expample, 32GB in Working Set = ~5-8 seconds. Even if there are no inserts and updates.



 Comments   
Comment by Nikita Tarasov [ 04/Apr/14 ]

I attached performance counter trace

Comment by Mark Benvenuto [ 03/Apr/14 ]

I would also like a performance counter trace to understand why it is running so slow. You will need to run the following commands, and it will collect a trace file for 15 minutes of 1 second samples, and then stop. After it stops, attach the information to the ticket so understand how much write traffic there is and if is particularly high disk latency from your storage system in the first place.

logman delete mongodb_log
logman create counter mongodb_log -c "\Processor(_Total)\% Processor Time" "\Processor(_Total)\% Privileged Time" "\PhysicalDisk(_Total)\*" -f bin -rf 00:15:00 -si 1 -ow
logman start mongodb_log

later run

logman query mongodb_log to find the file(s), zip and attach to jira

Comment by Nikita Tarasov [ 03/Apr/14 ]

Hi Thomas,

I attached log file(about 10 minutes with logLevel=5) of one of nodes.

Comment by Thomas Rueckstiess [ 02/Apr/14 ]

Hi Nikita,

This is probably related to the flushing of memory mapped files to disk, which happens every 60 seconds, but we would need the mongod log file of one of the affected nodes to diagnose further. Can you attach one to the ticket please?

Thanks
Thomas

Comment by Nikita Tarasov [ 01/Apr/14 ]

Sorry, real mongostat log in attached file

MMS info:
Group: Normativ
Hosts: NORMATIV-back1, NORMATIV-back2, NORMATIV-back3

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