John Bailey

Microsoft | Service Ops 2 | Exchange | MSFT Corp & O365 Dedicated

Exchange 2013: When the DAG NIC Affects Transport, That Can't Be Good

Exchange 2013: When the DAG NIC Affects Transport, That Can't Be Good

  • Comments 1
  • Likes

In my on-premises Exchange 2013 lab, there was a queue built up to a mailbox:

 

Get-TransportService | Get-Queue | Where{$_.MessageCount -gt 0} | FT -AutoSize

 

Identity      DeliveryType          Status MessageCount Velocity RiskLevel OutboundIPPool NextHopDomain

--------      ------------          ------ ------------ -------- --------- -------------- -------------

Stromkarlen\3 SmtpDeliveryToMailbox Retry  15           0        Normal    0              emea-sweex15-01 store 001

 

What’s interesting about the queue is that it’s specifically delivery to a mailbox but the error associated is a DNS error:

 

Get-Queue "Stromkarlen\3" | Select -ExpandProperty LastError -Unique

451 4.4.0 DNS query failed. The error was: SMTPSEND.DNS.NonExistentDomain; nonexistent domain

 

If I looked at the recipient, we’re targeting the correct store:

 

Get-Message -Queue "Stromkarlen\3" -IncludeRecipientInfo | Select -ExpandProperty Recipients -Unique

 

Address          : Administrator@minvan.se

OutboundIPPool   : 0

Type             : Mailbox

FinalDestination : CN=EMEA-SWEEX15-01 Store 001,CN=Databases,CN=Exchange Administrative Group (FYDIBOHF23SPDLT),CN=Administrative Groups,CN=minvan,CN=Microsoft Exchange,CN=Services,CN=Configuration,DC=minvan,DC=se

Status           : Ready

LastError        : [{LRT=};{LED=400 4.4.7 Message delayed};{FQDN=};{IP=}]

 

 The store was mounted and last log was ~14 minutes ago (from when I was investigating):

 

Get-MailboxDatabaseCopyStatus "EMEA-SWEEX15-01 Store 001" | FT -AutoSize

 

Name                                  Status  CopyQueueLength ReplayQueueLength LastInspectedLogTime ContentIndexState

----                                  ------  --------------- ----------------- -------------------- -----------------

EMEA-SWEEX15-01 Store 001\HYLDA       Healthy 0               0                 8/21/2014 7:25:24 PM Healthy

EMEA-SWEEX15-01 Store 001\STROMKARLEN Mounted 0               0                                      Healthy

 

The address we were sending to is correct:

 

Get-Mailbox Administrator | FL *addr*

 

 

AddressBookPolicy             :

ForwardingAddress             :

ForwardingSmtpAddress         :

OfflineAddressBook            :

JournalArchiveAddress         :

GeneratedOfflineAddressBooks  : {}

AddressListMembership         : {\Mailboxes(VLV), \All Mailboxes(VLV), \All Recipients(VLV), \Default Global Address List, \All Users}

EmailAddresses                : {smtp:Administrator@minvan.mail.onmicrosoft.com, SMTP:Administrator@minvan.se}

HiddenFromAddressListsEnabled : False

EmailAddressPolicyEnabled     : True

PrimarySmtpAddress            : Administrator@minvan.se

WindowsEmailAddress           : Administrator@minvan.se

 

In the connectivity log (Mailbox), I see the following:

 

2014-08-21T19:40:58.639Z,08D187F0D08C4E37,MapiDelivery,EMEA-SWEEX15-01 Store 002,>,Starting delivery

2014-08-21T19:40:58.639Z,08D187F0D08C4E37,MapiDelivery,EMEA-SWEEX15-01 Store 002,>,Connecting to server Stromkarlen.minvan.se session type Mailbox

2014-08-21T19:40:58.685Z,08D187F0D08C4E37,MapiDelivery,EMEA-SWEEX15-01 Store 002,-,Messages: 1 Bytes: 190 Recipients: 1

2014-08-21T19:40:58.701Z,08D187F0D08C4E39,MapiDelivery,EMEA-SWEEX15-01 Store 001,+,Delivery;MailboxServer=Stromkarlen.minvan.se;Database=EMEA-SWEEX15-01 Store 001

2014-08-21T19:40:58.701Z,08D187F0D08C4E39,MapiDelivery,EMEA-SWEEX15-01 Store 001,>,Starting delivery

2014-08-21T19:40:58.717Z,08D187F0D08C4E39,MapiDelivery,EMEA-SWEEX15-01 Store 001,>,Connecting to server Stromkarlen.minvan.se session type Mailbox

2014-08-21T19:40:58.763Z,08D187F0D08C4E39,MapiDelivery,EMEA-SWEEX15-01 Store 001,-,Messages: 1 Bytes: 190 Recipients: 1

2014-08-21T19:42:59.453Z,08D187F0D08C4E3B,MapiDelivery,EMEA-SWEEX15-01 Store 002,+,Delivery;MailboxServer=Stromkarlen.minvan.se;Database=EMEA-SWEEX15-01 Store 002

2014-08-21T19:42:59.453Z,08D187F0D08C4E3B,MapiDelivery,EMEA-SWEEX15-01 Store 002,>,Starting delivery

2014-08-21T19:42:59.469Z,08D187F0D08C4E3B,MapiDelivery,EMEA-SWEEX15-01 Store 002,>,Connecting to server Stromkarlen.minvan.se session type Mailbox

2014-08-21T19:42:59.500Z,08D187F0D08C4E3B,MapiDelivery,EMEA-SWEEX15-01 Store 002,-,Messages: 1 Bytes: 190 Recipients: 1

2014-08-21T19:42:59.531Z,08D187F0D08C4E3D,MapiDelivery,EMEA-SWEEX15-01 Store 001,+,Delivery;MailboxServer=Stromkarlen.minvan.se;Database=EMEA-SWEEX15-01 Store 001

2014-08-21T19:42:59.531Z,08D187F0D08C4E3D,MapiDelivery,EMEA-SWEEX15-01 Store 001,>,Starting delivery

2014-08-21T19:42:59.531Z,08D187F0D08C4E3D,MapiDelivery,EMEA-SWEEX15-01 Store 001,>,Connecting to server Stromkarlen.minvan.se session type Mailbox

2014-08-21T19:42:59.563Z,08D187F0D08C4E3D,MapiDelivery,EMEA-SWEEX15-01 Store 001,-,Messages: 1 Bytes: 190 Recipients: 1

 

But Submission gave me the juicy details of what our issue was stemming from:

 

2014-08-21T19:43:54.533Z,08D187F052C39BA0,MapiSubmission,bbbfef75-3381-42dc-b027-850f29eebc62,+,STROMKARLEN.minvan.se
2014-08-21T19:43:54.533Z,08D187F052C39BA1,SMTP,mailboxtransportsubmissioninternalproxy,+,Undefined 00000000-0000-0000-0000-000000000000;QueueLength=<no priority counts>
2014-08-21T19:43:54.533Z,08D187F052C39BA1,SMTP,mailboxtransportsubmissioninternalproxy,>,Non-existent domain reported by y.y.y.y. [Domain:Result] = Hylda.minvan.se:InfoDomainNonexistent; STROMKARLEN.minvan.se:InfoDomainNonexistent;
2014-08-21T19:43:54.533Z,08D187F052C39BA1,SMTP,mailboxtransportsubmissioninternalproxy,-,Messages: 0 Bytes: 0 (The DNS query for  'Undefined':'mailboxtransportsubmissioninternalproxy':'00000000-0000-0000-0000-000000000000' failed with error : InfoDomainNonexistent)
2014-08-21T19:43:54.533Z,08D187F052C39BA0,MapiSubmission,bbbfef75-3381-42dc-b027-850f29eebc62,>,"Failed; HResult: 2684354560; DiagnosticInfo: Stage:CommitMailItem, SmtpResponse:451 4.4.0 DNS query failed. The error was: SMTPSEND.DNS.NonExistentDomain; nonexistent domain"
2014-08-21T19:43:54.533Z,08D187F052C39BA0,MapiSubmission,bbbfef75-3381-42dc-b027-850f29eebc62,-,RegularSubmissions: 0 ShadowSubmissions: 0 Bytes: 0 Recipients: 0 Failures: 1 ReachedLimit: False Idle: False

 

Then, I saw my answer. We’re hitting the wrong DNS server for the query:

 

nslookup hylda.minvan.se

Server:  UnKnown

Address:  x.x.x.x

 

Name:    hylda.minvan.se

Address:  x.x.x.x

 

Changed the DNS settings on the DAG NIC and resubmitted the queue:

 

Retry-Queue "Stromkarlen\3" -Resubmit:$TRUE

 

Get-TransportService | Get-Queue | Where{$_.MessageCount -gt 0} | FT -AutoSize

 

Identity      DeliveryType          Status MessageCount Velocity RiskLevel OutboundIPPool NextHopDomain

--------      ------------          ------ ------------ -------- --------- -------------- -------------

Stromkarlen\3 SmtpDeliveryToMailbox Active 15           0.02     Normal    0              emea-sweex15-01 store 001

 

 

Get-TransportService | Get-Queue | Where{$_.MessageCount -gt 0} | FT -AutoSize

 

Essentially, this boiled down to two NICS using different DNS servers but why didn’t this affect the SMTP probes to Health Mailboxes? If it didn’t, why did we use local DNS for Health Manager and foreign DNS for delivery? …and, if that’s the case. Is this a bug?

 

Then, the answer finally arrived in the form of a realization: if we had no queues to the Health Mailboxes, maybe the probe was broken? Alright, time to investigate that piece.

 

Sure enough, the probe has failed some time back and was marked as poisoned:

 

   MachineName: Stromkarlen.minvan.se

 

StartTime            ProbeName                      Result       Duration   Latency    TargetResource/Error                                         HealthSet

---------            ---------                      ------       --------   -------    --------------------                                         ---------

2014-08-21 20:12:57  Mapi.Submit.Probe              Poisoned     02:28.388  00:00.000  A previous poisoned execution was detected. This is indic... MailboxTransport

2014-08-21 20:12:59  MailboxDeliveryAvailability    Poisoned     03:38.978  00:00.000  A previous poisoned execution was detected. This is indic... MailboxTransport

2014-08-21 20:13:04  MailboxTransportSubmissionS... Poisoned     02:49.648  00:00.000  {msexchangesubmission, A previous poisoned execution was ... MailboxTransport

2014-08-21 20:13:20  MailboxTransportDeliverySer... Poisoned     02:30.491  00:00.000  {msexchangedelivery, A previous poisoned execution was de... MailboxTransport

 

Moral of the story: Logs are just as important as the Health Manager/Active Probing, as the probes could fail or be marked as poisoned.

  • Thanks for sharing very interesting

Your comment has been posted.   Close
Thank you, your comment requires moderation so it may take a while to appear.   Close
Leave a Comment