Exchange 2010 Outlook Calendar Duplication – Another Weird Thing

Before I start, I must tell that there are several articles related to this kind of behavior but they do not really elaborate much about how to reach the resolution. I thought I would take few minutes to write up and help people. 🙂

Here is the scenario:

CEO of one of our customer companies was facing a long time unresolved issue with calendar item duplication. His secretary observed that she used to see duplication of some random meeting requests. Interestingly, she was not a delegate of his calendar and used his mailbox as an additional mailbox in outlook. This configuration ruled out the possibility of a corrupt rule in the mailbox that might have caused this behavior. In fact there was no corrupt rule in either of the mailboxes.

Here is what we did to investigate it in details:

MFCMAPI is my all-time favorite tool when it comes to troubleshooting complex client side issues. Another tool that was used in the entire troubleshooting is an internal tool to Microsoft so we could not really get hold of it. But, one of the PSS engineers helped us parsing the log files with correct information that was needed.

Using MFCMAPI:

Use MFCMAPI to locate the calendar items which seem to be getting duplicated in target mailbox. Export both messages into an XML file and look for the difference between two messages. Each object stored in Exchange Database gets a unique GUID stamped on it. If you open the XML file that is exported using MFCMAPI, you will see what the ID is stamped as a value of Prop LID_GLOBAL_OBJID value of this prop is unique on each item.

 

Using Exchange Server Store Trace:

In some complex issues you need to enable Exchange Server store trace. This procedure produces .etl files which are unreadable unless they are parsed. I would suggest you catch hold of someone in Microsoft to take some help to get the logs parsed. Technet Support Forums can be a good help there.

To enable store tracing follow http://support.microsoft.com/default.aspx?scid=kb;EN-US;971878 after parsing the etl files the output looks somewhat like below.

– User A sent a meeting request to CEO on 06:35:41.528 AM 1/19/2012 UTC which seems to have hit the recipient’s mailbox at 06:35:41.528 AM 1/19/2012 (Thursday, 19 January 2012, 12:05:00 [+5:30 GMT])

– Details recorded on the server for above mentioned message ID are as below:

o StartTrace GUID=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 Time:1/19/2012 6:35:41 AM

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 ServerBuild=14.01.0218.015

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 UserDN=/o=Exchange/ou=Exchange Administrative Group (FYDIBOHF23SPDLT)/cn=Recipients/cn=SDG003

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 WszMailboxOwnerName=CEO

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 PguidMailbox=BFD0F2A2-1896-48BA-BA0A-E84AA53FA1ED

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 Connecting host=<NULL>

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 Connecting protocol=MAPI

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 SzApplicationId=<NULL>

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 MapiClient_Type=ctTransport

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 MapiClient_MachineName=HT-01

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 MapiClient_ProcessName=edgetransport.exe

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 MapiClient_UserName=

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 ClientBuildNumber=3585.0.32986.15

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 Flags for Notification type=40000005

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 Dirty Properties Mask=0x95FFFFFF

o TGuid=2F91F24E-E4AB-4F31-B74B-93FC96FDEE17 FolderName=Calendar

– What confirms the duplication of messages at primary look is a property named PR_CONVERSATION_TOPIC_W on both the messages.

– The original message sent by User A show PR_CONVERSATION_TOPIC_W = Meeting with CFO and CIO

– However the duplicated message (calendar entry) shows PR_CONVERSATION_TOPIC_W = Contracts Management – Status Update

– On the other hand an even closer look shows that the PR_NORMALIZED_SUBJECT_W has a similar value showing up on both messages and it appears as Meeting with CFO and CIO

– This makes the viewer believe that both messages are same.

– Trace for the duplicated message shows

o StartTrace GUID=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 Time:1/19/2012 6:47:10 AM

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 ServerBuild=14.01.0218.015

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 UserDN=/o=Exchange/ou=Exchange Administrative Group (FYDIBOHF23SPDLT)/cn=Recipients/cn=SDG003

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 WszMailboxOwnerName=CEO

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 PguidMailbox=BFD0F2A2-1896-48BA-BA0A-E84AA53FA1ED

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 Connecting host=<NULL>

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 Connecting protocol=MAPI

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 SzApplicationId=Client=ActiveSync;UserAgent=RoadSync-S60/5.0;Action=/Microsoft-Server-ActiveSync/default.eas?User=00010090&DeviceId=358741022338476&DeviceType=Samsungi8910&Cmd=Sync

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 MapiClient_Type=ctAirSync

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 MapiClient_MachineName=BLR-VCAS-02

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 MapiClient_ProcessName=w3wp.exe

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 MapiClient_UserName=

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 ClientBuildNumber=3585.0.32986.15

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 Flags for Notification type=40000005

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 Dirty Properties Mask=0x15FFFFFF

o TGuid=65F2FFE7-5246-43B4-9B82-5BA4DB1256A3 FolderName=Recoverable Items

– Digging further down to the duplicated entry shows that the message did exist in the affected mailbox on the date 06:40:52.128 AM 9/15/2011 (Saturday, 15 September 2012, 12:10:00 UTC) and was called the application that exists on the phone Samsung I8910.

– It is a real mystery to identify how phone can really mess up the times but the logs are showing the things clearly. Possibly, the local cache of the phone / handheld still maintains a list of appointments offline.

Conclusion:

Looks like Mr CEO’s handheld device is creating the issues more than anything else at the moment. We may have to request him to stop using the device for some time to see if that resolves this problem. If that is not possible then change his mobile device settings to store only recent and future appointments and not all. The other way is to request him wiping his device to factory defaults if that is possible (but the last option)

 

At last, this post is a publication out of a technical troubleshooting note so may not be well formed with words used in it. In case you find anything confusing or I can help you understanding please feel free to comment or drop me a note.