MailService.exe high memory usage

Problem reported by Mark Thornton - 2/24/2023 at 12:46 PM

Submitted

I'm running running Build 8451 that I upgraded to on Tuesday, February 21. Today my mail server became very sluggish, crashing desktop clients, etc. I logged into the mail server itself and found the mailservice.exe process had consumed all 20 GB of available memory. I stopped the service then restarted it and am watching the memory climb up to 8 GB and now seems to be leveling off there. Where should I look in the logs to determine what was consuming all the memory?

15 Replies

Reply to Thread

Gabriele Maoret - SERSIS Replied

2/24/2023 at 9:25 PM

I'm seeing similar memory issues in SmarterMail after update to Build 8451.

Maybe can this be a bug in this build?

Gabriele Maoret - Head of SysAdmins at SERSIS Currently manages 6 SmarterMail installations (1 in the cloud for SERSIS which provides services to a few hundred third-party email domains + 5 on-premise for customers who prefer to have their mail server in-house)

Mark Thornton Replied

2/26/2023 at 12:30 PM

I'm checking back in on my server and it has been running between 6 and 8 GB of RAM used by mailserver.exe since I restarted the service. Still don't know what sent it over the edge before.

mh Replied

3/2/2023 at 1:13 PM

8251, same issues in the past few weeks. Either related to a search bug (seems to happen possibly after a global search rather than just a specific folder) or a windows update is causing issues somewhere. Doesn't happen often, but it will climb and client connections will time out

Kyle Kerst Replied

3/2/2023 at 3:40 PM

Employee Post

Do any of you have anything being reported with exception in the log entry under the Error or protocol logs?

Kyle Kerst IT Coordinator SmarterTools Inc. www.smartertools.com

mh Replied

3/3/2023 at 9:21 AM

This was at the time (~2:30-2:53pm was the issue) that the service had just been restarted in Administrative logs, all for the same user -

[2023.03.02] 14:53:00.699 [Folder Delete:SearchFolder] [User: ---] [FolderId: 2070048] [DisplayName: 2422385f-f9fc-4896-be61-666b69cf7307] Stack:    at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)
[2023.03.02] 14:53:00.699 [Folder Delete:SearchFolder] [User: ---] [FolderId: 2070049] [DisplayName: 8bc085ba-2835-4606-8bdc-55612bf73782] Stack:    at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)
[2023.03.02] 14:53:00.720 [Folder Delete:SearchFolder] [User: ---] [FolderId: 2070048] [DisplayName: 2422385f-f9fc-4896-be61-666b69cf7307] Stack:    at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)
[2023.03.02] 14:53:00.720 [Folder Delete:SearchFolder] [User: ---] [FolderId: 2070049] [DisplayName: 8bc085ba-2835-4606-8bdc-55612bf73782] Stack:    at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)
[2023.03.02] 14:53:00.732 [Folder Delete:SearchFolder] [User: ---] [FolderId: 2070048] [DisplayName: 2422385f-f9fc-4896-be61-666b69cf7307] Stack:    at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)
[2023.03.02] 14:53:00.732 [Folder Delete:SearchFolder] [User: ---] [FolderId: 2070049] [DisplayName: 8bc085ba-2835-4606-8bdc-55612bf73782] Stack:    at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)
[2023.03.02] 14:53:00.732 [Folder Delete:SearchFolder] [User: ---] [FolderId: 2070048] [DisplayName: 2422385f-f9fc-4896-be61-666b69cf7307] Stack:    at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)
[2023.03.02] 14:53:00.732 [Folder Delete:SearchFolder] [User: ---] [FolderId: 2070049] [DisplayName: 8bc085ba-2835-4606-8bdc-55612bf73782] Stack:    at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.AsyncThunk.UnhandledExceptionFrame(IAsyncResult result)
[2023.03.02]    at System.Runtime.Fx.IOCompletionThunk.UnhandledExceptionFrame(UInt32 error, UInt32 bytesRead, NativeOverlapped* nativeOverlapped)

Nothing in the "Error" log file

In the IMAP log, around this time -

[2023.03.02] 14:28:55.223 [x.x.x.x][34126772] response: * OK IMAP 
[2023.03.02] 14:28:55.223 [x.x.x.x][34126772] connected at 3/2/2023 2:28:55 PM
[2023.03.02] 14:28:56.051 [x.x.x.x][34126772] command: 1 CAPABILITY
[2023.03.02] 14:28:56.051 [x.x.x.x][34126772] response: * CAPABILITY IMAP4rev1 AUTH=CRAM-MD5 AUTH=PLAIN SASL-IR UIDPLUS QUOTA XLIST CHILDREN ENABLE CONDSTORE IDLE STARTTLS
[2023.03.02] 14:28:56.051 [x.x.x.x][34126772] response: 1 OK CAPABILITY completed
[2023.03.02] 14:28:56.285 [x.x.x.x][34126772] command: 2 AUTHENTICATE PLAIN
[2023.03.02] 14:28:56.285 [x.x.x.x][34126772] response: +
[2023.03.02] 14:28:56.348 [x.x.x.x][34126772] PLAIN message received AGxlYXN0QGZvbW50dC5jb20ATGluZHNleTkx
[2023.03.02] 14:28:56.348 [x.x.x.x][34126772] response: 2 OK PLAIN authentication successful
[2023.03.02] 14:28:56.348 [x.x.x.x][34126772] redacted@domain.com logged in
[2023.03.02] 14:28:56.426 [x.x.x.x][34126772] command: 3 CAPABILITY
[2023.03.02] 14:28:56.426 [x.x.x.x][34126772] response: * CAPABILITY IMAP4rev1 AUTH=CRAM-MD5 AUTH=PLAIN SASL-IR UIDPLUS QUOTA XLIST CHILDREN ENABLE CONDSTORE IDLE STARTTLS
[2023.03.02] 14:28:56.426 [x.x.x.x][34126772] response: 3 OK CAPABILITY completed
[2023.03.02] 14:28:56.551 [x.x.x.x][34126772] command: 4 SELECT INBOX
[2023.03.02] 14:28:56.551 [x.x.x.x][34126772] response: * 1438 EXISTS
[2023.03.02] 14:28:56.551 [x.x.x.x][34126772] response: * 140 RECENT
[2023.03.02] 14:28:56.551 [x.x.x.x][34126772] response: * OK [UNSEEN 1423] Message 1423 is first unseen
[2023.03.02] 14:28:56.551 [x.x.x.x][34126772] response: * OK [UIDVALIDITY 1] UIDs valid
[2023.03.02] 14:28:56.551 [x.x.x.x][34126772] response: * OK [UIDNEXT 9409] Predicted next UID
[2023.03.02] 14:28:56.551 [x.x.x.x][34126772] response: * FLAGS (\Answered \Flagged \Deleted \Seen \Draft \Recent)
[2023.03.02] 14:28:56.551 [x.x.x.x][34126772] response: * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \Recent)] Folder flags
[2023.03.02] 14:28:56.551 [x.x.x.x][34126772] response: 4 OK [READ-WRITE] SELECT completed
[2023.03.02] 14:28:56.707 [x.x.x.x][34126772] command: 5 UID FETCH 9396 BODY.PEEK[2]
[2023.03.02] 14:31:15.375 [x.x.x.x][34126772] response: 5 OK FETCH completed.
[2023.03.02] 14:31:15.375 [x.x.x.x][34126772] Exception: (PooledTcpItem.cs) An established connection was aborted by the software in your host machine
[2023.03.02] 14:31:15.563 [x.x.x.x][34126772] StackTrace:    at System.Net.Sockets.Socket.BeginReceive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags, AsyncCallback callback, Object state)

In the MAPI log -

[2023.03.02] 11:12:38.901 [{7BAB4169-1E04-4A8F-A737-286901F89B64}:848] Exception: System.NullReferenceException: Object reference not set to an instance of an object.
[2023.03.02] 11:13:15.456 [{4C27D1AC-9A26-4547-ADCF-426576886389}:28] Exception: System.NullReferenceException: Object reference not set to an instance of an object.
[2023.03.02] 11:43:34.028 [{396570E5-950A-4FF9-A800-38DE904973ED}:30] Exception: System.Exception: Array copy with negative number -2081 [sizeOfCurrentItem] 34 - 2115
[2023.03.02] 11:43:34.043 [{380084D2-B0EE-428E-B7BD-C90750CC97C0}:15] Exception: System.Exception: Array copy with negative number -5825 [sizeOfCurrentItem] 34 - 5859
[2023.03.02] 12:23:11.784 [{F16A5267-9685-4F3F-8BED-E6D5AD7188F6}:15] Exception: System.NullReferenceException: Object reference not set to an instance of an object.
[2023.03.02] 13:08:05.680 [{253BE6F5-6ABB-45DB-8266-6F02BA965DFA}:15] Exception: System.InvalidOperationException: Collection was modified; enumeration operation may not execute.
[2023.03.02]    at System.ThrowHelper.ThrowInvalidOperationException(ExceptionResource resource)

SMTP Log around this time or hour before -

[2023.03.02] 13:48:11.107 [x.x.x.x][8455836] rsp: 220 x.x.com
[2023.03.02] 13:48:11.107 [x.x.x.x][8455836] connected at 3/2/2023 1:48:11 PM
[2023.03.02] 13:48:11.107 [x.x.x.x][8455836] Country code: US
[2023.03.02] 13:48:11.154 [x.x.x.x][8455836] cmd: EHLO Membership2PC
[2023.03.02] 13:48:11.154 [x.x.x.x][8455836] rsp: 250-x.x.com Hello [x.x.x.x]250-SIZE 139810133250-AUTH LOGIN CRAM-MD5250-STARTTLS250-8BITMIME250-DSN250 OK
[2023.03.02] 13:48:11.200 [x.x.x.x][8455836] cmd: STARTTLS
[2023.03.02] 13:48:11.200 [x.x.x.x][8455836] rsp: 220 Start TLS negotiation
[2023.03.02] 13:48:11.372 [x.x.x.x][8455836] cmd: EHLO Membership2PC
[2023.03.02] 13:48:11.372 [x.x.x.x][8455836] rsp: 250-x.x.com Hello [x.x.x.x]250-SIZE 139810133250-AUTH LOGIN CRAM-MD5250-8BITMIME250-DSN250 OK
[2023.03.02] 13:48:11.419 [x.x.x.x][8455836] cmd: AUTH LOGIN
[2023.03.02] 13:48:11.419 [x.x.x.x][8455836] rsp: 334 VXNlcm5hbWU6
[2023.03.02] 13:48:11.466 [x.x.x.x][8455836] Authenticating as email@domain.com
[2023.03.02] 13:48:11.466 [x.x.x.x][8455836] rsp: 334 UGFzc3dvcmQ6
[2023.03.02] 13:48:11.779 [x.x.x.x][8455836] rsp: 235 Authentication successful
[2023.03.02] 13:48:11.794 [x.x.x.x][8455836] Authenticated as email@domain.com
[2023.03.02] 13:48:11.841 [x.x.x.x][8455836] cmd: MAIL FROM: <email@domain.com>
[2023.03.02] 13:48:11.841 [x.x.x.x][8455836] senderEmail(1): email@domain.com parsed using: <email@domain.com>
[2023.03.02] 13:48:11.841 [x.x.x.x][8455836] rsp: 250 OK <email@domain.com> Sender ok
[2023.03.02] 13:48:11.841 [x.x.x.x][8455836] Sender accepted. Weight: 0. Block threshold: 25. 
[2023.03.02] 13:48:11.888 [x.x.x.x][8455836] cmd: RCPT TO: <email@domain.org>
[2023.03.02] 13:48:11.888 [x.x.x.x][8455836] rsp: 250 OK <email@domain.org> Recipient ok
[2023.03.02] 13:48:11.919 [x.x.x.x][8455836] cmd: DATA
[2023.03.02] 13:48:11.919 [x.x.x.x][8455836] Performing PTR host name lookup for x.x.x.x
[2023.03.02] 13:48:11.919 [x.x.x.x][8455836] PTR host name for x.x.x.x resolved as static-23-244-80-219.oh.x.x.net
[2023.03.02] 13:48:11.935 [x.x.x.x][8455836] rsp: 354 Start mail input; end with <CRLF>.<CRLF>
[2023.03.02] 13:48:12.029 [x.x.x.x][8455836] senderEmail(2): email@domain.com parsed using: <email@domain.com>
[2023.03.02] 13:52:45.250 [x.x.x.x][8455836] rsp: 250 OK
[2023.03.02] 13:52:45.250 [x.x.x.x][8455836] Client socket is disconnected! Disconnect exception encountered: False, IsDisconnected: True, This message will be rejected.
[2023.03.02] 13:52:45.250 [x.x.x.x][8455836] Received message size: 54049 bytes
[2023.03.02] 13:52:45.250 [x.x.x.x][8455836] Successfully wrote to the HDR file. (c:\SmarterMail\Spool\SubSpool2\511769714188.hdr)
[2023.03.02] 13:52:45.250 [x.x.x.x][8455836] Data transfer succeeded, writing mail to 511769714188.eml (MessageID: <008d01d94d37$8a087390$9e195ab0$@x.org>)
[2023.03.02] 13:52:45.250 [x.x.x.x][8455836] disconnected at 3/2/2023 1:52:45 PM

[2023.03.02] 13:58:52.116 [x.x.x.x][35989911] rsp: 220 x.x.com
[2023.03.02] 13:58:52.116 [x.x.x.x][35989911] connected at 3/2/2023 1:58:52 PM
[2023.03.02] 13:58:52.116 [x.x.x.x][35989911] Country code: US
[2023.03.02] 13:58:52.179 [x.x.x.x][35989911] cmd: EHLO localhost.localdomain
[2023.03.02] 13:58:52.179 [x.x.x.x][35989911] rsp: 250-x.x.com [x.x.x.x]250-SIZE 139810133250-AUTH LOGIN CRAM-MD5250-STARTTLS250-8BITMIME250-DSN250 OK
[2023.03.02] 13:58:52.241 [x.x.x.x][35989911] cmd: STARTTLS
[2023.03.02] 13:58:52.241 [x.x.x.x][35989911] rsp: 220 Start TLS negotiation
[2023.03.02] 13:58:52.288 [x.x.x.x][35989911] rsp: 554 Security failure
[2023.03.02] 13:58:52.288 [x.x.x.x][35989911] Exception negotiating TLS session: The secure connection has failed due to an unsupported protocol such as TLS 1.0 or SSL 3.0. A call to SSPI failed, see inner exception..
[2023.03.02] 13:58:52.304 [x.x.x.x][35989911] disconnected at 3/2/2023 1:58:52 PM


[2023.03.02] 14:35:27.062 [x.x.x.x][64639041] rsp: 220 x.x.com
[2023.03.02] 14:35:27.062 [x.x.x.x][64639041] connected at 3/2/2023 2:35:27 PM
[2023.03.02] 14:35:27.062 [x.x.x.x][64639041] Country code: HK
[2023.03.02] 14:35:28.843 [x.x.x.x][64639041] Exception: (PooledTcpItem.cs) An established connection was aborted by the software in your host machine
[2023.03.02] 14:35:30.406 [x.x.x.x][64639041] StackTrace:    at System.Net.Sockets.Socket.BeginReceive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags, AsyncCallback callback, Object state)

Kyle Kerst Replied

3/6/2023 at 9:03 AM

Employee Post

It looks like one of the messages in that user's account is tripping things up. Anything abnormal about the messages in their Inbox? The other error is a pretty standard TLS handshake error, and usually means their client and your server couldn't agree on a TLS version (they have incompatible versions available.) If the user updates that client, and you run the latest Windows Updates and TLS versions on the server; you should be in good shape!

Kyle Kerst IT Coordinator SmarterTools Inc. www.smartertools.com

JerseyConnect Team Replied

3/13/2023 at 12:36 PM

For those of you on 8451, are you still having memory consumption issues or has it stabilized?

Mark Thornton Replied

3/13/2023 at 2:03 PM

I haven't had a repeat of the issue on my server. It has been stable under 8 out of 20 GB since I restarted the server. I suspect it was a bad message that the system couldn't let go of. That used to be a big problem back in the early days of the internet. I remember having to manually edit user mailboxes to cut out messages that wouldn't go through the system.

Patrick Flynn Replied

1/24/2024 at 11:02 AM

I am running version 13.3.5535 on Windows 2012; this has begun recently and just keeps creeping higher and higher until service is unresponsive. Cant find anything in the logs to determine but need a resolution.

Brian Bjerring-Jensen Replied

1/24/2024 at 1:21 PM

Upgrade. Running these old versions is hard to maintain and fix.

Zach Sylvester Replied

1/24/2024 at 1:36 PM

Employee Post

Hi Patrick,

I wanted to let you know that SmarterMail won't install on any version of Windows lower than Windows Server 2012 R2. If you're currently using Windows Server 2012 and it's not the R2 version, then the best option is to upgrade to version 8451 as that should work. However, it's highly recommended that you consider doing an in-place upgrade to at least Windows Server 2016 or migrating to a new server. Please note that since your current environment is unsupported, support will not be able to help you much.

I hope this information is helpful.

Thank you,

Zach Sylvester Software Developer SmarterTools Inc. www.smartertools.com

Patrick Flynn Replied

1/24/2024 at 2:15 PM

I am running on 2012 r2, have been for many years; I recently purchased newest license last month but noticed that the technical requirements for that are 2016 so need to work in getting a new box setup. But in the interim our email users are going nuts with this memory leak type of issue that we cant debug anything from why it occurs.

Tan Replied

1/26/2024 at 6:28 AM

Sounds like potential corruption in files that cause memory leak. Happen to me many times before.

The hardest part is to find which domain so what i do previously is to dettach the folder to find it.

Michael Replied

2/15/2024 at 5:45 PM

Out of no where today, we just got extremely high memory on MaiService.exe

We're on Build 8797 (Feb 1, 2024)

The solution was to stop MaiService for 5 mins. Then restart it.

No strange connections or other information found so far.

Patrick Flynn Replied

2/15/2024 at 6:25 PM

After trying a lot of stuff, determined several domains had unlimited storage and 1 specific user under one of those domains had several emails containing folders holding some very large file sizes and then when indexing would try it would just go go go. Also guessing corruption in some of the files but just wiped the account and havent had problems since.

Back to Community Threads

Please leave this box unchecked

15 Replies

Reply to Thread

Tags

Related Knowledge Base Articles