Mongo DB crashing with an error: Not enough storage is available to process this command

Ops and Admin
1

Hi,
Mongo DB is crashing which is causing the application to fail. When extracted mongo Db logs found below error :-1:

2022-09-11T00:36:21.977+0000 E STORAGE [WTJournalFlusher] WiredTiger (-28992) [1662856581:400819][7072:1995194080], WT_SESSION.log_flush: journal/WiredTigerLog.0000158373 handle-sync: FlushFileBuffers error: Not enough storage is available to process this command.

2022-09-11T00:36:21.989+0000 I - [WTJournalFlusher] Invariant failure: s->log_flush(s, “sync=on”) resulted in status UnknownError: -28992: Not enough storage is available to process this command.
This is the second occurrence and After restarting application servers mongo started working as expected.

what is the possible reason for this issue? and do we have any work around to avoid future occurences?

Attaching logs for your reference.

Thanks in advance!

2 
2022-09-11T00:36:21.849+0000 I COMMAND  [conn3987] insert meolutdb.rawDetection ninserted:40 keyUpdates:0 writeConflicts:0 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } 113ms
2022-09-11T00:36:21.977+0000 E STORAGE  [WTJournalFlusher] WiredTiger (-28992) [1662856581:400819][7072:1995194080], WT_SESSION.log_flush: journal/WiredTigerLog.0000158373 handle-sync: FlushFileBuffers error: Not enough storage is available to process this command.

2022-09-11T00:36:21.989+0000 I -        [WTJournalFlusher] Invariant failure: s->log_flush(s, "sync=on") resulted in status UnknownError: -28992: Not enough storage is available to process this command.

 at src\mongo\db\storage\wiredtiger\wiredtiger_session_cache.cpp 203
2022-09-11T00:36:25.065+0000 I COMMAND  [conn4275] update meolutdb.eMSStatus query: { _id: "421d0553-e28b-4feb-a48e-7bfb6ed129fc" } update: { _id: "421d0553-e28b-4feb-a48e-7bfb6ed129fc", _class: "com.emsgt.lut.il.dal.api.EMSStatus", subsystem_id: 3, service_id: 10005, service_description: "Motor Temperature", timestamp: 1662856584631000000, status: "OK", errors: " 34.00 celsius", subsystem_type: "Antenna" } keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keyUpdates:6 writeConflicts:0 numYields:1 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 } } } 113ms
2022-09-11T00:36:26.505+0000 I COMMAND  [conn3965] insert meolutdb.rawDetection ninserted:40 keyUpdates:0 writeConflicts:0 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } 119ms
2022-09-11T00:36:26.632+0000 I COMMAND  [conn4001] insert meolutdb.rawDetection ninserted:40 keyUpdates:0 writeConflicts:0 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } 156ms
2022-09-11T00:36:50.126+0000 I CONTROL  [WTJournalFlusher] mongod.exe    ...\src\mongo\util\stacktrace_windows.cpp(174)                                   mongo::printStackTrace+0x43
2022-09-11T00:36:50.126+0000 I CONTROL  [WTJournalFlusher] mongod.exe    ...\src\mongo\util\log.cpp(136)                                                  mongo::logContext+0xa8
2022-09-11T00:36:50.126+0000 I CONTROL  [WTJournalFlusher] mongod.exe    ...\src\mongo\util\assert_util.cpp(164)                                          mongo::invariantOKFailed+0x14c
2022-09-11T00:36:50.126+0000 I CONTROL  [WTJournalFlusher] mongod.exe    ...\src\mongo\db\storage\wiredtiger\wiredtiger_session_cache.cpp(203)            mongo::WiredTigerSessionCache::waitUntilDurable+0x2bd
2022-09-11T00:36:50.126+0000 I CONTROL  [WTJournalFlusher] mongod.exe    ...\src\mongo\db\storage\wiredtiger\wiredtiger_kv_engine.cpp(97)                 mongo::WiredTigerKVEngine::WiredTigerJournalFlusher::run+0x1a8
2022-09-11T00:36:50.126+0000 I CONTROL  [WTJournalFlusher] mongod.exe    ...\src\mongo\util\background.cpp(152)                                           mongo::BackgroundJob::jobBody+0x1b1
2022-09-11T00:36:50.126+0000 I CONTROL  [WTJournalFlusher] mongod.exe    c:\program files (x86)\microsoft visual studio 12.0\vc\include\thr\xthread(188)  std::_LaunchPad<std::_Bind<0,void,std::_Bind<1,void,std::_Pmf_wrap<void (__cdecl mongo::dur::JournalWriter::*)(void) __ptr64,void,mongo::dur::JournalWriter>,mongo::dur::JournalWriter * __ptr64 const> > >::_Go+0x1c
2022-09-11T00:36:50.126+0000 I CONTROL  [WTJournalFlusher] mongod.exe    f:\dd\vctools\crt\crtw32\stdcpp\thr\threadcall.cpp(28)                           _Call_func+0x14
2022-09-11T00:36:50.126+0000 I CONTROL  [WTJournalFlusher] mongod.exe    f:\dd\vctools\crt\crtw32\startup\threadex.c(376)                                 _callthreadstartex+0x17
2022-09-11T00:36:50.126+0000 I CONTROL  [WTJournalFlusher] mongod.exe    f:\dd\vctools\crt\crtw32\startup\threadex.c(354)                                 _threadstartex+0x102
2022-09-11T00:36:50.126+0000 I CONTROL  [WTJournalFlusher] kernel32.dll                                                                                   BaseThreadInitThunk+0xd
2022-09-11T00:36:50.126+0000 I CONTROL  [WTJournalFlusher] 
2022-09-11T00:36:50.126+0000 I -        [WTJournalFlusher] 

***aborting after invariant() failure
3

Hello @Mamatha_K and welcome to the MongoDB community forums. :wave:

This log entry seems to be stating that your disk is full and that the process cannot write to the disk. Have you verified that amount of free space you have on the drive you’re writing to?

3 Likes
4

@Doug_Duncan : Yes we have 800gb in D drive, 40-50gb is C drive. And mongo DB is around 720gb.

5

It looks like you should have enough free space on your drives, but I’m not sure if the numbers given are the amount free or the amount total. You also don’t state where MongoDB data is located.

If you have 800G free on the D drive and your MongoDB data is also on the D drive, then you definitely have more than enough free space for most things. You might run into problems if you were to back up to that drive or do some other admin-y type things that would require you to basically copy the data to that drive.

If you have 800G total on the D drive and your MongoDB data is also on the D drive, then you might still have enough space for running the database. I would be concerned that I was sitting at 90% usage on the drive however, especially if your database is growing in size. Once you run out of space (as your error indicates) the system will shutdown to mitigate any potential corruption.

If you have 40 - 50G free on the C drive and your MongoDB data is also on the C drive, then again you might have enough space for running the database. I would caution again that this is not a lot of space compared to the size of the database.

If you have 40 - 50G total on the C drive then your MongoDB data will not be there because it’s just not possible. :wink:

You can take a look at the <dbdata path>/journal/WiredTigerLog.* files to see how big in size they are on average as that might give more insight into what’s going on.

6

Hi Doug_Duncan : i managed to extract WiredTigerLog.* logs but unfortunately it’s not in user readable format :frowning: Do we have any modes to parse it?

7

MicrosoftTeams-image (1)
MicrosoftTeams-image (1)1783×802 10.2 KB

Attaching memory availability report where mongo is installed for reference.

8

MicrosoftTeams-image
MicrosoftTeams-image1269×746 15.5 KB

9

Hi @Mamatha_K,

Please share more details on your environment including:

  • specific version of MongoDB server

  • version of Windows

  • filesystem used for your MongoDB data volume. If NTFS, are you using compression?

Thanks,
Stennie

10

HI @Stennie_X ,

MongoDB version used is : 3.2.6
Windows : Windows Server 2008 R2
FIle system used is : NTFS, compression is not used. We are using a raid array
with two logical drives.
on the disk drive where the mongo data is stored the compression option is not been selected.

11

You don’t need to look at the contents. My comment was to look to see how big the files were and to see if creating a new file of that size would cause problems for the process.

12

Hi @Mamatha_K,

MongoDB 3.2.6 was released in April, 2016 and the 3.2 series reached end of life in September, 2018.

As a first step I recommend upgrading to the final 3.2.22 server version as there have been a few years of bug fixes and improvements since the version you are using. Minor/patch releases do not introduce any backward breaking changes or incompatibilities so they are very straightforward.

I would also consider planning an upgrade to the latest release series supported for your O/S. Per the MongoDB Platform Support Matrix, MongoDB 4.2 is the last server release series to support Windows Server 2008 R2 (which reached end of life in Jan 2015).

If your NTFS volume appears to have sufficient free space but writes are not successful, one option to check might be disk fragmentation and filesystem limits. There are some underlying filesystem limits that might result in large files being unable to grow, similar to SERVER-32808 where the problem was more evident on a compressed NTFS volume.

However, since you are using very old and unsupported software versions I would start by moving to later versions as you may be encountering issues which have since been resolved.

Regards,
Stennie

2 Likes
13

Hi Stennie,
Thank you for the solution .
I am planning to upgrade to 3.2.22 version on windows server 2008 R2. I have downloaded zip file (mongodb-win32-x86_64-2008plus-3.2.22.zip) .
Will it work if i just replace the content? or do we need to follow any installation process?
Please help.

14

I am getting this error on running mongod on my kali os:

{“t”:{“$date”:“2023-05-03T12:38:39.224+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:23285, “ctx”:“thread1”,“msg”:“Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols ‘none’”}
{“t”:{“$date”:“2023-05-03T12:38:39.225+05:30”},“s”:“I”, “c”:“NETWORK”, “id”:4915701, “ctx”:“thread1”,“msg”:“Initialized wire specification”,“attr”:{“spec”:{“incomingExternalClient”:{“minWireVersion”:0,“maxWireVersion”:17},“incomingInternalClient”:{“minWireVersion”:0,“maxWireVersion”:17},“outgoing”:{“minWireVersion”:6,“maxWireVersion”:17},“isInternalClient”:true}}}
{“t”:{“$date”:“2023-05-03T12:38:39.226+05:30”},“s”:“I”, “c”:“NETWORK”, “id”:4648601, “ctx”:“thread1”,“msg”:“Implicit TCP FastOpen unavailable. If TCP FastOpen is required, set tcpFastOpenServer, tcpFastOpenClient, and tcpFastOpenQueueSize.”}
{“t”:{“$date”:“2023-05-03T12:38:39.227+05:30”},“s”:“I”, “c”:“REPL”, “id”:5123008, “ctx”:“thread1”,“msg”:“Successfully registered PrimaryOnlyService”,“attr”:{“service”:“TenantMigrationDonorService”,“namespace”:“config.tenantMigrationDonors”}}
{“t”:{“$date”:“2023-05-03T12:38:39.227+05:30”},“s”:“I”, “c”:“REPL”, “id”:5123008, “ctx”:“thread1”,“msg”:“Successfully registered PrimaryOnlyService”,“attr”:{“service”:“TenantMigrationRecipientService”,“namespace”:“config.tenantMigrationRecipients”}}
{“t”:{“$date”:“2023-05-03T12:38:39.227+05:30”},“s”:“I”, “c”:“REPL”, “id”:5123008, “ctx”:“thread1”,“msg”:“Successfully registered PrimaryOnlyService”,“attr”:{“service”:“ShardSplitDonorService”,“namespace”:“config.tenantSplitDonors”}}
{“t”:{“$date”:“2023-05-03T12:38:39.227+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:5945603, “ctx”:“thread1”,“msg”:“Multi threading initialized”}
{“t”:{“$date”:“2023-05-03T12:38:39.228+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:4615611, “ctx”:“initandlisten”,“msg”:“MongoDB starting”,“attr”:{“pid”:18499,“port”:27017,“dbPath”:“/data/db”,“architecture”:“64-bit”,“host”:“kali”}}
{“t”:{“$date”:“2023-05-03T12:38:39.228+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:23403, “ctx”:“initandlisten”,“msg”:“Build Info”,“attr”:{“buildInfo”:{“version”:“6.0.1”,“gitVersion”:“32f0f9c88dc44a2c8073a5bd47cf779d4bfdee6b”,“openSSLVersion”:“OpenSSL 3.0.7 1 Nov 2022”,“modules”:,“allocator”:“tcmalloc”,“environment”:{“distarch”:“x86_64”,“target_arch”:“x86_64”}}}}
{“t”:{“$date”:“2023-05-03T12:38:39.228+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:51765, “ctx”:“initandlisten”,“msg”:“Operating System”,“attr”:{“os”:{“name”:“PRETTY_NAME="Kali GNU/Linux Rolling"”,“version”:“Kernel 6.0.0-kali3-amd64”}}}
{“t”:{“$date”:“2023-05-03T12:38:39.228+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:21951, “ctx”:“initandlisten”,“msg”:“Options set by command line”,“attr”:{“options”:{}}}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“E”, “c”:“CONTROL”, “id”:20557, “ctx”:“initandlisten”,“msg”:“DBException in initAndListen, terminating”,“attr”:{“error”:“NonExistentPath: Data directory /data/db not found. Create the missing directory or specify another path using (1) the --dbpath command line option, or (2) by adding the ‘storage.dbPath’ option in the configuration file.”}}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“REPL”, “id”:4784900, “ctx”:“initandlisten”,“msg”:“Stepping down the ReplicationCoordinator for shutdown”,“attr”:{“waitTimeMillis”:15000}}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“REPL”, “id”:4794602, “ctx”:“initandlisten”,“msg”:“Attempting to enter quiesce mode”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“-”, “id”:6371601, “ctx”:“initandlisten”,“msg”:“Shutting down the FLE Crud thread pool”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“COMMAND”, “id”:4784901, “ctx”:“initandlisten”,“msg”:“Shutting down the MirrorMaestro”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“SHARDING”, “id”:4784902, “ctx”:“initandlisten”,“msg”:“Shutting down the WaitForMajorityService”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“NETWORK”, “id”:20562, “ctx”:“initandlisten”,“msg”:“Shutdown: going to close listening sockets”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“NETWORK”, “id”:4784905, “ctx”:“initandlisten”,“msg”:“Shutting down the global connection pool”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:4784906, “ctx”:“initandlisten”,“msg”:“Shutting down the FlowControlTicketholder”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“-”, “id”:20520, “ctx”:“initandlisten”,“msg”:“Stopping further Flow Control ticket acquisitions.”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“NETWORK”, “id”:4784918, “ctx”:“initandlisten”,“msg”:“Shutting down the ReplicaSetMonitor”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“SHARDING”, “id”:4784921, “ctx”:“initandlisten”,“msg”:“Shutting down the MigrationUtilExecutor”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“ASIO”, “id”:22582, “ctx”:“MigrationUtil-TaskExecutor”,“msg”:“Killing all outstanding egress activity.”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“COMMAND”, “id”:4784923, “ctx”:“initandlisten”,“msg”:“Shutting down the ServiceEntryPoint”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:4784925, “ctx”:“initandlisten”,“msg”:“Shutting down free monitoring”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:4784927, “ctx”:“initandlisten”,“msg”:“Shutting down the HealthLog”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:4784928, “ctx”:“initandlisten”,“msg”:“Shutting down the TTL monitor”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:6278511, “ctx”:“initandlisten”,“msg”:“Shutting down the Change Stream Expired Pre-images Remover”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:4784929, “ctx”:“initandlisten”,“msg”:“Acquiring the global lock for shutdown”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“-”, “id”:4784931, “ctx”:“initandlisten”,“msg”:“Dropping the scope cache for shutdown”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:20565, “ctx”:“initandlisten”,“msg”:“Now exiting”}
{“t”:{“$date”:“2023-05-03T12:38:39.232+05:30”},“s”:“I”, “c”:“CONTROL”, “id”:23138, “ctx”:“initandlisten”,“msg”:“Shutting down”,“attr”:{“exitCode”:100}}

Any solution ??

15

Your dbpath dir is missing
Create it and you should be able to start the mongod

1 Like
16

Hi @Neer_Amrutia ,
As mentioned from @Ramachandra_Tummala, you Need to create a dir for data.
Here Is your error

Regards