search

Azure / azure-storage-azcopy

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

AzCopy v10.3.2 gives spurious "RESPONSE Status: 404 The specified resource does not exist" #745

Closed GezHenry closed 1 year ago

GezHenry commented 5 years ago

AzCopy Version 10.3.2 (issue also encountered on previous versions) Platform : Windows (Server 2016, Desktop 8.1)

Command details

set AZCOPY_SPA_CLIENT_SECRET= azcopy login --service-principal --application-id --tenant-id= azcopy copy "\\Prod\Output\Prod.csv" "https://.blob.core.windows.net/" azcopy logout

Problem encountered ... The AZCOPY executes successfuly and file is transferred to Azure BLOB. However, EventViewer has ERROR entry ... .... RESPONSE Status: 404 The specified resource does not exist. .... ERROR: -> github.com/Azure/azure-storage-blob-go/azblob.newStorageError, /home/vsts/go/pkg/mod/github.com/!azure/azure-storage-blob-go@v0.7.0/azblob/zc_storage_error.go:42 ... ===== RESPONSE ERROR (ServiceCode=ResourceNotFound) ===== Description=The specified resource does not exist. RequestId:0fc3306f-b01e-000b-46da-9ac18d000000 Time:2019-11-14T11:00:03.3860278Z, Details: Code: ResourceNotFound GET https://.blob.core.windows.net/?restype=container&timeout=901 User-Agent: [Azure-Storage/0.7 (go1.12; Windows_NT)] X-Ms-Client-Request-Id: [a657fb9e-02e0-4240-44ab-65367d8a790c] X-Ms-Version: [2018-11-09]

How can we reproduce the problem in the simplest way? Create Azure BLOB with Client secret Authorisation and execute AZCOPY corresponding to above example

Have you found a mitigation/solution? No. This requires resolving because we montior EventViewer to alert when AZCOPY error occurs. Hence a lot of redundant errors being alerted for AZCOPY executions that are successful

JohnRusk commented 5 years ago

Thanks for logging this. I think I understand what's going on.

As a workaround, and I'm not sure if this would help, but AzCopy does set an exit code. That's not visible in the event log, but it can be checked after AzCopy is run to see if it succeeded or not. E.g. in PowerShell you can see if AzCopy had any real errors by checking $LastExitCode after AzCopy exits. It will be zero if, and only if, the job ran to completion and there were no failed files.

GezHenry commented 5 years ago

I will have a look at the workaround. However, is there a resolution to prevent the spurious errors occuring in Event Viewer?

JohnRusk commented 5 years ago

There's no current workaround, I'm sorry. I .e. no way to turn that off. It happens at a fairly low level in the stack that we use for our REST calls, and we don't currently have a way to turn it off. I've added something about this to our backlog, to remind us to look into maybe adding a way to turn it off.

GezHenry commented 5 years ago

So, can the error be ignored in Event Viewer or could be there be instances where that error string is a real error? i.e. Can we filter/ignore in the error stack..

ERROR: -> github.com/Azure/azure-storage-blob-go/azblob.newStorageError, /home/vsts/go/pkg/mod/github.com/!azure/azure-storage-blob-go@v0.7.0/azblob/zc_storage_error.go:42

JohnRusk commented 5 years ago

I don't think you can use the callstack as shown in your message. I might have another workaround for you. Will post details soon.

JohnRusk commented 5 years ago

OK, I've reproduced your issue so that I can look at the full text that ends up in the event log. It turns out that there's a bigger call stack logged at the bottom of the message. You can filter on that. I'd suggest you ignore errors where both of the following lines exist:

github.com/Azure/azure-storage-azcopy/cmd.getBlobCredentialType.func1
github.com/Azure/azure-storage-azcopy/cmd.(*cookedCopyCmdArgs).isDestDirectory
GezHenry commented 5 years ago

The suggested 2 lines also exist where this is a valid error; e.g.

  1. AZCOPY to non-existent Destination Storage Account outputs those 2 lines in error stack and also following line ... ERROR: -> github.com/Azure/azure-pipeline-go/pipeline.NewError, /home/vsts/go/pkg/mod/github.com/!azure/azure-pipeline-go@v0.2.1/pipeline/error.go:154 HTTP request failed

  2. AZCOPY to valid Destination Storage Account but to non-existent BLOB container outputs those 2 lines in error stack and also following line ... ERROR: -> github.com/Azure/azure-storage-blob-go/azblob.newStorageError, /home/vsts/go/pkg/mod/github.com/!azure/azure-storage-blob-go@v0.7.0/azblob/zc_storage_error.go:42

Example 2 gives same error stack (i.e. including "zc_storage_error:go.42") as the original example raised where it is a spurious error.

I'm not sure how we can differentiate between real error and spurious error logged in EventView ?

JohnRusk commented 5 years ago

In those examples, is only one error logged?

GezHenry commented 5 years ago

From what I observe, the 'spurious' error is written once to EventViewer. When there is a genuine error then it depends whether it is logged more than once ....

  1. If AZCOPY from non-existent Source endpoint (e.g. cannot connect with server where source file/s stored) then it is logged once to EventViewer with RESPONSE Status: 404 The specified resource does not exist. ... ERROR:-> github.com/Azure/azure-storage-blob-go/azblob.newStorageError, /home/vsts/go/pkg/mod/github.com/!azure/azure-storage-blob- go@v0.7.0/azblob/zc_storage_error.go:42 ... ... and AZCOPY outputs .... failed to perform copy command due to error: cannot start job due to error: cannot scan the path \c-cotfps\Output\Extract.csv, please verify that it is a valid.

  2. If AZCOPY to non-existent Destination Storage Account or BLOB container then it is logged several times to EventViewer with same error stack; i.e. retries AZCopy command maybe every 1 minute so that it logs an error every 1 minute, for example, if it continues to not connect with the endpoint BLOB/Container.

GezHenry commented 5 years ago

If there is no workaround to ensure that genuine errors and spurious errors can be differentiated in Windows EventViewer, then we need the "spurious errors" issue resolving as a priority.

JohnRusk commented 5 years ago

@GezHenry, thanks for the info.

The logging to the event log happens in the "pipeline" library that AzCopy uses for its HTTP traffic. The fact that the logging is not in the core AzCopy code base itself has an important implication, which was highlighted in my mind by your most recent comment above. The event logging only captures HTTP errors. E.g. if a transfer fails for some other reason that doesn't have an HTTP error, it won't be logged to the event log.

If I understand correctly you're aiming to use the event log info as the primary means of detecting success and failure. I'm sorry to say it's not currently suitable for that purpose, and wouldn't be suitable even if we removed the spurious errors - because some failures may not result in any event log entries at all.

Right now the only supported means of detecting success and failure are the application return code, the application's output to stdout (which can optionally be in JSON form for easier parsing) and the log keywords documented here: https://docs.microsoft.com/en-us/azure/storage/common/storage-use-azcopy-configure#troubleshoot-issues.

A possible workaround, to get reliable event log status, might be to wrap the invocation of AzCopy in a PowerShell script, and have it check $LastExitCode and then call Write-EventLog if the code is non-zero.

I'm sorry we don't have anything better right now. I've added this issue to our backlog for future consideration. But at this stage I can't guarantee whether it will be processed as a priority (since we're already fully committed to other priority work). So I think the workaround suggested above is your best option right now.

ricolaten commented 4 years ago

@JohnRusk I've a similar problem where azcopy floods the windows event logs because it cannot reach this address: aka.ms/azcopyv10-version-metadata?timeout=901. This generates a HTTP error which - as you pointed out - ends up in the event log. I have not found a way to stop azcopy from trying to verify if new versions are available. I'm using azcopy in a corporate environment on back-end infrastructure where we only allow access to URL via whitelisting. Azcopy sync is ran regularly to maintain the sync between blob and local storage.

JohnRusk commented 4 years ago

Thanks ricolanten. FYI I'm handing this issue over to @zezha-msft / @adreed-msft / @nakulkar-msft

supermistag commented 2 years ago

I've a similar problem where azcopy floods the windows event logs because it cannot reach this address: aka.ms/azcopyv10-version-metadata?timeout=901. This generates a HTTP error which - as you pointed out - ends up in the event log. I have not found a way to stop azcopy from trying to verify if new versions are available. I'm using azcopy in a corporate environment on back-end infrastructure where we only allow access to URL via whitelisting. Azcopy sync is ran regularly to maintain the sync between blob and local storage.

Tried asking for that in #1705 but no luck. Seems that the dev team doesn't quite understand the impact it has. In other tickets they suggest suppressing event log writing to stop this error from hitting the event log.

Which of course, stops any other real error from getting to the event log. Their "workaround" for a 3 line code change is to tell you to build it yourself.

The real-world doesn't seem to exist for them.

nakulkar-msft commented 1 year ago

Please reopen if you still see the issue.