Note: This blog describes a Exchange 2007 misconfiguration issue which also applies to Exchange 2010. Special thanks to Naveen Nathanial (MS PSS) for the assistance, like (ex)tracing, in order to solve this issue.

While implementing UM at a customer in an existing Exchange 2007 environment, I encountered an issue where the UM server wasn’t sending missed call notifications and voice mail messages to Hub Transport servers in the organization, despite the missed call setting on their mailbox. The events recorded in the UM server’s event log were:

Event Type: Warning
Event Source: MSExchange Unified Messaging
Event Category: UMCore
Event ID: 1185
Description:
The Unified Messaging server was unable to submit a message to Hub Transport server “HUB1” because the following error occurred: Unexpected SMTP server response. Expected: 250, actual: 501, whole response: 501 5.1.7 Invalid address

followed by:

Event Type: Error
Event Source: MSExchange Unified Messaging
Event Category: UMService
Event ID: 1082
Description:
The Unified Messaging server was unable to submit messages to a Hub Transport server because there is no Hub Transport server available to process the request with UM header file “C:\Program Files\Microsoft\Exchange Server\UnifiedMessaging\voicemail\46ffee82-97ab-4cf3-830e-f2ef4f0fc275.txt”. Make sure that there is a Hub Transport server located in the same Active Directory site as the UM server. In addition, make sure that the Microsoft Exchange Transport service is started on the Hub Transport server.

As you can see from 1082 event, the folder where UM stores messages is the UnifiedMessaging\voicemail folder below the Exchange installation folder, e.g. C:\Program Files\Microsoft\Exchange Server\UnifiedMessaging\voicemail. Missed call notifications are stored in a <GUID>.txt file, voicemail messages are stored in a <GUID>.txt file accompanied by a <GUID>.wav file which will contain the actual message. When the UM server can’t deliver these messages it will queue them here and retry sending them each 10 minutes. This will mean that after a while the event log may contain lots of 1185 and 1082 messages.

Now, when searching for possible causes of the UM not being able to deliver these messages to the Hub Transport server, knowledgebase article 935629 came up. This article states three common causes:

• Removed default receive connector or misconfigured receive connector;
  • Discrepancy between the FQDN configured on the connector and en the Hub Transport server’s FQDN;
  • Authorization settings;
• Certificate misconfiguration;
• Missing service principal name (SPN) records.

For your information, I created a separate receive connector on the Hub Transport server specific for UM by specifying the UM’s IP address (192.168.1.43) in RemoteIPranges:

New-ReceiveConnector -Name “UM Receive Connector” –Fqdn <HUB1.domain.com> -Bindings ‘0.0.0.0:25’ -RemoteIPRanges ‘192.168.1.43’

Note that the default AuthMechanism setting of newly created receive connectors, {Tls,Integrated, BasicAuth, BasicAuth RequireTLS, ExchangeServer}, is fine, so we don’t need to specify it.

The certificate was also properly configured by importing it and enabling it for SMTP using

Enable-ExchangeCertificate <Thumbprint> –Services SMTP

First I checked if the SPN records were properly registered. They should be, because the UM service always registers them during startup. But just to rule things out we executed the following command:

SETSPN.EXE –l UM1

which resulted in:

SmtpSvc/UM1
SmtpSvc/UM1.domain.com

To investigate what the Hub Transport received from the UM server, causing the “Invalid Address” message, I enabled logging on the Hub Transport server’s receive connector. This would also show if the configuration changes made were properly processed. The messages from the UM server to the Hub Transport server are send using secure SMTP, so I needed to enable SMTP logging as follows:

Set-ReceiveConnector “UM Receive Connector” –ProtocolLoggingLevel Verbose

The log files are by default located in the TransportRoles\Logs\ProtocolLog folder below the Exchange installation folder, e.g. C:\Program Files\Microsoft\Exchange Server\TransportRoles\Logs\ProtocolLog. Since we’re interested in the received communications, we drill down to the SmtpReceive subfolder and check out the latest RECV log file to see what’s going on. This is an excerpt of the log file (192.168.1.88 is the IP address of HUB1):

2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,0,192.168.1.88:25,192.168.1.43:22906,+,,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,1,192.168.1.88:25,192.168.1.43:22906,*,None,Set Session Permissions
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,2,192.168.1.88:25,192.168.1.43:22906,>,”220 HUB1.domain.com Microsoft ESMTP MAIL Service ready at Thu, 2 Dec 2010 15:01:23 +0100″,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,3,192.168.1.88:25,192.168.1.43:22906,<,EHLO UM1.domain.com,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,4,192.168.1.88:25,192.168.1.43:22906,>,250-HUB1.domain.com Hello [192.168.1.43],
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,5,192.168.1.88:25,192.168.1.43:22906,>,250-SIZE 10485760,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,6,192.168.1.88:25,192.168.1.43:22906,>,250-PIPELINING,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,7,192.168.1.88:25,192.168.1.43:22906,>,250-DSN,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,8,192.168.1.88:25,192.168.1.43:22906,>,250-ENHANCEDSTATUSCODES,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,9,192.168.1.88:25,192.168.1.43:22906,>,250-STARTTLS,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,10,192.168.1.88:25,192.168.1.43:22906,>,250-X-ANONYMOUSTLS,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,11,192.168.1.88:25,192.168.1.43:22906,>,250-AUTH NTLM,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,12,192.168.1.88:25,192.168.1.43:22906,>,250-X-EXPS GSSAPI NTLM,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,13,192.168.1.88:25,192.168.1.43:22906,>,250-8BITMIME,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,14,192.168.1.88:25,192.168.1.43:22906,>,250-BINARYMIME,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,15,192.168.1.88:25,192.168.1.43:22906,>,250-CHUNKING,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,16,192.168.1.88:25,192.168.1.43:22906,>,250-XEXCH50,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,17,192.168.1.88:25,192.168.1.43:22906,>,250 XRDST,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,18,192.168.1.88:25,192.168.1.43:22906,<,X-ANONYMOUSTLS,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,19,192.168.1.88:25,192.168.1.43:22906,>,220 2.0.0 SMTP server ready,
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,20,192.168.1.88:25,192.168.1.43:22906,*,,Sending certificate
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,21,192.168.1.88:25,192.168.1.43:22906,*,CN=HUB1.domain.com,Certificate subject
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,22,192.168.1.88:25,192.168.1.43:22906,*,”CN=DC1, DC=domain, DC=com”,Certificate issuer name
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,23,192.168.1.88:25,192.168.1.43:22906,*,60B39F250000000000F4,Certificate serial number
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,24,192.168.1.88:25,192.168.1.43:22906,*,525F116DD3CC9676708144A40F364B13D07F852F,Certificate thumbprint
2010-12-02T14:01:24.534Z,HUB1\UM Receive Connector,08CD5C684653F17E,25,192.168.1.88:25,192.168.1.43:22906,*,HUB1.domain.com;HUB1,Certificate alternate names
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,26,192.168.1.88:25,192.168.1.43:22906,<,EHLO UM1.domain.com,
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,27,192.168.1.88:25,192.168.1.43:22906,>,250-HUB1.domain.com Hello [192.168.1.43],
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,28,192.168.1.88:25,192.168.1.43:22906,>,250-SIZE 10485760,
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,29,192.168.1.88:25,192.168.1.43:22906,>,250-PIPELINING,
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,30,192.168.1.88:25,192.168.1.43:22906,>,250-DSN,
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,31,192.168.1.88:25,192.168.1.43:22906,>,250-ENHANCEDSTATUSCODES,
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,32,192.168.1.88:25,192.168.1.43:22906,>,250-AUTH NTLM,
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,33,192.168.1.88:25,192.168.1.43:22906,>,250-X-EXPS EXCHANGEAUTH GSSAPI NTLM,
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,34,192.168.1.88:25,192.168.1.43:22906,>,250-X-EXCHANGEAUTH SHA256,
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,35,192.168.1.88:25,192.168.1.43:22906,>,250-8BITMIME,
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,36,192.168.1.88:25,192.168.1.43:22906,>,250-BINARYMIME,
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,37,192.168.1.88:25,192.168.1.43:22906,>,250-CHUNKING,
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,38,192.168.1.88:25,192.168.1.43:22906,>,250-XEXCH50,
2010-12-02T14:01:24.549Z,HUB1\UM Receive Connector,08CD5C684653F17E,39,192.168.1.88:25,192.168.1.43:22906,>,250 XRDST,
2010-12-02T14:01:24.565Z,HUB1\UM Receive Connector,08CD5C684653F17E,40,192.168.1.88:25,192.168.1.43:22906,<,X-EXPS EXCHANGEAUTH,
2010-12-02T14:01:24.565Z,HUB1\UM Receive Connector,08CD5C684653F17E,41,192.168.1.88:25,192.168.1.43:22906,*,SMTPSubmit SMTPSubmitForMLS SMTPAcceptAnyRecipient SMTPAcceptAuthenticationFlag SMTPAcceptAnySender SMTPAcceptAuthoritativeDomainSender BypassAntiSpam BypassMessageSizeLimit SMTPSendEXCH50 SMTPAcceptEXCH50 AcceptRoutingHeaders AcceptForestHeaders AcceptOrganizationHeaders SendRoutingHeaders SendForestHeaders SendOrganizationHeaders SendAs,Set Session Permissions
2010-12-02T14:01:24.565Z,HUB1\UM Receive Connector,08CD5C684653F17E,42,192.168.1.88:25,192.168.1.43:22906,*,DOMAIN\UM1$,authenticated
2010-12-02T14:01:24.565Z,HUB1\UM Receive Connector,08CD5C684653F17E,43,192.168.1.88:25,192.168.1.43:22906,>,235 <authentication response>,
2010-12-02T14:01:24.581Z,HUB1\UM Receive Connector,08CD5C684653F17E,44,192.168.1.88:25,192.168.1.43:22906,<,MAIL FROM: ,
2010-12-02T14:01:24.581Z,HUB1\UM Receive Connector,08CD5C684653F17E,45,192.168.1.88:25,192.168.1.43:22906,>,501 5.1.7 Invalid address,
2010-12-02T14:01:24.596Z,HUB1\UM Receive Connector,08CD5C684653F17E,46,192.168.1.88:25,192.168.1.43:22906,-,,Remote

Looking at this information, we can conclude the following:

• The FQDN of the Receive Connector matches the Hub Transport server FQDN (HUB1.domain.com);
• Certificate is properly configured (thumbprint offered matches SMTP enabled certificate using Enable-ExchangeCertificate, certificate subject matches FQDN);
• The UM server can properly authenticate itself with the Hub Transport server (X-ANONYMOUSTLS verb is advertised, required for certificate handshake, and in the TLS secured part of the session, after the 2nd EHLO, the UM server’s computer account DOMAIN\UM1$ is able to authenticate);

What you perhaps immediately noticed is that MAIL FROM command does not contain a sender, which is the reason why the Hub Transport server refuses to accept the message. So, why did the UM server not include a sender. To check if there was something wrong with the generated messages, I copied some of them to the lab environment. I edited the recipient information to match my lab environment, which is straightforward if you look at a missed call notification for example:

MessageType : MissedCall
CallerId : 612345678
NDRRequired : False
RecipientName : Test
RecipientAddress : Test@lab.com
RecipientCulture : nl-NL
CallId : 7066890-a00e70a-13c4-55013-6826c-718b9f72-6826c
Important : False

When injecting the edited files in the lab’s voicemail folder and restarting the MSExchangeUM service (if you don’t want to wait for the processing cycle), they get processed properly and the missed call and voicemail messages were sent. When going through the logs in the lab environment, the sender was found to be MicrosoftExchange329e71ec88ae4615bbc36ab6ce41109e@lab.com. This should provided a clue to the cause.

After some extracing and Wireshark capture sessions with PSS, it was concluded nothing was wrong with the UM server nor the communication between the UM and Hub Transport server. Then, PSS came up with the question to check the OrganizationConfig settings. The output of Get-OrganizationConfig  cmdlet was as follows (only attributes of interest shown):

MicrosoftExchangeRecipientEmailAddresses : {smtp:MicrosoftExchange329e71ec88ae4615bbc36ab6ce41109e@domain.com, X400:C=us;A= ;P=ExOrg;O=Exchange;S=MicrosoftExchange329e71ec88ae4615bbc36ab;}
MicrosoftExchangeRecipientReplyRecipient :
MicrosoftExchangeRecipientPrimarySmtpAddress :
MicrosoftExchangeRecipientEmailAddressPolicyEnabled : False

We had a winner: The policy was not enabled (MicrosoftExchangeRecipientEmailAddressPolicyEnabled) and MicrosoftExchangeRecipientPrimarySmtpAddress was blank, which caused Exchange, using a Microsoft Exchange recipient, to use a blank sender for system messages! The MicrosoftExchangeRecipientPrimarySmtpAddress attribute contains the SMTP address used by Exchange to send system messages, e.g. internal NDRs, quota, journal or agent messages. As you now know, it’s also used to send anonymous (i.e. unresolvable caller ID) UM messages.

So, to fix this issue the MicrosoftExchangeRecipientPrimarySmtpAddress needs a proper SMTP address for the Microsoft Exchange recipient (i.e. system messages) or MicrosoftExchangeRecipientEmailAddressPolicyEnabled should be set to $true. When enabled, the policy will look at the E-mail Address Policies and set MicrosoftExchangeRecipientPrimarySmtpAddress to MicrosoftExchange329e71ec88ae4615bbc36ab6ce41109e@domain.com, where domain.com is the domain specified in the highest E-Mail Address Policy.

A short explanation of the other attributes:

• MicrosoftExchangeRecipientEmailAddresses contains all valid e-mail addresses for the Microsoft Exchange recipient;
• MicrosoftExchangeRecipientReplyRecipient can be used to set the reply address, i.e. who will receive replies to system messages. Normally, replies to the Microsoft Exchange recipient are dropped.

As I don’t know the history of that particular Exchange 2007 environment, I can’t tell why it was misconfigured this way. Luckily, chances of seeing this issue are small because either the policy is enabled (default) or the PrimarySmtpAddress keeps its current value when the policy is disabled.

More information on the Microsoft Exchange Recipient can be found here.