Error (ThrottledFolderBind): Exception calling "Bind" with "3" argument(s): "The specified object was not found in the store., Default folder Root not found.

[yfernanh]

Hello @David-Barrett-MS,

Thank you for your great scripts!

What I would like to achieve in Exchange Online is to copy folders from on mailbox to another mailbox in two parts. Because license user's is EOL. First part, copy mailbox A in the mailbox B. Second part, copy archive mailbox A in the another archive mailbox B.

Thus, when I run the script Merge-MailboxFolders.ps1:

.\Merge-MailboxFolder.ps1 -SourceMailbox $SourceMailboxA -TargetMailbox $SourceMailboxB -Office365 -OAuth -OAuthTenantId $tenantId -OAuthClientId $clientId -OAuthRedirectUri $redirectUrl -Copy -ProcessSubfolders -OAuthSecretKey $secretKey -CreateTargetFolder -Impersonate

.\Merge-MailboxFolder.ps1 -SourceMailbox $SourceMailboxA -SourceArchive -TargetMailbox $SourceMailboxB -TargetArchive -Office365 -OAuth -OAuthTenantId $tenantId -OAuthClientId $clientId -OAuthRedirectUri $redirectUrl -Copy -CreateTargetFolder -ProcessSubfolders -OAuthSecretKey $secretKey

I get the following output:

Merge-MailboxFolder.ps1 version 1.2.6 starting Using EWS Managed API found at: C:\Program Files\Microsoft\Exchange\Web Services\2.2\Microsoft.Exchange.WebServices.dll

Processing mailbox SourceMailboxA Error (ThrottledFolderBind): Excepción al llamar a "Bind" con los argumentos "3": "The specified object was not found in the store., Default folder Root not found." Failed to open target message store (SourceMailboxB)

Merge-MailboxFolder.ps1 version 1.2.6 starting Using EWS Managed API found at: C:\Program Files\Microsoft\Exchange\Web Services\2.2\Microsoft.Exchange.WebServices.dll

Processing mailbox SourceMailboxA Error (ThrottledFolderBind): Excepción al llamar a "Bind" con los argumentos "3": "Access is denied. Check credentials and try again., Archive mailbox:f9db971c-dfd6-4b6e-89aa-af4652bdb695" Failed to open target message store (SourceMailboxB)

Do I have missed something related to permissions?

Thank you in advance.

[yfernanh]

Merge-MailboxFolder.ps1 version 1.2.6 starting DETALLADO: Loading Microsoft.Exchange.WebServices.dll vSystem.Object[] found at: System.Object[] Using EWS Managed API found at: C:\Program Files\Microsoft\Exchange\Web Services\2.2\Microsoft.Exchange.WebServices.dll

Processing mailbox SourceMailboxA DETALLADO: POST https://login.microsoftonline.com/f752ca52-e763-497a-939c-e7b7813268bf/oauth2/v2.0/token with -1-byte payload DETALLADO: received 1615-byte response of content type application/json; charset=utf-8 DETALLADO: Currently caching 1 ExchangeService objects DETALLADO: [ThrottledFolderBind]Attempting to bind to folder MsgFolderRoot (SourceMailboxA) DETALLADO: [ThrottledFolderBind]Successfully bound to folder MsgFolderRoot (SourceMailboxA) DETALLADO: Currently caching 2 ExchangeService objects DETALLADO: [ThrottledFolderBind]Attempting to bind to folder MsgFolderRoot (SourceMailboxB) Error (ThrottledFolderBind): Excepción al llamar a "Bind" con los argumentos "3": "The specified object was not found in the store., Default folder Root not found." DETALLADO: FAILED to bind to folder MsgFolderRoot (SourceMailboxB) Failed to open target message store (SourceMailboxB)

[David-Barrett-MS]

$SourceMailboxA will require FullAccess permissions to $SourceMailboxB.

[yfernanh]

Thank you very much for your help. The agent has already been run but we don't see that it has copied anything. In the log we see many errors of this type: Error ErrorInternalServerError () reported for item (attempt 1): and at the end it writes: 83 items reported error during batch request (if throttled, some failures are expected, and will be retried). I attach the log so you can see it.

17/04/2023 13:56:20 [MoveItems]No subfolders found: SourceMailboxA:\Principio del almacén de información\Archivo 17/04/2023 13:56:20 [ThrottledFolderBind]Attempting to bind to folder AAMkADE5ZjI3YzAzLTdlYjgtNGYwYy1hM2QzLTVhYzkwNjNkMjMwNgAuAAAAAAACqY/anShJQK206zGg3o1XAQDKRgv8N3cERL7YSK7vdnOWAAAcy/x0AAA= 17/04/2023 13:56:20 [ThrottledFolderBind]Successfully bound to folder AAMkADE5ZjI3YzAzLTdlYjgtNGYwYy1hM2QzLTVhYzkwNjNkMjMwNgAuAAAAAAACqY/anShJQK206zGg3o1XAQDKRgv8N3cERL7YSK7vdnOWAAAcy/x0AAA= 17/04/2023 13:56:20 [IsFolderExcluded]Folder is of type: 1 17/04/2023 13:56:20 [IsFolderExcluded]Folder not identified as search folder 17/04/2023 13:56:20 [MoveItems]Creating target folder Archivos 17/04/2023 13:56:20 Error (MoveItems): Excepción al llamar a "Save" con los argumentos "1": "Operation would change object type, which is not permitted." 17/04/2023 13:56:20 [MoveItems]FAILED TO CREATE TARGET FOLDER: Archivos 17/04/2023 13:56:20 [ThrottledFolderBind]Attempting to bind to folder AQMkADE5ZjI3YzAzLTdlYjgtNGYwYy1hM2QzLTVhYzkwNjNkMjMwNgAuAAADAqmP2p0oSUCttOsxoN6NVwEAykYL/Dd3BES+2Eiu73ZzlgAAAgEMAAAA 17/04/2023 13:56:20 [ThrottledFolderBind]Successfully bound to folder AQMkADE5ZjI3YzAzLTdlYjgtNGYwYy1hM2QzLTVhYzkwNjNkMjMwNgAuAAADAqmP2p0oSUCttOsxoN6NVwEAykYL/Dd3BES+2Eiu73ZzlgAAAgEMAAAA 17/04/2023 13:56:20 [IsFolderExcluded]Folder is of type: 1 17/04/2023 13:56:20 [IsFolderExcluded]Folder not identified as search folder 17/04/2023 13:56:20 [MoveItems]Target folder already exists 17/04/2023 13:56:20 [ThrottledFolderBind]Attempting to bind to folder AQMkADE5ZjI3YzAzLTdlYjgtNGYwYy1hM2QzLTVhYzkwNjNkMjMwNgAuAAADAqmP2p0oSUCttOsxoN6NVwEAykYL/Dd3BES+2Eiu73ZzlgAAAgEMAAAA 17/04/2023 13:56:20 [ThrottledFolderBind]Successfully bound to folder AQMkADE5ZjI3YzAzLTdlYjgtNGYwYy1hM2QzLTVhYzkwNjNkMjMwNgAuAAADAqmP2p0oSUCttOsxoN6NVwEAykYL/Dd3BES+2Eiu73ZzlgAAAgEMAAAA 17/04/2023 13:56:20 [ThrottledFolderBind]Attempting to bind to folder AAMkAGRkOGMzZjQ3LWM4ZTEtNGNhMS04N2FiLTM1MjA3NWNkYjU1ZAAuAAAAAABi0dlSoKv6Qo40Ut87UjQAAQASDXI2F0mFQZwNUHhLanpdAAAAAAEMAAA= 17/04/2023 13:56:20 [ThrottledFolderBind]Successfully bound to folder AAMkAGRkOGMzZjQ3LWM4ZTEtNGNhMS04N2FiLTM1MjA3NWNkYjU1ZAAuAAAAAABi0dlSoKv6Qo40Ut87UjQAAQASDXI2F0mFQZwNUHhLanpdAAAAAAEMAAA= 17/04/2023 13:56:20 [MoveItems]Copying from SourceMailboxA:\Principio del almacén de información\Bandeja de entrada to SourceMailboxB:\Principio del almacén de información\Bandeja de entrada 17/04/2023 13:56:20 [ThrottledFolderBind]Attempting to bind to folder AQMkADE5ZjI3YzAzLTdlYjgtNGYwYy1hM2QzLTVhYzkwNjNkMjMwNgAuAAADAqmP2p0oSUCttOsxoN6NVwEAykYL/Dd3BES+2Eiu73ZzlgAAAgEMAAAA 17/04/2023 13:56:20 [ThrottledFolderBind]Successfully bound to folder AQMkADE5ZjI3YzAzLTdlYjgtNGYwYy1hM2QzLTVhYzkwNjNkMjMwNgAuAAADAqmP2p0oSUCttOsxoN6NVwEAykYL/Dd3BES+2Eiu73ZzlgAAAgEMAAAA 17/04/2023 13:56:20 [MoveItems]Building list of items to copy 17/04/2023 13:56:20 76 items found; attempting to copy 17/04/2023 13:56:21 Current batch size is 100 17/04/2023 13:56:21 Added to batch: AQMkADE5ZjI3YzAzLTdlYjgtNGYwYy1hM2QzLTVhYzkwNjNkMjMwNgBGAAADAqmP2p0oSUCttOsxoN6NVwcAykYL/Dd3BES+2Eiu73ZzlgAAAgEMAAAAykYL/Dd3BES+2Eiu73ZzlgAEpQmpzQAAAA== . . . 17/04/2023 13:56:21 Ignored null source item (index 76) 17/04/2023 13:56:21 Sending batch request to copy 76 items (76 remaining) 17/04/2023 13:56:31 Batch request completed 17/04/2023 13:56:31 Error ErrorInternalServerError () reported for item (attempt 1): AQMkADE5ZjI3YzAzLTdlYjgtNGYwYy1hM2QzLTVhYzkwNjNkMjMwNgBGAAADAqmP2p0oSUCttOsxoN6NVwcAykYL/Dd3BES+2Eiu73ZzlgAAAgEMAAAAykYL/Dd3BES+2Eiu73ZzlgAEpQmpzQAAAA== . . . 17/04/2023 13:56:31 76 items reported error during batch request (if throttled, some failures are expected, and will be retried) 17/04/2023 13:56:31 Current batch size is 100 17/04/2023 13:56:32 Added to batch: AQMkADE5ZjI3YzAzLTdlYjgtNGYwYy1hM2QzLTVhYzkwNjNkMjMwNgBGAAADAqmP2p0oSUCttOsxoN6NVwcAykYL/Dd3BES+2Eiu73ZzlgAAAgEMAAAAykYL/Dd3BES+2Eiu73ZzlgAEpQmpzQAAAA== . . . 17/04/2023 13:56:32 Ignored null source item (index 76) 17/04/2023 13:56:32 Sending batch request to copy 76 items (76 remaining) 17/04/2023 13:56:42 Batch request completed

[yfernanh]

17/04/2023 14:54:24 Sending batch request to copy 50 items (661 remaining) 17/04/2023 14:54:31 Batch request completed 17/04/2023 14:54:31 [ApplyEWSOAuthCredentials] OAuth access token invalid, attempting to renew 17/04/2023 14:54:31 [ApplyEWSOAuthCredentials] OAuth Token renewal failed

[David-Barrett-MS]

Does the OAuth error happen after one hour? I'd have to check that, but I haven't changed the OAuth code for a while so surprised there is an issue there.

The other errors in the log look like message corruption or issues with specific messages (e.g. Operation would change object type, which is not permitted. is unusual) so for those you'd need to investigate the specific items causing an error.

[David-Barrett-MS]

Just published v1.2.9 which contains various bugfixes. As there hasn't been any feedback on this issue for a while I'm closing it.

[Martijn-Lucas]

Hi @David-Barrett-MS,

Thanks for the amazing script. Unfortunately with the version V1.2.9 I'll get the error OAuth Token renewal failed. This was approximately after one Hour. Is this something you can look at?

I used the settings below.

[David-Barrett-MS]

Looking at the code, the check for expiry after the token is renewed is slightly different to that before, so I wonder if that is the issue. To test this, please try changing line 476 as follows:

if ( $script:oauthTokenAcquireTime.AddSeconds($script:oauthToken.expires_in) -lt [DateTime]::UtcNow )

(assuming 1.2.9 of the script).

Let me know if that resolves. I will set up some test myself but that will take me some time.

[Martijn-Lucas]

I'll try it and let you know the results. Just to be sure, I guess you mean change -le to -lt at line 477? (if ( $script:oauthTokenAcquireTime.AddSeconds($script:oauthToken.expires_in) -le [DateTime]::Now ))

[David-Barrett-MS]

Just checked, and it is line 477 yes (I removed a debug line from my current version of the script and hadn't realised). I also changed ::Now to ::UtcNow so as to not get confused by timezones. It is the UtcNow change that is more important (I suspect that is where the issue is coming from).

[David-Barrett-MS]

Hmm... I may have got that the wrong way round... The -lt I think needs to remain as -gt (as then the check is that token expires in the future). If the issue remains, please change that back (but keep the ::UtcNow change).

[Martijn-Lucas]

At this moment I get the error below. With at line 477: if ( $script:oauthTokenAcquireTime.AddSeconds($script:oauthToken.expires_in) -lt [DateTime]::UtcNow )

You think I need to change the -lt to -gt because it was -le and you mention I think needs to remain as -gt

[David-Barrett-MS]

Looks like the renewal did actually fail for some reason (there is no expiry date shown). I'll need to do some testing.

[David-Barrett-MS]

So I think I've traced the error to line 488, which should be:

$service.Credentials = New-Object Microsoft.Exchange.WebServices.Data.OAuthCredentials($exchangeCredentials)

I'll publish the fixed version once I've tested fully (need to confirm the above change works and then test the other OAuth flows). Takes a while to test as you can't revoke access tokens so I need to wait for them to expire.

[David-Barrett-MS]

I've fixed the OAuth token renewal issues in 1.3.0 which has just been published.

[Martijn-Lucas]

Thanks for your quick responses and fixes! The OAuth is now working. Only now I'm facing an error "the request failed. The operation has timed out." Is this related to the change you made?

[David-Barrett-MS]

Please raise new issues rather than reopening/reusing existing ones. It's difficult to keep track otherwise.

Timeout is a network error, not something that the code would generate (I didn't make any changes other than OAuth in this release).