Processing mailbox fail

[Robvil]

Hi,

Version 1.5

Case ID: 03081331

Since friday evening i am getting this error on different users:
02-07-2018 15:22:25 :: Processing mailbox X failed with error: Mail item data export failed. The server cannot service this request right now. Try again later. :: 0:24:16

Last 2 days it is on the same mailbox. I have 147 licensen O365 mailboxes and a backup runs every 4 hours, normal within 5 minuttes to 45 minuttes. Until friday Veeam did backup a couple of hundred MB of data up to 1GB during each run.
After friday my backup exploded and from 1. july to 2. july veeam did backup 160GB of exchange data. I cannot believe my 147 users would change/send/receive 160GB data with 1 day, and looking in O365 portal under user activity, i do not see anything which indicates that much data has been proceeded by users.

Running Microsoft Support and Recovery Assistant for Office 365 from the veeam server do not show any issues. Fine latency and fast download.

So tonight i restarted veeam o365 services and when i login in again, i got a license warning saying i have exceeded my license cound with 1. I have 150 Veeam licenses and 147 O365 licensed mailboxes. I have never had above 147 licensed O365 mailboxes, so how can my veeam license be exceeded?

Is there any way to see what have changed from the 1. to the 2. july?
Could there be a local Veeam DB store issue causing Veeam to re-download items already being backup up?

/Robert

[Robvil]

A thought regarding the huge amount of backup data. Last week i applied a new retension policy/tag to all users.
Could the background tasks Microsoft runs with retension policies on data stores change users last changed date/time on their items somehow?

[nielsengelen]

Hi Robert,

I would advise you to get in touch with support to see if we can determine this behaviour. Retention changes shouldn’t affect or explain this huge growth.

[Robvil]

It was caused by a issue with a users <deleted items> folder - so this folder was download again and again and again and now i have approx. 250GB unwanted duplicated data in my backup repository.

1. There must be a bug in Veeam which can cause items to be re-downloaded over and over again
2. Would be nice to have a option to delete specific user folder from the backup archive

/Robert

[Polina]

Hi Robert,

Thank you for providing more details on this case. This is a known issue, and to the best of my knowledge, Veeam together with Microsoft is currently investigating it. As Niels suggested, please open a support case and post your case ID here.

[Robvil]

case number already provided in the first message - Case ID: 03081331

[Polina]

Oh, sorry, I missed it.

[Mike Resseler]

Robert,

To shed a bit more light on this. Microsoft is changing organizations batch by batch to a new indexing system. The difference between the old and new indexing service is that the indexing data is now stored in the mailbox/ mail/ contact/ ... metadata while it used to be stored somewhere in a "black box" that nobody could look into.


We worked with MSFT over the last weeks to figure out what is going on, and MSFT has found a solution for it that has been checked in and will be rolling out in the next couple of weeks. In the meantime I hope we can have a workaround for you. But support will be able to help you better with that

Hope it helps

[Robvil]

Thank you.

In the mean time i decided to create a new repository and start from fresh, but now i am gettings many errors like this:
14-07-2018 04:13:13 :: Processing mailbox user@domain.local failed with error: Mail item data export failed. There is an error in XML document (1, 78488173).. Unexpected end of file has occurred. The following elements are not closed: m:Data, m:ExportItemsResponseMessage, m:ResponseMessages, m:ExportItemsResponse, s:Body, s:Envelope. Line 1, position 78488173. :: 0:41:29

Is this related?

/Robert

[Mike Resseler]

Robert,

Not sure. At first thought I would say no but there is not enough information for me to be sure. Please add this in your support call

Thanks
Mike

[Robvil]

I opened a new case - 3101551.

[Robvil]

Looks as the server at O365 cannot service my requests in time ....

14-07-2018 09:07:26 43 (9892) Processing mailbox: reklamation@domain.local...
14-07-2018 09:07:26 43 (9892) Syncing folder items: Indbakke...
14-07-2018 09:07:27 52 (3888) Error: Mail item data export failed
14-07-2018 09:07:27 52 (3888) Stack:
14-07-2018 09:07:27 52 (3888) at Veeam.Ews.ExError.Throw(Exception error, String format, Object[] args)
at Veeam.Ews.ExError.Catch(Action action, String format, Object[] args)
at Veeam.Ews.ExError.Catch[T](Func`1 func, String format, Object[] args)
at Veeam.Ews.ExServices.EndExportItems(IAsyncResult ar)
at Veeam.Ews.ExServicesExtension.BatchExport(ExServices ews, IReadOnlyCollection`1 batches, TimeSpan timeout, CancellationToken cancel)
at Veeam.Archiver.Source.Exchange.SyncPage.RequestBatches(IReadOnlyCollection`1 batches, Dictionary`2 data)
at Veeam.Archiver.Source.Exchange.SyncPage.BatchExport(IEnumerable`1 batches)
at Veeam.Archiver.Source.Exchange.SyncPage.ProcessData(IFolderRepository repository, IReadOnlyCollection`1 page)
at Veeam.Archiver.Source.Exchange.SyncPage.SaveChanges(IFolderRepository repository)
at Veeam.Archiver.Source.ItemProcessor.ProcessFolder(Byte[] id, ExFolder folder, Byte[] currentState)
at Veeam.Archiver.Source.ItemProcessor.<>c__DisplayClass7_0.<Process>b__1()
at Veeam.Ews.Retry.FolderRetry.<>c__DisplayClass17_0`1.<Process>b__0()
at Veeam.Ews.Retry.FolderRetry.Process(Action action)
14-07-2018 09:07:27 52 (3888) Error: There is an error in XML document (1, 84800029).
14-07-2018 09:07:27 52 (3888) Stack:
14-07-2018 09:07:27 52 (3888) at System.Xml.Serialization.XmlSerializer.Deserialize(XmlReader xmlReader, String encodingStyle, XmlDeserializationEvents events)
at System.Web.Services.Protocols.SoapHttpClientProtocol.ReadResponse(SoapClientMessage message, WebResponse response, Stream responseStream, Boolean asyncCall)
at System.Web.Services.Protocols.SoapHttpClientProtocol.EndInvoke(IAsyncResult asyncResult)
at EWServices.ExchangeServiceBinding.EndExportItems(IAsyncResult asyncResult)
at Veeam.Ews.ExError.<>c__DisplayClass6_0`1.<Catch>b__0()
at Veeam.Ews.ExError.Catch(Action action, String format, Object[] args)
14-07-2018 09:07:27 52 (3888) Error: Unexpected end of file has occurred. The following elements are not closed: m:Data, m:ExportItemsResponseMessage, m:ResponseMessages, m:ExportItemsResponse, s:Body, s:Envelope. Line 1, position 84800029.
14-07-2018 09:07:27 52 (3888) Stack:
14-07-2018 09:07:27 52 (3888) at System.Xml.XmlTextReaderImpl.Throw(Exception e)
at System.Xml.XmlTextReaderImpl.ThrowUnclosedElements()
at System.Xml.XmlTextReaderImpl.ParseElementContent()
at System.Xml.XmlTextReaderImpl.MoveToNextContentNode(Boolean moveIfOnContentNode)
at System.Xml.XmlTextReaderImpl.ReadContentAsBinary(Byte[] buffer, Int32 index, Int32 count)
at System.Xml.XmlTextReaderImpl.ReadElementContentAsBinary(Byte[] buffer, Int32 index, Int32 count)
at System.Xml.Serialization.XmlSerializationReader.ReadByteArray(Boolean isBase64)
at Microsoft.Xml.Serialization.GeneratedAssembly.XmlSerializationReaderExBinding.Read549_ExportItemsResponseMessageType(Boolean isNullable, Boolean checkType)
at Microsoft.Xml.Serialization.GeneratedAssembly.XmlSerializationReaderExBinding.Read553_ArrayOfResponseMessagesType(Boolean isNullable, Boolean checkType)
at Microsoft.Xml.Serialization.GeneratedAssembly.XmlSerializationReaderExBinding.Read607_ExportItemsResponseType(Boolean isNullable, Boolean checkType)
at Microsoft.Xml.Serialization.GeneratedAssembly.XmlSerializationReaderExBinding.Read911_ExportItemsResponse()
at System.Xml.Serialization.XmlSerializer.Deserialize(XmlReader xmlReader, String encodingStyle, XmlDeserializationEvents events)
14-07-2018 09:07:27 52 (3888) Warning: Exchange Web Services request failed
14-07-2018 09:07:27 52 (3888) Retry count: 2
14-07-2018 09:07:27 52 (3888) Waiting before next processing attempt: 00:00:10...
14-07-2018 09:07:27 51 (2816) Receive time: 5,5381271
14-07-2018 09:07:27 51 (2816) Saving received items...
14-07-2018 09:07:27 51 (2816) Saving time: 0,0276548
14-07-2018 09:07:27 51 (2816) Total data: 1586423
14-07-2018 09:07:27 51 (2816) Receive rate: 286454 B/s
14-07-2018 09:07:27 51 (2816) Saving rate : 57365195 B/s

[nielsengelen]

Best would be to let support handle this as not every solution may be the same.