search

Azure / azure-storage-azcopy

The new Azure Storage data transfer utility - AzCopy v10
MIT License
614 stars 222 forks source link

Negative pending transfer count #2880

Open eindenbom opened 4 days ago

eindenbom commented 4 days ago

When resuming a canceled job with some pending and some failed transfers, number of pending transfers can become negative:

100.2 %, 3739321 Done, 106941 Failed, 4294961036 Pending, 0 Skipped, 3840002 Total, 2-sec Throughput (Mb/s): 108.305

as transfers failed on previous iteration become pending when resumed.

azcopy version 10.27.1
souravgupta-msft commented 2 days ago

Hi @eindenbom. Can you please share more details like the commands used and what you are seeing in the in the pending transfer count. Also, what is the total number of files you are transferring?

eindenbom commented 2 days ago

This was a server to server transfer of 3 840 002 blobs (see above), but the problem is easy to reproduce on a small set. Reproduction sequence:

  1. Reduce AZCOPY_CONCURRENCY_VALUE
  2. Start transfer
  3. Wait for scanning to complete and cancel it
  4. Disable auto login
  5. Resume transfer and wait for it to fail
  6. Enable auto login
  7. Resume transfer and observe negative pending transfer count

Console output:

(dec3) PS D:\source> $env:AZCOPY_CONCURRENCY_VALUE=5
(dec3) PS D:\source> azcopy copy --recursive https://mlvideopremwestus2.blob.core.windows.net/test-set/mp4/640x360_30fps/ https://mlvideopremwestus2.blob.core.windows.net/job-outputs/checkpoints/tmp
INFO: Scanning...
INFO: Login with AzCliCreds succeeded
INFO: Authenticating to destination using Azure AD
INFO: Authenticating to source using Azure AD
INFO: Any empty folders will not be processed, because source and/or destination doesn't have full folder support

Job d37c5d2f-b8d1-5549-40f3-123c0164bcbd has started
Log file is located at: C:\Users\eindenbom\.azcopy\d37c5d2f-b8d1-5549-40f3-123c0164bcbd.log

INFO: Cancellation requested. Beginning clean shutdown...
28.8 %, 43 Done, 0 Failed, 120 Pending, 0 Skipped, 163 Total, 2-sec Throughput (Mb/s): 170.0043panic: close of nil channel

goroutine 231 [running]:
github.com/Azure/azure-storage-azcopy/v10/ste.(*jobMgr).reportJobPartDoneHandler(0xc000620708)
        D:/a/1/s/ste/mgr-JobMgr.go:718 +0x327
created by github.com/Azure/azure-storage-azcopy/v10/ste.NewJobMgr in goroutine 1
        D:/a/1/s/ste/mgr-JobMgr.go:203 +0xc88
(dec3) PS D:\source> $env:AZCOPY_AUTO_LOGIN_TYPE=""
(dec3) PS D:\source> azcopy jobs resume d37c5d2f-b8d1-5549-40f3-123c0164bcbd
INFO: Autologin not specified.
INFO: Authenticating to destination using Unknown, Please authenticate using Microsoft Entra ID (https://aka.ms/AzCopy/AuthZ), use AzCopy login, or append a SAS token to your Azure URL.
INFO: Authenticating to source using Unknown, Please authenticate using Microsoft Entra ID (https://aka.ms/AzCopy/AuthZ), use AzCopy login, or append a SAS token to your Azure URL.

Job d37c5d2f-b8d1-5549-40f3-123c0164bcbd has started
Log file is located at: C:\Users\eindenbom\.azcopy\d37c5d2f-b8d1-5549-40f3-123c0164bcbd.log

28.8 %, 45 Done, 118 Failed, 0 Pending, 0 Skipped, 163 Total, 2-sec Throughput (Mb/s): 112.6258

Job d37c5d2f-b8d1-5549-40f3-123c0164bcbd summary
Elapsed Time (Minutes): 0.1
Number of File Transfers: 163
Number of Folder Property Transfers: 0
Number of Symlink Transfers: 0
Total Number of Transfers: 163
Number of File Transfers Completed: 45
Number of Folder Transfers Completed: 0
Number of File Transfers Failed: 118
Number of Folder Transfers Failed: 0
Number of File Transfers Skipped: 0
Number of Folder Transfers Skipped: 0
Total Number of Bytes Transferred: 83466053
Final Job Status: CompletedWithErrors

(dec3) PS D:\source> $env:AZCOPY_AUTO_LOGIN_TYPE="AZCLI"
(dec3) PS D:\source> azcopy jobs resume d37c5d2f-b8d1-5549-40f3-123c0164bcbd
INFO: Login with AzCliCreds succeeded
INFO: Authenticating to destination using Azure AD
INFO: Authenticating to source using Azure AD

Job d37c5d2f-b8d1-5549-40f3-123c0164bcbd has started
Log file is located at: C:\Users\eindenbom\.azcopy\d37c5d2f-b8d1-5549-40f3-123c0164bcbd.log

347.2 %, 163 Done, 118 Failed, 4294967178 Pending, 0 Skipped, 163 Total, 2-sec Throughput (Mb/s): 68.8408

Job d37c5d2f-b8d1-5549-40f3-123c0164bcbd summary
Elapsed Time (Minutes): 0.2001
Number of File Transfers: 163
Number of Folder Property Transfers: 0
Number of Symlink Transfers: 0
Total Number of Transfers: 163
Number of File Transfers Completed: 163
Number of Folder Transfers Completed: 0
Number of File Transfers Failed: 118
Number of Folder Transfers Failed: 0
Number of File Transfers Skipped: 0
Number of Folder Transfers Skipped: 0
Total Number of Bytes Transferred: 289765073
Final Job Status: Completed
souravgupta-msft commented 2 days ago

Thanks for the explanation. I am able to replicate the issue. We will add this in our backlog.