C# + AD: Dump COM and Use System.DirectoryServices.Protocols with LINQ to Query AD

NOTE: This post – drafted, composed, written, and published by me – originally appeared on https://blogs.technet.microsoft.com/johnbai and is potentially (c) Microsoft.

A while back, I posted about using ADSI COM to get the data that you wanted. I want to show you how you can do this 10 times faster, using System.DirectoryServices.Protocols and LINQ.

Class for the actual AD query being performed:

    /// <summary>
    /// Initializes a new instance of the <see cref="LdapSearcher"/> class.
    /// </summary>
    internal class LdapSearcher
    {
        /// <summary>
        /// Initializes a new instance of the <see cref="SearchTheForestTask"/> method.
        /// </summary>
        /// <param name="filter">The filter to use for the LDAP query.</param>
        /// <param name="sizeLimit">The limit of return objects for the query.</param>
        /// <param name="configContainer"></param>
        /// <returns></returns>
        public static async Task<SearchResponse> SearchTheForestTask(string filter, int? sizeLimit, bool configContainer)
        {
            // More information on the return statement can be found here: https://msdn.microsoft.com/en-us/library/1h3swy84.aspx
            // More information on the async/await keywords can be found here: https://msdn.microsoft.com/en-us/library/hh191443.aspx
            // More information on the Task<TResult>.Run() method can be found here: https://msdn.microsoft.com/en-us/library/hh160382(v=vs.110).aspx
            return await Task.Run(async /* Run on asynchronous thread so we don't block. */
                () =>
                {
                    // More information on the return statement can be found here: https://msdn.microsoft.com/en-us/library/1h3swy84.aspx
                    // More information on the async/await keywords can be found here: https://msdn.microsoft.com/en-us/library/hh191443.aspx
                    // More information on the Task<TResult>.Run() method can be found here: https://msdn.microsoft.com/en-us/library/hh160382(v=vs.110).aspx
                    return await Task.Run(() => SearchTheForest(filter, sizeLimit, configContainer));
                });
        }

        /// <summary>
        /// Initializes a new instance of the <see cref="SearchTheForest"/> method.
        /// </summary>
        /// <param name="filter">The filter to use for the LDAP query.</param>
        /// <param name="sizeLimit">The limit of return objects for the query.</param>
        /// <param name="configContainer"></param>
        /// <returns></returns>
        private static SearchResponse SearchTheForest(string filter, int? sizeLimit, bool configContainer)
        {
            string targetServer = Domain.GetComputerDomain().FindDomainController().Name;

            // We can't await a Task to get RootDSE via async or it may execute AFTER we need it.
            DirectoryEntry rootDse = new DirectoryEntry("LDAP://RootDSE")
            {
                // More information on the DirectoryEntry.AuthenticationType property can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.directoryentry.authenticationtype(v=vs.110).aspx
                // More information on the AuthenticationTypes enumeration can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.authenticationtypes(v=vs.110).aspx
                AuthenticationType = AuthenticationTypes.Encryption
            };

            string searchRoot = AdMethods.GetSearchRootTask(rootDse, configContainer).Result;

            // We instantiate the object to clear data.
            Ad.NewSearchResponse = null;

            // If the size limit isn't defined, we set it to 1k.
            int pageSize = sizeLimit ?? 1000;

            // We specify the page size so that we don't break all the things.
            // More information on the PageResultRequestControl class can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.pageresultrequestcontrol(v=vs.100).aspx
            PageResultRequestControl newPageResultRequestControl = new PageResultRequestControl(pageSize);

            // We include deleted objects in the search.
            // More information on the ShowDeletedControl class can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.showdeletedcontrol(v=vs.110).aspx
            ShowDeletedControl newShowDeletedControl = new ShowDeletedControl();
            
            // Establish connection to the Directory.
            LdapConnection newLdapConnection = new LdapConnection(targetServer);

            // Create the Search Request.
            // More information on the SearchRequest class be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchrequest(v=vs.110).aspx
            SearchRequest newSearchRequest = new SearchRequest
            {
                // More information on the SearchRequest.Filter property can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchrequest.filter(v=vs.110).aspx
                Filter = filter,

                // We specify the search root for the query. Don't let the documentation lie to you,
                // this property does not specify the object to query FOR.
                // More information on the SearchRequest.DistinguishedName property can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchrequest.distinguishedname(v=vs.110).aspx
                DistinguishedName = searchRoot,

                // More information on the SearchRequest.Scope property can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchrequest.scope(v=vs.110).aspx
                // More information on the SearchScope enumeration can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.searchscope(v=vs.110).aspx
                Scope = System.DirectoryServices.Protocols.SearchScope.Subtree,

                // More information on the SearchRequest.TimeLimit property can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchrequest.timelimit(v=vs.110).aspx
                TimeLimit = TimeSpanConstants.OneMinuteTimeSpan,

                // More information on the SearchRequest.RequestId property can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.directoryrequest.requestid(v=vs.110).aspx
                RequestId = GuidConstants.RequestGuid.ToString(),

                // More information on the SearchRequest.Aliases property can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchrequest.aliases(v=vs.110).aspx
                // More information on the DereferenceAlias enumeration can be found there: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.dereferencealias(v=vs.100).aspx
                Aliases = System.DirectoryServices.Protocols.DereferenceAlias.Never,

                // More information on the SearchRequest.TypesOnly property can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchrequest.typesonly(v=vs.110).aspx
                TypesOnly = false,

                // More information on the SearchRequest.Controls property can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.directoryrequest.controls(v=vs.110).aspx
                Controls = { newPageResultRequestControl, newShowDeletedControl }
            };
            if (sizeLimit.HasValue)
            {
                // More information on the SearchRequest.SizeLimit property can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchrequest.sizelimit(v=vs.110).aspx
                newSearchRequest.SizeLimit = sizeLimit.Value;
            }

            // Since we're entering a critical section, let's lock so we block further calls.
            // More information on the lock keyword can be found here: https://msdn.microsoft.com/en-us/library/c5kehkcz.aspx
            lock (ObjectConstants.NewLock)
            {
                // Enter the critical section.
                // More information on the try keyword can be found here: https://msdn.microsoft.com/en-us/library/6dekhbbc.aspx
                try
                {
                    // More information on the SearchResponse class can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchresponse(v=vs.110).aspx
                    // More information on the LdapConnection.SendRequest(DirectoryRequest) method can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.ldapconnection.sendrequest(v=vs.110).aspx
                    Ad.NewSearchResponse = (SearchResponse) newLdapConnection.SendRequest(newSearchRequest, TimeSpanConstants.OneMinuteTimeSpan);
                }
                catch (LdapException exception)
                {
                    // We throw the base exception so it can be unwound by the calling thread.
                    // More information on the Exception.GetBaseException() method can be found here: https://msdn.microsoft.com/en-us/library/system.exception.getbaseexception(v=vs.110).aspx
                    throw exception.GetBaseException();
                }
            }

            // Since we need to await completion, we pass a value back.
            // More information on the return statement can be found here: https://msdn.microsoft.com/en-us/library/1h3swy84.aspx
            return Ad.NewSearchResponse;
        }
    }

The real magic – taking the return and using LINQ:

           // More information on the TaskFactory class can be found here: https://msdn.microsoft.com/en-us/library/system.threading.tasks.taskfactory(v=vs.110).aspx
            TaskFactory<SearchResponse> newTaskFactory = new TaskFactory<SearchResponse>();

            // More information on the using statement can be found here: https://msdn.microsoft.com/en-us/library/yh598w02.aspx
            // More information on the Task<TResult> class can be found here: https://msdn.microsoft.com/en-us/library/dd321424(v=vs.110).aspx
            // More information on the TaskFactory.StartNew(Action) method can be found here: https://msdn.microsoft.com/en-us/library/dd321439(v=vs.110).aspx
            using (Task<SearchResponse> newTask = newTaskFactory.StartNew(() => LdapSearcher.SearchTheForestTask(filter, null, false).Result))
            {
                // More information on the TaskAwaiter<TResult> class can be found here: https://msdn.microsoft.com/en-us/library/hh138386(v=vs.110).aspx
                // More information on the Task.GetAwaiter() method can be found here: https://msdn.microsoft.com/en-us/library/system.threading.tasks.task.getawaiter(v=vs.110).aspx
                TaskAwaiter<SearchResponse> newTaskAwaiter = newTask.GetAwaiter();

                // More information on the TaskAwaiter.IsCompleted property can be found here: https://msdn.microsoft.com/en-us/library/system.runtime.compilerservices.taskawaiter.iscompleted(v=vs.110).aspx
                while (!newTaskAwaiter.IsCompleted)
                {
                    // More information on the string.Format() method can be found here: https://msdn.microsoft.com/en-us/library/system.string.format(v=vs.110).aspx
                    this.WriteDebug(string.Format("Awaiting task with id'{0}' to finish.", newTask.Id));

                    // Let's wait for task completion.
                    System.Threading.Thread.Sleep(500);
                }

                // More information on the TaskAwaiter.IsCompleted property can be found here: https://msdn.microsoft.com/en-us/library/system.runtime.compilerservices.taskawaiter.iscompleted(v=vs.110).aspx
                if (newTaskAwaiter.IsCompleted)
                {
                    // More information on the string.Format() method can be found here: https://msdn.microsoft.com/en-us/library/system.string.format(v=vs.110).aspx
                    this.WriteDebug(string.Format("Task with Id '{0}' completed.", newTask.Id));

                    // More information on the Task.IsFaulted property can be found here: https://msdn.microsoft.com/en-us/library/system.threading.tasks.task.isfaulted(v=vs.110).aspx
                    if (!newTask.IsFaulted)
                    {
                        // More information on the TaskAwaiter.GetResult() method can be found here: https://msdn.microsoft.com/en-us/library/system.runtime.compilerservices.taskawaiter.getresult(v=vs.110).aspx
                        newTaskAwaiter.GetResult();

                        // More information on the SearchResultEntryCollection class can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchresultentrycollection(v=vs.110).aspx
                        SearchResultEntryCollection newSearchResultEntryCollection = Ad.NewSearchResponse.Entries;

                        // More information on the SearchResultEntry class can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchresultentry(v=vs.110).aspx
                        SearchResultEntry newSearchResultEntry = newSearchResultEntryCollection[0];

                        // More information on the SearchResultAttributeCollection class can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchresultattributecollection(v=vs.110).aspx
                        SearchResultAttributeCollection newSearchResultAttributeCollection = newSearchResultEntry.Attributes;

                        // Validate we don't hit the System.NullReferenceException
                        // More information on the SearchResultAttributeCollection.Values property can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchresultattributecollection.values(v=vs.110).aspx
                        if (newSearchResultAttributeCollection.Values != null)
                        {
                            // To save overhead from iterating through each attribute on the object, we need to convert it into a queryable.
                            // This takes some magic but the overall result is the same data, just slightly faster.

                            // More information on the SearchResultAttributeCollection.Values property can be found here: https://msdn.microsoft.com/en-us/library/system.directoryservices.protocols.searchresultattributecollection.values(v=vs.100).aspx
                            ICollection newCollection = newSearchResultAttributeCollection.Values;

                            // More information on the Enumerable.Cast<TResult>() method can be found here: https://msdn.microsoft.com/en-us/library/bb341406(v=vs.110).aspx
                            IEnumerable newDirectoryAttributesCollection = newCollection.Cast<DirectoryAttribute>();

                            // More information on the Queryable.AsQueryable() method can be found here: https://msdn.microsoft.com/en-us/library/bb353734(v=vs.110).aspx
                            IQueryable<DirectoryAttribute> newQueryable = (IQueryable<DirectoryAttribute>) newDirectoryAttributesCollection.AsQueryable();

                            // More information on the Where() method can be found here: https://msdn.microsoft.com/en-us/library/bb546161.aspx
                            // More information on the Select() method can be found here: https://msdn.microsoft.com/en-us/library/bb546168.aspx
                            IQueryable<object[]> newQueryableObjectUno = newQueryable.Where(x => x.Name.Equals("msExchMailboxSecurityDescriptor")).Select(x => x.GetValues(typeof (byte[])));

                            // More information on the FirstOrDefault() method can be found here: https://msdn.microsoft.com/en-us/library/bb546140.aspx
                            object[] newObjectsUno = newQueryableObjectUno.FirstOrDefault();

                            // If the data is null, we went wrong somewhere but it's best to prevent System.NullReferenceException.
                            if (newObjectsUno != null)
                            {
                                byte[] newByteArrayBytes = (byte[]) newObjectsUno[0];

                                // We decode the string.
                                CommonSecurityDescriptor newCommonSecurityDescriptor = new CommonSecurityDescriptor(true, true, newByteArrayBytes, 0);
                                string attrValue = newCommonSecurityDescriptor.GetSddlForm(AccessControlSections.All);

                                this.WriteObject(attrValue);
                            }
                        }
                    }
                }
            }

While this isn’t quite straight-forward, what’s happening is that we’re obtaining all of the properties for the object in AD, in byte format, and then performing a select against the specific property that we want to see.

Happy coding! šŸ™‚

Debugging: When Recursive NDRs Bring the FSC to It’s Knees And Causes Queuing

NOTE: This post – drafted, composed, written, and published by me – originally appeared on https://blogs.technet.microsoft.com/johnbai and is potentially (c) Microsoft.

A while back (circa July 2015), we had alerting for queuing for a Dedicated customer. When we went and looked, the messages were just sitting in the Submission queue.

We dumped the EdgeTransport process and I cracked it open. When I looked at the dump, only 4 threads were at or above 30 frames and those threads had the same stack[s] (redacted for readability):

# Child-SP          RetAddr           Call Site
00 00000000`3587d298 000007fe`ff2e74f6 ntdll!ZwAlpcSendWaitReceivePort+0xa
01 00000000`3587d2a0 000007fe`ff2e1c32 rpcrt4!LRPC_CCALL::SendReceive+0x156
02 00000000`3587d360 000007fe`fdf228c0 rpcrt4!I_RpcSendReceive+0x42
03 00000000`3587d390 000007fe`fdf2282f ole32!ThreadSendReceive+0x40
04 00000000`3587d3e0 000007fe`fdf2265b ole32!CRpcChannelBuffer::SwitchAptAndDispatchCall+0xa3
05 00000000`3587d480 000007fe`fddddaaa ole32!CRpcChannelBuffer::SendReceive2+0x11b
06 00000000`3587d640 000007fe`fdddda0c ole32!CAptRpcChnl::SendReceive+0x52
07 00000000`3587d710 000007fe`fdf2205d ole32!CCtxComChnl::SendReceive+0x68
08 00000000`3587d7c0 000007fe`ff38fd61 ole32!NdrExtpProxySendReceive+0x45
09 00000000`3587d7f0 000007fe`fdf1f82f rpcrt4!NdrpClientCall2+0x9ea
0a 00000000`3587df60 000007fe`fdddd8a2 ole32!ObjectStublessClient+0x1ad
0b 00000000`3587e2f0 000007fe`f839a8b7 ole32!ObjectStubless+0x42
0c 00000000`3587e340 000007ff`0042901d mscorwks!DoCLRToCOMCall+0x177
0d 00000000`3587e3f0 000007ff`00424efc DomainBoundILStubClass.IL_STUB(System.Object, UInt32, UInt32 ByRef, UInt32 ByRef, System.Array ByRef)+0x15d
0e 00000000`3587e540 000007ff`001af3ec FSEAgent_8_0_685!Antigen.Scanner.Scan()+0x45c
0f 00000000`3587e640 000007fe`f74f2bbb FSEAgent_8_0_685!Antigen.Scanner.ScannerThread()+0x13c
10 00000000`3587e6e0 000007fe`f758aadd mscorlib_ni!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)+0x9b
11 00000000`3587e730 000007fe`f839c6a2 mscorlib_ni!System.Threading.ThreadHelper.ThreadStart()+0x4d
12 00000000`3587e780 000007fe`f825ff03 mscorwks!CallDescrWorker+0x82
13 00000000`3587e7d0 000007fe`f877a291 mscorwks!CallDescrWorkerWithHandler+0xd3
14 00000000`3587e870 000007fe`f81c37b9 mscorwks!MethodDesc::CallDescr+0x2b1
15 00000000`3587eab0 000007fe`f831d298 mscorwks!ThreadNative::KickOffThread_Worker+0x191
16 00000000`3587edd0 000007fe`f8230945 mscorwks!ManagedThreadBase_DispatchInner+0x2c
17 00000000`3587ee20 000007fe`f81fe52d mscorwks!ManagedThreadBase_DispatchMiddle+0x9d
18 00000000`3587eef0 000007fe`f835a2b5 mscorwks!ManagedThreadBase_DispatchOuter+0x31
19 00000000`3587ef30 000007fe`f832825b mscorwks!ManagedThreadBase_FullTransitionWithAD+0x35
1a 00000000`3587ef90 000007fe`f8320134 mscorwks!ThreadNative::KickOffThread+0xd3
1b 00000000`3587f070 00000000`779959dd mscorwks!Thread::intermediateThreadProc+0x78
1c 00000000`3587fc40 00000000`77aca651 kernel32!BaseThreadInitThunk+0xd
1d 00000000`3587fc70 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

All of those aforementioned threads were passing to COM:

!findstack mscorwks!DoCLRToCOMCall
Thread 064, 1 frame(s) match
        * 12 000000003587e3e0 000007ff0042901d mscorwks!DoCLRToCOMCall+0x177

Thread 066, 1 frame(s) match
        * 12 0000000051cfe240 000007ff0042901d mscorwks!DoCLRToCOMCall+0x177

Thread 068, 1 frame(s) match
        * 12 0000000051dfddb0 000007ff0042901d mscorwks!DoCLRToCOMCall+0x177

Thread 070, 1 frame(s) match
        * 12 000000005205e250 000007ff0042901d mscorwks!DoCLRToCOMCall+0x177

And the messages that were being processed were NDRs that have been around the block or two (sorry for the wall of text):

0:064> !mdt 00000000e074c8b0
00000000e074c8b0 (System.String) Length=12515, String="Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undelivered Mail Returned to Sender"
0:070> !mdt 0000000100776d88
0000000100776d88 (System.String) Length=11719, String="Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Undeliverable: Delayed Mail (still being retried)"

The message details (in redacted form) were:

0:064> !mdt 0000000081097f30
0000000081097f30 (Antigen.AntigenMessage)
    m_folder:00000000810a01f0 (System.String) Length=36, String="C:\forefront\data\\Archive\Internal\"
    m_fileObject:0x250e0 (System.UInt32)
    m_bcc:00000000e0754c50 (System.String) Length=43, String="<recipient>;"
    m_flags:0x0 (System.Int32)
    m_smtpSenderAddress:00000000907eb738 (System.String) Length=21, String=""Sender""
    m_smtpExternalIP:NULL (System.String)
    m_onlyTreatIfPurge:0x0 (System.UInt32)
    m_isSystemMessage:0x1 (System.UInt32)
    m_smtpExternalHostName:NULL (System.String)
    m_MessageDateTimeReceived:00000000e0754990 (System.String) Length=20, String="2015-07-21T08:41:46Z"
    m_MessageDateTimeSent:00000000e07549d8 (System.String) Length=20, String="2015-07-21T08:26:23Z"
    m_EHSBypassVirusScan:0x0 (System.UInt32)
    m_PremiumEngineSet:0x0 (System.UInt32)
    m_IsTransportDecrypted:0x0 (System.UInt32)
    m_ReplayHeaders:00000000810a0428 (System.String) Length=172, String="X-Receiver: <recipient> ORCPT=rfc822;<recipient>
X-Sender: <sender>
X-CreatedBy: MSExchange12"

When I checked message tracking, this was a partial indicator of what introduced the problem:

$msgTrk = @()
$hubz = Get-TransportServer
foreach($hub in $hubz)
{
     $msgTrk += Get-MessageTrackingLog -Server $hub.Name -Recipients <recipient> -ResultSize Unlimited
}

$msgTrk.Count
1491474

In the words of Strongbad, “That is not a small number! That’s a very big number!

This was a limitation in the Forefront hook in Transport that caused it to consume a lot of resources on the heap, which was exacerbated by a mail-storm from the customer’s on-premises.

Debugging: Incremental Mailbox Sync Move Requests Cause ‘StopAll’ to be called on the Assistants Infrastructure Which Causes CalendarNotificationAssistant to Stop Processing Text Message (SMS) Notifications

NOTE: This post – drafted, composed, written, and published by me – originally appeared on https://blogs.technet.microsoft.com/johnbai and is potentially (c) Microsoft.

Not too long ago, I debugged an issue with the Calendar Notification Assistant (CNA), wherein the Assistant would stop processing text message (SMS) notifications for events. The affected end-users noted that if they enabled text message (SMS) notifications in Outlook Web Access (OWA), the notifications would work for around 24 hours and then they would fall back into reproduction of the issue, in which the notifications stop altogether.

When I went looking in PowerShell, I could verify (via the Admin Audit Log) that the commands to set the configuration for SMS were ran and that it was enabled:

Search-AdminAuditLog -Cmdlets Set-TextMessagingAccount | Where{$_.ObjectModified -contains '<objectId>'} | FL


RunspaceId         : c7683058-b25c-4557-818d-546cf5f178c6
ObjectModified     : <objectId>
CmdletName         : Set-TextMessagingAccount
CmdletParameters   : {CountryRegionId, MobileOperatorId, NotificationPhoneNumber, Identity}
ModifiedProperties : {}
Caller             : <callerObjectId>
ExternalAccess     :
Succeeded          : True
Error              : None
RunDate            : 12/22/2015 1:15:17 PM
OriginatingServer  : <serverName>
Identity           : <identity>
IsValid            : True
ObjectState        : New

We could also see the messages being sent via the Message Tracking Log (MTL):

$MsgTrk | Sort TimeStamp | FT EventId,Source,Sender,Recipients,MessageSubject,TimeStamp -AutoSize

EventId Source      Sender                       Recipients                                  MessageSubject 	Timestamp
------- ------      ------                       ----------                                  -------------- 	---------
RECEIVE STOREDRIVER <senderEmailAddress> 	{[email protected]}                		12/17/2015 13:18:34
SEND    AGENT       <senderEmailAddress> 	{[email protected]}                		12/17/2015 13:18:34
RECEIVE STOREDRIVER <senderEmailAddress> 	{[email protected]}                		12/17/2015 13:19:46
SEND    AGENT       <senderEmailAddress> 	{[email protected]}                		12/17/2015 13:19:46
RECEIVE STOREDRIVER <senderEmailAddress> 	{[email protected]}                		12/17/2015 16:15:02
SEND    AGENT       <senderEmailAddress> 	{[email protected]}                		12/17/2015 16:15:02

Using this, I could tell the originator of the message: The Mailbox Assistants. This was done by the seeing that the client and the server were the same:

$MsgTrk[0] | FL


RunspaceId              : 13ad4581-25d9-4136-8ed1-a284b7e979db
Timestamp               : 12/21/2015 15:40:31
ClientIp                : <ipAddress>
ClientHostname          : <serverName>
ServerIp                : <ipAddress>
ServerHostname          : <serverName>
SourceContext           : 08D30340C2F43943
ConnectorId             :
Source                  : STOREDRIVER
EventId                 : RECEIVE
InternalMessageId       : 2429739
MessageId               : <messageId>
Recipients              : {[email protected]}
RecipientStatus         : {To}
TotalBytes              : 6386
RecipientCount          : 1
RelatedRecipientAddress :
Reference               :
MessageSubject          :
Sender                  : <emailAddress>
ReturnPath              : <emailAddress>
MessageInfo             : 04I:
MessageLatency          :
MessageLatencyType      : None
EventData               : {[MailboxDatabaseGuid, 347a971c-e8f5-45de-8e01-870ed4dc6901], [ItemEntryId, 00-00-00-00-1E-95-32-44-0A-EA-D6-47-A5-98-9B-F0-5F-89-B9-09-07-00-BE-9B-24-68-00-23-66-49-95-41-BB-56-C6-02-E3-D0-00-00-00-03-71-5C-00-00-75-FB-A6-9E-77-CF-BE-43-A8-2A-B9-7F-C1-34-9A-01-00-00-1C-C-91-D1-00-00]}

Once I knew this, I checked the Database Event Watermarks for any backlog:

<databaseName>\<serverName> CalendarNotificationAssistant             977234167 989106153    11871986

I now had enough data to assert that a dump of the process was necessary in order to see what’s going on.

At the time of the dump, despite the fact that the user was no longer receiving text message (SMS) notifications, the process was processing (for lack of a better turn-of-phrase at the moment) a two week old message in thread 21 in the stack:

0:021> !mdt 00000000036e1088
00000000036e1088 (Microsoft.Exchange.MailboxAssistants.Assistants.CalendarNotification.CalendarEvent)
    <CalendarItemIdentity>k__BackingField:00000000036e1208 (Microsoft.Exchange.Data.Storage.StoreObjectId)
    <CalendarItemOccurrenceIdentity>k__BackingField:00000000036e1048 (Microsoft.Exchange.Data.Storage.OccurrenceStoreObjectId)
    <CalendarItemType>k__BackingField:0x1 (Microsoft.Exchange.Data.Storage.CalendarItemType)
    <NormalizedSubject>k__BackingField:00000000036e0880 (System.String) Length=5, String="Lunch"
    <Location>k__BackingField:00000000036e0860 (System.String) 
    <ReminderIsSet>k__BackingField:true (System.Boolean)
    <ReminderTime>k__BackingField:(Microsoft.Exchange.ExchangeSystem.ExDateTime) VALTYPE (MT=000007ff002c5cb0, ADDR=00000000036e10d0)
    <ReminderMinutesBeforeStart>k__BackingField:0xf (System.Int32)
    <StartTime>k__BackingField:(Microsoft.Exchange.ExchangeSystem.ExDateTime) VALTYPE (MT=000007ff002c5cb0, ADDR=00000000036e10f0)
    <EndTime>k__BackingField:(Microsoft.Exchange.ExchangeSystem.ExDateTime) VALTYPE (MT=000007ff002c5cb0, ADDR=00000000036e1110)
    <FreeBusyStatus>k__BackingField:0x2 (Microsoft.Exchange.Data.Storage.BusyType)
    <ChangeHighlight>k__BackingField:0x0 (Microsoft.Exchange.Data.Storage.ChangeHighlightProperties)
    <AppointmentState>k__BackingField:0x0 (Microsoft.Exchange.Data.Storage.AppointmentStateFlags)
    <CreationRequestTime>k__BackingField:(Microsoft.Exchange.ExchangeSystem.ExDateTime) VALTYPE (MT=000007ff002c5cb0, ADDR=00000000036e1130)
    <ResponseType>k__BackingField:0x0 (Microsoft.Exchange.Data.Storage.ResponseType)
    <OldStartTime>k__BackingField:(System.Nullable`1) VALTYPE (MT=000007fef6207cc8, ADDR=00000000036e1150)
    <OldEndTime>k__BackingField:(System.Nullable`1) VALTYPE (MT=000007fef6207cc8, ADDR=00000000036e1178)

We can see the date of the item from the backing field:

0:021> !mdt 000007ff002c5cb0 00000000036e10d0
(Microsoft.Exchange.ExchangeSystem.ExDateTime) VALTYPE (MT=000007ff002c5cb0, ADDR=00000000036e10d0)
    timeZone:00000000014bb040 (Microsoft.Exchange.ExchangeSystem.ExTimeZone)
    universalTime:(System.DateTime) 2015/12/23 16:15:00.000 VALTYPE (MT=000007fef62482d0, ADDR=00000000036e10d8)
    localTime:(System.Nullable`1) VALTYPE (MT=000007fef6207cc8, ADDR=00000000036e10e0)

And we can see that it’s processing the item for the same user that lodged the complaint:

0:021> !mdt 0000000003761ad0
0000000003761ad0 (System.String) Length=129, String="<sameUserFromAbove>"

Finally, after perusing the dump for an hour or more, I found what I believed to be introducing the issue:

<ContextInfo>k__BackingField:00000000032fe908 (System.String) Length=7, String="StopAll"

Given this, it was time to go to the devs and figure out what was going on. After some back-and-forth and a conference call with both the Store and Calendaring devs, we arrived at what was causing the issue.

First, it’s important to understand that an incremental sync was created for the user but had not – as of the time of debugging – been completed:

Get-MoveRequestStatistics 957ca0a9-f84f-425e-a263-5b468e90d574 | FL *increm*


EffectiveIncrementalSyncInterval  : 1.00:00:00
ConfiguredIncrementalSyncInterval : 1.00:00:00

Since it syncs once a day, this aligns with the end-user’s statement regarding reconfiguration but we needed proof.

When we went and looked at the Mailbox Database Events for the mailbox in question, we saw the ‘MailboxMoveStarted’ event fire:

$eventz | FT Counter,ItemType,EventName,ObjectClass,Mailbox,CreateTime -AutoSize

  Counter ItemType   EventName          ObjectClass Mailbox CreateTime
  ------- --------   ---------          ----------- ------- ----------
974015558 MAPI_STORE MailboxMoveStarted                     1/25/2016 21:32:01
974683553 MAPI_STORE MailboxMoveStarted                     1/26/2016 21:41:10
975414298 MAPI_STORE MailboxMoveStarted                     1/27/2016 21:44:00
976136834 MAPI_STORE MailboxMoveStarted                     1/28/2016 21:52:10
976842768 MAPI_STORE MailboxMoveStarted                     1/29/2016 22:02:30
977056359 MAPI_STORE MailboxMoveStarted                     1/30/2016 22:03:45
977195259 MAPI_STORE MailboxMoveStarted                     1/31/2016 22:15:01

What’s important to note as a side-comment/take-away is that the 24-hour interval doesn’t initiate from the same start time. This is because the counter for the 24-hour interval starts when the last sync stopped.

When we matched this against a trace of the Assistant, we saw the following:

"2016/01/13-03:06:05.279","9444","2480","Assistants","EventDispatcher","Dispatcher for <userDisplayName> (957ca0a9-f84f-425e-a263-5b468e90d574) and Calendar Notification Assistant: Event handled successfully: Counter: 0x3B331E14; MailboxID: 957ca0a9-f84f-425e-a263-5b468e90d574; Mask: MailboxMoveStarted; Flags: Source; ExtendedFlags: None;Object Class: ; Created Time: 1/13/2016 11:06:04 AM;Item Type: MAPI_STOREItem EntryId: Parent entryId: Old Item entryId: Old parent entryId: SID: S-1-5-21-276227223-3107228690-1043224028-159164Client Type: MigrationDocument ID: 0" 
"85868820"        020B591B          Debug 2016/01/13-02:01:49.777 9444     2480            MailboxAssistants.Assistants.CalendarNotification Assistant           rmd----- caller: StopAll, subj: <subject>, usr: <objectId>c1, calItemId: RgAAAAAelTJECurWR6WYm/BfibkJBwC+myRoACNmSZVBu1bGAuPQAAAAA3FaAAB1+6aed8++Q6gquX/BNJoBAAAcyVmOAAAP, calItemOccId: , event_t: 01/13/2016 16:15:00, rmd_t: 01/13/2016 19:45:00, s_t: 01/13/2016 20:00:00, e_t: 01/13/2016 21:30:00
"8326743"         006B5AB0          Debug 2016/01/13-03:06:05.277 9444     2480            MailboxAssistants.Assistants.CalendarNotification UserSettings      Processing Disabling event for mailbox <objectId> on database 347a971c-e8f5-45de-8e01-870ed4dc6901

To elaborate on this bug and explain it further: Recall back in Exchange 2007 (E12) that mailbox moves caused the mailbox to be locked. When this occurred, it would’ve been necessary for any code that attempts to open the message store to stop processing the mailbox until the move is complete. Fast-forward a few years (nigh to a decade) and incremental sync move requests are a common, every day occurrence. When the incremental sync starts, there is no delineation between it and a regular move request, so a database event fires and this signals the assistant to stop processing the mailbox. When the text message (SMS) notification is reconfigured, it signals the Assistant to start processing on the mailbox. This explains the behavior seen by the end-users.

For those of you concerned about hitting this bug in the wild, we’ve only see it happen once and we’re using that instance to drive a change in the Assistant logic in all versions of Exchange (assuming all have the same bug in the logic).

PowerShell + C#: Accessing the Current Runspace And Adding a Snap-In

NOTE: This post – drafted, composed, written, and published by me – originally appeared on https://blogs.technet.microsoft.com/johnbai and is potentially (c) Microsoft.

I’ve been coding an assembly for import into the Exchange Management Shell (EMS) in C# for some time. One of the problems that I ran into was how to load the Support assembly, since it’s not imported into the RunSpace by default. After a while of testing/trying/failing and repeat ad nauseam, I found the answer in the form of what I consider to be a cheat.

You see, when the module is loaded, I’m depending on the current runspace as it exists to execute commands. There’s no proper way to access the runspace that you’re currently executing to modify it’s configuration by adding the snap-in.

So, we arrive at the “cheat”:

// We use the current runspace to cast our calls into.
// This grants us access to the current runspace, instead of instantiating a new one.
// More information on the PowerShell.Create method can be found here: https://msdn.microsoft.com/en-us/library/system.management.automation.powershell.create(v=vs.85).aspx
// More information on the RunspaceMode.CurrentRunspace enumeration value can be found here: https://msdn.microsoft.com/en-us/library/system.management.automation.runspacemode(v=vs.85).aspx
PowerShell initialPowerShell = PowerShell.Create(RunspaceMode.CurrentRunspace);

// More information on the PowerShell.AddScript method can be found here: https://msdn.microsoft.com/en-us/library/dd182436(v=vs.85).aspx
initialPowerShell.Commands.AddScript("Add-PSSnapin Microsoft.Exchange.Management.Powershell.Support");

// More information on the PowerShell.Invoke method can be found here: https://msdn.microsoft.com/en-us/library/dd182449(v=vs.85).aspx
initialPowerShell.Invoke();

If you’re wondering about the code comments: One of the ways that people learn is by searching for examples or questions related to the problem they’re trying to solve. This is something that I – admittedly – used to do. Once they find what they think might be the answer, they look at the methods/class in the documentation (at least, that’s what I used to do). So, I figured why not shorten the effort down for those who want to learn? šŸ™‚