Since upgrade to 5.0.1.225, backups don't always complete and can sit unfinished for many hours

[jimmyhurr]

Support case ID: #04789880

I run VBO 5.0.1.22 and it seems that since the upgrade to this release I have been unable to get a complete backup. I have two O365 tenancies protected with one nightly job each. These jobs are configured to backup the entire organisation with some exclusions. Both jobs backup to a single AWS S3 storage repo. For several weeks since I onboarded both tenancies, the jobs have run fine each night and always completed, however, since the upgrade to 5.0.1.225 (I think), both jobs has never completed, except one of them which completed when I ran it manually one time. I am in contact with Veeam support on this, but it is glacially slow (I have now changed the severity to 2).

The jobs seem to choke at this step when pushing the items to the S3 storage:

Code: Select all

9 (4280) Starting database contexts clearing...
9 (4280) Clearing old contexts in all databases...
9 (4280) Database contexts closed: 0

Last night I rebooted the machine on which Veeam is installed and let it run the two scheduled jobs automatically.

The 10pm job got quite a way through and then got stuck at this point:

Code: Select all

5/5/2021 11:07:53 PM 9 (4280) Starting database contexts clearing...
5/5/2021 11:07:53 PM 9 (4280) Clearing old contexts in all databases...
5/5/2021 11:07:53 PM 9 (4280) Database contexts closed: 0
5/6/2021 12:07:53 AM 9 (4280) Starting database contexts clearing...
5/6/2021 12:07:53 AM 9 (4280) Clearing old contexts in all databases...
5/6/2021 12:07:53 AM 9 (4280) Database contexts closed: 0

- this log continues on every hour doing the same thing

The other job which runs at 2am didn't even get anywhere, it just got stuck immediately at this point and has not even moved:

Code: Select all

5/6/2021 2:00:00 AM 26 (3164) Activating job: XXXX - Nightly...
5/6/2021 2:00:00 AM 26 (3164) Mailbox folders excluded from backup:
5/6/2021 2:00:00 AM 26 (3164) Deleted Items
5/6/2021 2:00:00 AM 26 (3164) Junk E-Mail
5/6/2021 2:00:00 AM 26 (3164) Sync Issues
5/6/2021 2:00:00 AM 26 (3164) Litigation Hold Items
5/6/2021 2:00:00 AM 26 (3164) Litigation Hold Item Versions
5/6/2021 2:00:00 AM 26 (3164) In-Place Hold Items
5/6/2021 2:00:00 AM 26 (3164) Initializing auxiliary backup accounts from organization configuration...
5/6/2021 2:00:00 AM 26 (3164) Application ID: e9a09f1f-662a-4fa0-8cee-b6d5a322decc
5/6/2021 2:00:00 AM 26 (3164) SharePoint save all web parts: False (job name: XXXX - Nightly, job ID: 29e88610-0208-42c8-b42c-6e6c2ec651dd)

Both jobs are still running.

While I wait for support, does anyone have any ideas? Should I be backing up each tenancy to separate AWS S3 repos? Anyone else seeing issues on 5.0.1.225?

thank you.

[Mike Resseler]

Unfortunately I have no possible idea on this one. I doubt the issue is with the AWS S3 repos, it seems the job is waiting for something.

Please continue to work with support. If you are not getting further by tomorrow, let me know. I will work with support

[mats.jansson]

We had the same problem. Rebooting the server and proxy did not help.
We just waited for the jobs to complete and after 30 - 50 hours the jobs finished.
After that the jobs worked as usual.

[jimmyhurr]

Unfortunately I have no possible idea on this one. I doubt the issue is with the AWS S3 repos, it seems the job is waiting for something.

Please continue to work with support. If you are not getting further by tomorrow, let me know. I will work with support

Thanks Mike.

[jimmyhurr]

We had the same problem. Rebooting the server and proxy did not help.
We just waited for the jobs to complete and after 30 - 50 hours the jobs finished.
After that the jobs worked as usual.

Interesting! I have so far just cancelled them when they have run for over 12 hours. I will try leaving them to complete on the next scheduled run.
Seems very odd though.... thank you!

[jimmyhurr]

Update: support asked me to create a new AWS repo and try running a new job directing the data into this repo.

So, yesterday evening I decided to start totally from scratch.

- I checked the Proxy server settings and they are OK
- I created two brand new AWS S3 repositories, one for each tenant
- I left the original AWS S3 repository in place - i.e. there are now 3 repositories available.
- I deleted the two existing nightly jobs
- I created two new jobs, one for each tenant, directing data into the dedicated new AWS S3 repo for each tenant
- I then disabled the new job for one of the tenants and manually started the new job for the other tenant.

This job has now been running for 14.5hrs. The UI says 16 out of 72 items are complete. As of now, there is no network traffic being generated at all and the job is now stuck at exactly the same place as the other jobs:

Code: Select all

5/6/2021 8:43:32 PM   79 (4548) Updating object storage repository: VEEAM_XXX (ID: f3b6b255-b1c8-4e88-9516-3042418da8fa, repository ID: 8fa1ea94-d070-4135-8017-e6dec998a55e)...
5/6/2021 8:43:32 PM   79 (4548)  Object storage repository type: AmazonS3ObjectStorage
5/6/2021 8:43:32 PM   79 (4548)  Bucket: veeamXXX
5/6/2021 8:43:32 PM   79 (4548)  Bucket region: EU (London)
5/6/2021 8:43:32 PM   79 (4548)  AWS region: Global
5/6/2021 8:43:32 PM   79 (4548)  Amazon S3 storage class: Standard
5/6/2021 8:43:32 PM   79 (4548)  Folder: BACKUP
5/6/2021 8:43:32 PM   79 (4548)  Account ID: 6b67e204-bb06-4baf-a2e7-fbeb5dfca8a8
5/6/2021 9:07:36 PM   73 (800) Updating object storage repository: VEEAM_XXX (ID: f3b6b255-b1c8-4e88-9516-3042418da8fa, repository ID: 8fa1ea94-d070-4135-8017-e6dec998a55e)...
5/6/2021 9:07:36 PM   73 (800)  Object storage repository type: AmazonS3ObjectStorage
5/6/2021 9:07:36 PM   73 (800)  Bucket: veeamXXX
5/6/2021 9:07:36 PM   73 (800)  Bucket region: EU (London)
5/6/2021 9:07:36 PM   73 (800)  AWS region: Global
5/6/2021 9:07:36 PM   73 (800)  Amazon S3 storage class: Standard
5/6/2021 9:07:36 PM   73 (800)  Folder: BACKUP
5/6/2021 9:07:36 PM   73 (800)  Account ID: 6b67e204-bb06-4baf-a2e7-fbeb5dfca8a8
5/6/2021 9:07:55 PM    9 (4280) Starting database contexts clearing...
5/6/2021 9:07:55 PM    9 (4280)  Clearing old contexts in all databases...
5/6/2021 9:07:55 PM    9 (4280)   Database contexts closed: 0
5/6/2021 10:00:57 PM   10 (4596) Event received: Identify
5/6/2021 10:00:57 PM   10 (4596) Repository: C:\VeeamAWSRepository
5/6/2021 10:00:57 PM   10 (4596) Repository: C:\VeeamXXXRepo
5/6/2021 10:00:57 PM   10 (4596) Repository: C:\VeeamYYYRepo
5/6/2021 10:01:32 PM   10 (4596) Event received: Identify
5/6/2021 10:01:32 PM   10 (4596) Repository: C:\VeeamAWSRepository
5/6/2021 10:01:32 PM   10 (4596) Repository: C:\VeeamXXXRepo
5/6/2021 10:01:32 PM   10 (4596) Repository: C:\VeeamYYYmRepo
5/6/2021 10:01:38 PM   10 (4596) Event received: PrepareForSnapshot
5/6/2021 10:01:38 PM   10 (4596) Preparing snapshot...
5/6/2021 10:01:39 PM   10 (4596) Event received: Freeze
5/6/2021 10:01:39 PM   10 (4596) Freezing snapshot...
5/6/2021 10:01:50 PM   10 (4596) Event received: Thaw
5/6/2021 10:01:51 PM   10 (4596) Thawing snapshot...
5/6/2021 10:07:55 PM    9 (4280) Starting database contexts clearing...
5/6/2021 10:07:55 PM    9 (4280)  Clearing old contexts in all databases...
5/6/2021 10:07:55 PM    9 (4280)   Database contexts closed: 0
5/6/2021 10:20:13 PM   10 (4596) Event received: Identify
5/6/2021 10:20:15 PM   10 (4596) Repository: C:\VeeamAWSRepository
5/6/2021 10:20:15 PM   10 (4596) Repository: C:\VeeamXXXRepo
5/6/2021 10:20:15 PM   10 (4596) Repository: C:\VeeamYYYRepo
5/6/2021 11:07:55 PM    9 (4280) Starting database contexts clearing...
5/6/2021 11:07:55 PM    9 (4280)  Clearing old contexts in all databases...
5/6/2021 11:07:55 PM    9 (4280)   Database contexts closed: 0
5/7/2021 12:07:55 AM    9 (4280) Starting database contexts clearing...
5/7/2021 12:07:55 AM    9 (4280)  Clearing old contexts in all databases...
5/7/2021 12:07:55 AM    9 (4280)   Database contexts closed: 0
5/7/2021 1:00:00 AM  113 (11476) Computing database space in the repository (ID: 6c1dc377-8a46-4452-92ab-bf192085c6bc)...
5/7/2021 1:00:00 AM  113 (11476) Computing database space usage completed
5/7/2021 1:00:00 AM   65 (6588) Computing database space in the repository (ID: 8fa1ea94-d070-4135-8017-e6dec998a55e)...
5/7/2021 1:00:01 AM   65 (6588) Computing database space usage completed
5/7/2021 1:00:01 AM  113 (11476) Computing database space in the repository (ID: 71e255a1-d82e-4ff8-9090-cee43198c269)...
5/7/2021 1:00:01 AM  113 (11476) Computing database space usage completed
5/7/2021 1:07:55 AM    9 (4280) Starting database contexts clearing...
5/7/2021 1:07:55 AM    9 (4280)  Clearing old contexts in all databases...
5/7/2021 1:07:55 AM    9 (4280)   Database contexts closed: 0
5/7/2021 2:07:55 AM    9 (4280) Starting database contexts clearing...
5/7/2021 2:07:55 AM    9 (4280)  Clearing old contexts in all databases...
5/7/2021 2:07:55 AM    9 (4280)   Database contexts closed: 0
5/7/2021 3:07:55 AM    9 (4280) Starting database contexts clearing...
5/7/2021 3:07:55 AM    9 (4280)  Clearing old contexts in all databases...
5/7/2021 3:07:55 AM    9 (4280)   Database contexts closed: 0
5/7/2021 4:07:55 AM    9 (4280) Starting database contexts clearing...
5/7/2021 4:07:55 AM    9 (4280)  Clearing old contexts in all databases...
5/7/2021 4:07:55 AM    9 (4280)   Database contexts closed: 0
5/7/2021 5:07:55 AM    9 (4280) Starting database contexts clearing...
5/7/2021 5:07:55 AM    9 (4280)  Clearing old contexts in all databases...
5/7/2021 5:07:55 AM    9 (4280)   Database contexts closed: 0
5/7/2021 6:07:55 AM    9 (4280) Starting database contexts clearing...
5/7/2021 6:07:55 AM    9 (4280)  Clearing old contexts in all databases...
5/7/2021 6:07:55 AM    9 (4280)   Database contexts closed: 0
5/7/2021 7:07:55 AM    9 (4280) Starting database contexts clearing...
5/7/2021 7:07:55 AM    9 (4280)  Clearing old contexts in all databases...
5/7/2021 7:07:55 AM    9 (4280)   Database contexts closed: 0

New repo, new job, same problem. Something not right.

[Mike Resseler]

Jimmy, can you ask to escalate this. You can say that it is on my request. I will follow up further later today

[jimmyhurr]

Jimmy, can you ask to escalate this. You can say that it is on my request. I will follow up further later today

Thanks Mike, this has been done! Many thanks for your help.

[Polina]

Jimmy,

There's no need to ask - our VBO support team is on it since yesterday, and your case will be escalated to RnD for further research. Please stay in contact with engineers, as additional debugging might be needed.

Thanks!

[aich365]

Can you check that the time on S3 matches the time on the VBO Server?
We had problems accessing S3 storage when the time was 10 minutes out

[jimmyhurr]

Can you check that the time on S3 matches the time on the VBO Server?
We had problems accessing S3 storage when the time was 10 minutes out

Thanks for the suggestion.
Not sure how to check time on S3 though?
The VBO server is set to sync automatically with time.windows.com and its last sync was 9th May. Seems correct.

[jimmyhurr]

Update: on Friday Support noted that the machine was being backed up by Veeam Agent every night at 10pm and asked me to disable that job. I disabled it, rebooted the host and then restarted one of the new jobs again.

I let it run and run and it got stuck at the same place again.

Code: Select all

5/7/2021 1:06:26 PM   50 (11740) Updating object storage repository: VEEAM_XXX (ID: f3b6b255-b1c8-4e88-9516-3042418da8fa, repository ID: 8fa1ea94-d070-4135-8017-e6dec998a55e)...
5/7/2021 1:06:26 PM   50 (11740)  Object storage repository type: AmazonS3ObjectStorage
5/7/2021 1:06:26 PM   50 (11740)  Bucket: veeamXXX
5/7/2021 1:06:26 PM   50 (11740)  Bucket region: EU (London)
5/7/2021 1:06:26 PM   50 (11740)  AWS region: Global
5/7/2021 1:06:26 PM   50 (11740)  Amazon S3 storage class: Standard
5/7/2021 1:06:26 PM   50 (11740)  Folder: BACKUP
5/7/2021 1:06:26 PM   50 (11740)  Account ID: 6b67e204-bb06-4baf-a2e7-fbeb5dfca8a8
5/7/2021 1:44:41 PM    9 (10568) Starting database contexts clearing...
5/7/2021 1:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/7/2021 1:44:41 PM    9 (10568)   Database contexts closed: 0
5/7/2021 1:48:13 PM   55 (4376) Updating object storage repository: VEEAM_XXX (ID: f3b6b255-b1c8-4e88-9516-3042418da8fa, repository ID: 8fa1ea94-d070-4135-8017-e6dec998a55e)...
5/7/2021 1:48:13 PM   55 (4376)  Object storage repository type: AmazonS3ObjectStorage
5/7/2021 1:48:13 PM   55 (4376)  Bucket: veeamXXX
5/7/2021 1:48:13 PM   55 (4376)  Bucket region: EU (London)
5/7/2021 1:48:13 PM   55 (4376)  AWS region: Global
5/7/2021 1:48:13 PM   55 (4376)  Amazon S3 storage class: Standard
5/7/2021 1:48:13 PM   55 (4376)  Folder: BACKUP
5/7/2021 1:48:13 PM   55 (4376)  Account ID: 6b67e204-bb06-4baf-a2e7-fbeb5dfca8a8
5/7/2021 2:44:41 PM    9 (10568) Starting database contexts clearing...
5/7/2021 2:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/7/2021 2:44:41 PM    9 (10568)   Database contexts closed: 0
5/7/2021 3:44:41 PM    9 (10568) Starting database contexts clearing...
5/7/2021 3:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/7/2021 3:44:41 PM    9 (10568)   Database contexts closed: 0
5/7/2021 4:44:41 PM    9 (10568) Starting database contexts clearing...
5/7/2021 4:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/7/2021 4:44:41 PM    9 (10568)   Database contexts closed: 0
5/7/2021 5:44:41 PM    9 (10568) Starting database contexts clearing...
5/7/2021 5:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/7/2021 5:44:41 PM    9 (10568)   Database contexts closed: 0
5/7/2021 6:44:41 PM    9 (10568) Starting database contexts clearing...
5/7/2021 6:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/7/2021 6:44:41 PM    9 (10568)   Database contexts closed: 0
5/7/2021 7:44:41 PM    9 (10568) Starting database contexts clearing...
5/7/2021 7:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/7/2021 7:44:41 PM    9 (10568)   Database contexts closed: 0
5/7/2021 8:44:41 PM    9 (10568) Starting database contexts clearing...
5/7/2021 8:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/7/2021 8:44:41 PM    9 (10568)   Database contexts closed: 0
5/7/2021 9:44:41 PM    9 (10568) Starting database contexts clearing...
5/7/2021 9:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/7/2021 9:44:41 PM    9 (10568)   Database contexts closed: 0
5/7/2021 10:44:41 PM    9 (10568) Starting database contexts clearing...
5/7/2021 10:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/7/2021 10:44:41 PM    9 (10568)   Database contexts closed: 0
5/7/2021 11:44:41 PM    9 (10568) Starting database contexts clearing...
5/7/2021 11:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/7/2021 11:44:41 PM    9 (10568)   Database contexts closed: 0
5/8/2021 12:44:41 AM    9 (10568) Starting database contexts clearing...
5/8/2021 12:44:41 AM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 12:44:41 AM    9 (10568)   Database contexts closed: 0
5/8/2021 1:00:00 AM   79 (3580) Computing database space in the repository (ID: 6c1dc377-8a46-4452-92ab-bf192085c6bc)...
5/8/2021 1:00:00 AM   79 (3580) Computing database space usage completed
5/8/2021 1:00:00 AM  115 (6660) Computing database space in the repository (ID: 71e255a1-d82e-4ff8-9090-cee43198c269)...
5/8/2021 1:00:01 AM  115 (6660) Computing database space usage completed
5/8/2021 1:00:01 AM   79 (3580) Computing database space in the repository (ID: 8fa1ea94-d070-4135-8017-e6dec998a55e)...
5/8/2021 1:00:01 AM   79 (3580) Computing database space usage completed
5/8/2021 1:44:41 AM    9 (10568) Starting database contexts clearing...
5/8/2021 1:44:41 AM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 1:44:41 AM    9 (10568)   Database contexts closed: 0
5/8/2021 2:44:41 AM    9 (10568) Starting database contexts clearing...
5/8/2021 2:44:41 AM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 2:44:41 AM    9 (10568)   Database contexts closed: 0
5/8/2021 3:44:41 AM    9 (10568) Starting database contexts clearing...
5/8/2021 3:44:41 AM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 3:44:41 AM    9 (10568)   Database contexts closed: 0
5/8/2021 4:44:41 AM    9 (10568) Starting database contexts clearing...
5/8/2021 4:44:41 AM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 4:44:41 AM    9 (10568)   Database contexts closed: 0
5/8/2021 5:44:41 AM    9 (10568) Starting database contexts clearing...
5/8/2021 5:44:41 AM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 5:44:41 AM    9 (10568)   Database contexts closed: 0
5/8/2021 6:44:41 AM    9 (10568) Starting database contexts clearing...
5/8/2021 6:44:41 AM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 6:44:41 AM    9 (10568)   Database contexts closed: 0
5/8/2021 7:44:41 AM    9 (10568) Starting database contexts clearing...
5/8/2021 7:44:41 AM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 7:44:41 AM    9 (10568)   Database contexts closed: 0
5/8/2021 8:44:41 AM    9 (10568) Starting database contexts clearing...
5/8/2021 8:44:41 AM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 8:44:41 AM    9 (10568)   Database contexts closed: 0
5/8/2021 9:44:41 AM    9 (10568) Starting database contexts clearing...
5/8/2021 9:44:41 AM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 9:44:41 AM    9 (10568)   Database contexts closed: 0
5/8/2021 10:44:41 AM    9 (10568) Starting database contexts clearing...
5/8/2021 10:44:41 AM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 10:44:41 AM    9 (10568)   Database contexts closed: 0
5/8/2021 11:44:41 AM    9 (10568) Starting database contexts clearing...
5/8/2021 11:44:41 AM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 11:44:41 AM    9 (10568)   Database contexts closed: 0
5/8/2021 12:44:41 PM    9 (10568) Starting database contexts clearing...
5/8/2021 12:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 12:44:41 PM    9 (10568)   Database contexts closed: 0
5/8/2021 1:44:41 PM    9 (10568) Starting database contexts clearing...
5/8/2021 1:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 1:44:41 PM    9 (10568)   Database contexts closed: 0
5/8/2021 2:44:41 PM    9 (10568) Starting database contexts clearing...
5/8/2021 2:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 2:44:41 PM    9 (10568)   Database contexts closed: 0
5/8/2021 3:44:41 PM    9 (10568) Starting database contexts clearing...
5/8/2021 3:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 3:44:41 PM    9 (10568)   Database contexts closed: 0
5/8/2021 4:44:41 PM    9 (10568) Starting database contexts clearing...
5/8/2021 4:44:41 PM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 4:44:41 PM    9 (10568)   Database contexts closed: 0
5/8/2021 5:44:43 PM    9 (10568) Starting database contexts clearing...
5/8/2021 5:44:43 PM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 5:44:43 PM    9 (10568)   Database contexts closed: 0
5/8/2021 6:44:43 PM    9 (10568) Starting database contexts clearing...
5/8/2021 6:44:43 PM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 6:44:43 PM    9 (10568)   Database contexts closed: 0
5/8/2021 7:44:43 PM    9 (10568) Starting database contexts clearing...
5/8/2021 7:44:43 PM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 7:44:43 PM    9 (10568)   Database contexts closed: 0
5/8/2021 8:44:43 PM    9 (10568) Starting database contexts clearing...
5/8/2021 8:44:43 PM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 8:44:43 PM    9 (10568)   Database contexts closed: 0
5/8/2021 9:44:43 PM    9 (10568) Starting database contexts clearing...
5/8/2021 9:44:43 PM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 9:44:43 PM    9 (10568)   Database contexts closed: 0
5/8/2021 10:44:43 PM    9 (10568) Starting database contexts clearing...
5/8/2021 10:44:43 PM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 10:44:43 PM    9 (10568)   Database contexts closed: 0
5/8/2021 11:44:43 PM    9 (10568) Starting database contexts clearing...
5/8/2021 11:44:43 PM    9 (10568)  Clearing old contexts in all databases...
5/8/2021 11:44:43 PM    9 (10568)   Database contexts closed: 0
5/9/2021 12:44:43 AM    9 (10568) Starting database contexts clearing...
5/9/2021 12:44:43 AM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 12:44:43 AM    9 (10568)   Database contexts closed: 0
5/9/2021 1:00:00 AM   90 (11664) Computing database space in the repository (ID: 6c1dc377-8a46-4452-92ab-bf192085c6bc)...
5/9/2021 1:00:00 AM   90 (11664) Computing database space usage completed
5/9/2021 1:00:00 AM   90 (11664) Computing database space in the repository (ID: 71e255a1-d82e-4ff8-9090-cee43198c269)...
5/9/2021 1:00:01 AM   90 (11664) Computing database space usage completed
5/9/2021 1:00:01 AM  139 (14272) Computing database space in the repository (ID: 8fa1ea94-d070-4135-8017-e6dec998a55e)...
5/9/2021 1:00:01 AM  139 (14272) Computing database space usage completed
5/9/2021 1:44:43 AM    9 (10568) Starting database contexts clearing...
5/9/2021 1:44:43 AM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 1:44:43 AM    9 (10568)   Database contexts closed: 0
5/9/2021 2:44:43 AM    9 (10568) Starting database contexts clearing...
5/9/2021 2:44:43 AM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 2:44:43 AM    9 (10568)   Database contexts closed: 0
5/9/2021 3:44:43 AM    9 (10568) Starting database contexts clearing...
5/9/2021 3:44:43 AM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 3:44:43 AM    9 (10568)   Database contexts closed: 0
5/9/2021 4:44:43 AM    9 (10568) Starting database contexts clearing...
5/9/2021 4:44:43 AM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 4:44:43 AM    9 (10568)   Database contexts closed: 0
5/9/2021 5:44:43 AM    9 (10568) Starting database contexts clearing...
5/9/2021 5:44:43 AM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 5:44:43 AM    9 (10568)   Database contexts closed: 0
5/9/2021 6:44:43 AM    9 (10568) Starting database contexts clearing...
5/9/2021 6:44:43 AM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 6:44:43 AM    9 (10568)   Database contexts closed: 0
5/9/2021 7:44:43 AM    9 (10568) Starting database contexts clearing...
5/9/2021 7:44:43 AM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 7:44:43 AM    9 (10568)   Database contexts closed: 0
5/9/2021 8:44:43 AM    9 (10568) Starting database contexts clearing...
5/9/2021 8:44:43 AM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 8:44:43 AM    9 (10568)   Database contexts closed: 0
5/9/2021 9:44:43 AM    9 (10568) Starting database contexts clearing...
5/9/2021 9:44:43 AM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 9:44:43 AM    9 (10568)   Database contexts closed: 0
5/9/2021 10:44:43 AM    9 (10568) Starting database contexts clearing...
5/9/2021 10:44:43 AM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 10:44:43 AM    9 (10568)   Database contexts closed: 0
5/9/2021 11:44:43 AM    9 (10568) Starting database contexts clearing...
5/9/2021 11:44:43 AM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 11:44:43 AM    9 (10568)   Database contexts closed: 0
5/9/2021 12:44:43 PM    9 (10568) Starting database contexts clearing...
5/9/2021 12:44:43 PM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 12:44:43 PM    9 (10568)   Database contexts closed: 0
5/9/2021 1:44:43 PM    9 (10568) Starting database contexts clearing...
5/9/2021 1:44:43 PM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 1:44:43 PM    9 (10568)   Database contexts closed: 0
5/9/2021 2:44:43 PM    9 (10568) Starting database contexts clearing...
5/9/2021 2:44:43 PM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 2:44:43 PM    9 (10568)   Database contexts closed: 0
5/9/2021 3:44:43 PM    9 (10568) Starting database contexts clearing...
5/9/2021 3:44:43 PM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 3:44:43 PM    9 (10568)   Database contexts closed: 0
5/9/2021 4:44:43 PM    9 (10568) Starting database contexts clearing...
5/9/2021 4:44:43 PM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 4:44:43 PM    9 (10568)   Database contexts closed: 0
5/9/2021 5:44:44 PM    9 (10568) Starting database contexts clearing...
5/9/2021 5:44:44 PM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 5:44:44 PM    9 (10568)   Database contexts closed: 0
5/9/2021 6:44:44 PM    9 (10568) Starting database contexts clearing...
5/9/2021 6:44:44 PM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 6:44:44 PM    9 (10568)   Database contexts closed: 0
5/9/2021 7:44:44 PM    9 (10568) Starting database contexts clearing...
5/9/2021 7:44:44 PM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 7:44:44 PM    9 (10568)   Database contexts closed: 0
5/9/2021 8:44:44 PM    9 (10568) Starting database contexts clearing...
5/9/2021 8:44:44 PM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 8:44:44 PM    9 (10568)   Database contexts closed: 0
5/9/2021 9:44:44 PM    9 (10568) Starting database contexts clearing...
5/9/2021 9:44:44 PM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 9:44:44 PM    9 (10568)   Database contexts closed: 0
5/9/2021 10:44:44 PM    9 (10568) Starting database contexts clearing...
5/9/2021 10:44:44 PM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 10:44:44 PM    9 (10568)   Database contexts closed: 0
5/9/2021 11:44:44 PM    9 (10568) Starting database contexts clearing...
5/9/2021 11:44:44 PM    9 (10568)  Clearing old contexts in all databases...
5/9/2021 11:44:44 PM    9 (10568)   Database contexts closed: 0
5/10/2021 12:44:44 AM    9 (10568) Starting database contexts clearing...
5/10/2021 12:44:44 AM    9 (10568)  Clearing old contexts in all databases...
5/10/2021 12:44:44 AM    9 (10568)   Database contexts closed: 0
5/10/2021 1:00:00 AM   90 (11664) Computing database space in the repository (ID: 6c1dc377-8a46-4452-92ab-bf192085c6bc)...
5/10/2021 1:00:00 AM   90 (11664) Computing database space usage completed
5/10/2021 1:00:00 AM   90 (11664) Computing database space in the repository (ID: 71e255a1-d82e-4ff8-9090-cee43198c269)...
5/10/2021 1:00:01 AM   90 (11664) Computing database space usage completed
5/10/2021 1:00:01 AM   90 (11664) Computing database space in the repository (ID: 8fa1ea94-d070-4135-8017-e6dec998a55e)...
5/10/2021 1:00:01 AM   90 (11664) Computing database space usage completed
5/10/2021 1:44:44 AM    9 (10568) Starting database contexts clearing...
5/10/2021 1:44:44 AM    9 (10568)  Clearing old contexts in all databases...
5/10/2021 1:44:44 AM    9 (10568)   Database contexts closed: 0
5/10/2021 2:44:44 AM    9 (10568) Starting database contexts clearing...
5/10/2021 2:44:44 AM    9 (10568)  Clearing old contexts in all databases...
5/10/2021 2:44:44 AM    9 (10568)   Database contexts closed: 0
5/10/2021 3:44:44 AM    9 (10568) Starting database contexts clearing...
5/10/2021 3:44:44 AM    9 (10568)  Clearing old contexts in all databases...
5/10/2021 3:44:44 AM    9 (10568)   Database contexts closed: 0
5/10/2021 4:44:44 AM    9 (10568) Starting database contexts clearing...
5/10/2021 4:44:44 AM    9 (10568)  Clearing old contexts in all databases...
5/10/2021 4:44:44 AM    9 (10568)   Database contexts closed: 0
5/10/2021 5:44:44 AM    9 (10568) Starting database contexts clearing...
5/10/2021 5:44:44 AM    9 (10568)  Clearing old contexts in all databases...
5/10/2021 5:44:44 AM    9 (10568)   Database contexts closed: 0
5/10/2021 6:44:44 AM    9 (10568) Starting database contexts clearing...
5/10/2021 6:44:44 AM    9 (10568)  Clearing old contexts in all databases...
5/10/2021 6:44:44 AM    9 (10568)   Database contexts closed: 0
5/10/2021 7:44:44 AM    9 (10568) Starting database contexts clearing...
5/10/2021 7:44:44 AM    9 (10568)  Clearing old contexts in all databases...
5/10/2021 7:44:44 AM    9 (10568)   Database contexts closed: 0
5/10/2021 8:44:44 AM    9 (10568) Starting database contexts clearing...
5/10/2021 8:44:44 AM    9 (10568)  Clearing old contexts in all databases...
5/10/2021 8:44:44 AM    9 (10568)   Database contexts closed: 0
5/10/2021 9:44:44 AM    9 (10568) Starting database contexts clearing...
5/10/2021 9:44:44 AM    9 (10568)  Clearing old contexts in all databases...
5/10/2021 9:44:44 AM    9 (10568)   Database contexts closed: 0
5/10/2021 10:44:44 AM    9 (10568) Starting database contexts clearing...
5/10/2021 10:44:44 AM    9 (10568)  Clearing old contexts in all databases...
5/10/2021 10:44:44 AM    9 (10568)   Database contexts closed: 0

[jimmyhurr]

OK so I had a response from Support just now. I don't understand this response at all!

After some research we've found out that the bot sites created by third party SP applications.
Those sites are domainless, hence we can not phisically backup them.
Our advice would be to remove the site from your tenant completely.
You can do that by using the Remove-SPOSite command.
Let me know your thoughts about it.

I've asked for clarification, but it is now nearly a week since I have reported this issue and I have not been able to perform a backup on two tenants. The backup was working fine until I installed 5.0.1.225 and then started doing this immediately after that - this fact has not been acknowledged or mentioned by support.

The support agent is persistently calling me either Malcolm or Magnus for some reason too despite me telling him that I am called James - this leads me to believe there is some mix up in tickets or something....

Meanwhile the backup is still going, 77hrs later, stalled at the same spot.

Can anyone help me?

[pesos]

Subscribe. We also have jobs taking dozens to hundreds of hours. Trying to stop a job puts it into a queued state it never comes out of. Waiting for other jobs to finish so I can reboot the veeam o365 server.

[Mike Resseler]

@jimmyhurr

Let me verify what is going on.

@pesos
Please create a support call also. It is not normal

[jimmyhurr]

Update: I had another reply from support. I seem to be allocated one reply per day....!

Support confirmed that the message they sent on 10th May was destined for another customer I don't even understand how this can occur?
They then asked me EXACTLY the same question they asked me on Friday 7th May to which I have already replied previously. They have basically not even read those previous replies of mine. So now I will have to wait another 24hrs to get a reply to something that I already replied about last week....

This is a little ridiculous. I have now used the "talk to a manager" option in the Support area because I feel somewhat let down by this. Veeam is great, but so far my experience of Support is rather lacking. Yes, this isn't the end of the world, no, nobody has died, but on the other hand I'm a paying customer (granted I'm only small fry) and I'm getting nowhere.

[Mike Resseler]

Jimmy,

I am trying to get this escalated and I am glad you used the button. This is NOT what you should expect from our support division. Honestly, I don't know what went wrong here...

[jimmyhurr]

Thanks Mike.

[jimmyhurr]

Looks like something has worked as I have a new support agent requesting a remote session. I'll report back. Thanks!

[Mike Resseler]

Thanks for keeping me informed. We are keeping an eye on it also, and again, our apologies for this

[douglas Fernandes]

@jimmyhurr

Unfortunately I believe that you do not be the only have this problem, after made the upgrade from 4 to 5 version.

My company is 6 months without backup at the mailboxes completed and I had have several Veeam support teams, Locally "Brazil" and international, but no one has solved it for me yet.

I don't know what else I need to do to get backup my jobs to the normal.

I am currently using MS to restore the backup when asked.

[Polina]

Douglas,

Can you please provide me your latest support case ID?

[Johnny L]

Hello,

We are experiencing a similar, if not the same, issue. Some jobs which are configured to backup Microsoft Teams stops processing. I have yet to see this issue on a job not involving Teams, though.

When the processing stops the proxy-log only shows:

Code: Select all

03.06.2021 12:11:06   36 (3540) Work item <GUID> waiting for work item <OtherGUID>
03.06.2021 12:47:27    9 (3108) Starting database contexts clearing...
03.06.2021 12:47:27    9 (3108)  Clearing old contexts in all databases...
03.06.2021 12:47:27    9 (3108)   Database contexts closed: 0

I don't have the possibility to allow a job to run for hours as we have several other jobs that need to finish, so I am not sure if waiting an extended period of time would resolve it.

The previous backup-job this happened to was "resolved" by forcing a new full backup without any explanation as to why this might have occured. The same solution does not work for this job.

(ID of closed ticket: #02363075)

[Polina]

Johnny,

The latest cumulative patch KB4158 should address this issue. Did you give it a chance already?

[Johnny L]

Polina,

Huh, I didn't even know there was a new patch.. After an hour of upgrading and making sure all services came back up: it works!

[Polina]

Cool!

Btw, we noticed that often a patch is released but remains unseen by many customers for quite a long time, which means we need to improve our communications about such updates. Currently, we maintain a KB4106 with all the build numbers and links, and also post it on forums. Any ideas on how/where would you prefer to get notified?

[jimmyhurr]

Hi All, I wanted to come back and report on this as others seem to be having similar issues. I am backing up to AWS S3, not a local repo but I believe the issue exists also on local repos. The issue is linked to the synchronisation of Teams.

On my side, this has finally been resolved - great news! Initially support provided me with an an in-house unofficial patch which didn't work, and I also installed KB4158 as requested (not sure if they were one and the same though).

Even with the patch, the only way for me to get this resolved on one tenant was to completely start from scratch with a new AWS S3 repo, and exclude "Teams" from the initial sync like this:



Once the initial sync had been fully completed successfully (mine took a long time as this site only has low bandwidth upload that has to be throttled during the day) I then removed the exclusion on Teams, and the Teams were successfully synchronised.

It seems that actual issue is that Veeam is waiting to access something for some reason and until all other items in your job have been fully backed up, it will never be able to access the Team. You will find the log contains a line like below (the first work item GUID in the message refers to an Azure AD Office365 enabled group) - if this occurs the job will never complete and there will be no upload/download activity at all:

Code: Select all

5/17/2021 2:03:40 PM 34 (10436) Work item 3f2595dd-a96c-4502-89a2-f3e66d3112fa waiting for work item 520a14ec-59d9-43b8-9187-655020b0d887

The line in the log like this are not related, this just occurs regularly:

Code: Select all

03.06.2021 12:47:27    9 (3108) Starting database contexts clearing...
03.06.2021 12:47:27    9 (3108)  Clearing old contexts in all databases...
03.06.2021 12:47:27    9 (3108)   Database contexts closed: 0

Anyway support were great after the initial blip and working with them finally got a result.

[Polina]

Hi James,

Thanks for the heads-up.

Before accessing a Team itself VBO needs to have the corresponding mailbox and site backup completed, and likely this is why you see the 'waiting' message in the logs. What makes you think that Teams won't ever be accessed and the job will never complete?

[jimmyhurr]

@Polina - this was the bug itself - it systematically occurred whenever I tried to run a full "org" backup. It was R&D/Support that suggested I exclude Teams and let everything complete before I unexcluded Teams. I'm only reporting what happened to me.

[Polina]

OK, I'll take a closer look at your case to make sure if the issue is resolved in the latest patch or any additional fixes needed.

Thanks!