search

kahing / goofys

a high-performance, POSIX-ish Amazon S3 file system written in Go
Apache License 2.0
5.11k stars 522 forks source link

untar operations generates a lot of BlobNotFound errors #565

Open ValentinB10 opened 3 years ago

ValentinB10 commented 3 years ago

I mounted a Azure blob storage container using the following line in /etc/fstab:

goofys#wasb://globe@wfprodstorage.blob.core.windows.net /mnt/external_storage/data/Globe fuse _netdev,allow_other,--file-mode=0666,--dir-mode=0777 0 0

What I did is a simple untar method on a gz file:

tar xvf /mnt/external_storage/data/Globe/GFS/Determ_Archive/025/10v2016/gfs.0p25.2016030718.f012.grib2.soursou447903.nc.gz

The problem I have is that this operation generates a lot BlobNotFound errors. The errors I have are similar to:

Oct 12 10:06:44 weatherhub /usr/local/bin/goofys[16592]: 2020/10/12 10:06:44 ==> REQUEST/RESPONSE (Try=1/4.528507ms, OpTime=4.568308ms) -- REQUEST ERROR#012   HEAD https://wfprodstorage.blob.core.windows.net/glo
be/GFS/Determ_Archive/025/10v2016/gfs.0p25.2016030718.f012.grib2.soursou447903.nc.gz?timeout=61#012   Authorization: REDACTED#012   User-Agent: [Azure-Storage/0.7 (go1.13.1; linux)]#012   X-Ms-Client-Request-Id:
 [232efbcc-0266-465b-527e-6f19782e1684]#012   X-Ms-Version: [2018-11-09]#012   x-ms-date: [Mon, 12 Oct 2020 10:06:44 GMT]#012   --------------------------------------------------------------------------------#01
2   RESPONSE Status: 404 The specified blob does not exist.#012   Date: [Mon, 12 Oct 2020 10:06:44 GMT]#012   Server: [Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0]#012   X-Ms-Error-Code: [BlobNotFound]#012   X-
Ms-Request-Id: [8816522d-f01e-0004-1c7f-a0e085000000]#012   X-Ms-Version: [2018-11-09]#012   --------------------------------------------------------------------------------#012   ERROR:#012-> github.com/kahing/
goofys/vendor/github.com/Azure/azure-storage-blob-go/azblob.newStorageError, /home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure-storage-blob-go/azblob/zc_storage_error.go:42#012===== RESP
ONSE ERROR (ServiceCode=BlobNotFound) =====#012Description=404 The specified blob does not exist., Details: (none)#012   HEAD https://wfprodstorage.blob.core.windows.net/globe/GFS/Determ_Archive/025/10v2016/gfs.
0p25.2016030718.f012.grib2.soursou447903.nc.gz?timeout=61#012   Authorization: REDACTED#012   User-Agent: [Azure-Storage/0.7 (go1.13.1; linux)]#012   X-Ms-Client-Request-Id: [232efbcc-0266-465b-527e-6f19782e1684
]#012   X-Ms-Date: [Mon, 12 Oct 2020 10:06:44 GMT]#012   X-Ms-Version: [2018-11-09]#012   --------------------------------------------------------------------------------#012   RESPONSE Status: 404 The specified
 blob does not exist.#012   Date: [Mon, 12 Oct 2020 10:06:44 GMT]#012   Server: [Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0]#012   X-Ms-Error-Code: [BlobNotFound]#012   X-Ms-Request-Id: [8816522d-f01e-0004-1c7
f-a0e085000000]#012   X-Ms-Version: [2018-11-09]#012#012#012#012goroutine 10506644 [running]:#012github.com/kahing/goofys/vendor/github.com/Azure/azure-storage-blob-go/azblob.stack(0xc0461457d0, 0xc02004f100, 0x
c01fd05050)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure-storage-blob-go/azblob/zc_policy_request_log.go:146 +0x9d#012github.com/kahing/goofys/vendor/github.com/Azure/azure-s
torage-blob-go/azblob.NewRequestLogPolicyFactory.func1.1(0xeb5ac0, 0xc001fbf260, 0xc02004f100, 0x10, 0xbd9ee0, 0x1, 0xc01377db80)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure
-storage-blob-go/azblob/zc_policy_request_log.go:96 +0x650#012github.com/kahing/goofys/vendor/github.com/Azure/azure-pipeline-go/pipeline.PolicyFunc.Do(0xc02748bdb0, 0xeb5ac0, 0xc001fbf260, 0xc02004f100, 0xc0137
7dc68, 0xc02009b4f0, 0x44, 0xc01fe9b4a0)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure-pipeline-go/pipeline/core.go:43 +0x44#012github.com/kahing/goofys/vendor/github.com/Azur
e/azure-storage-blob-go/azblob.(*SharedKeyCredential).New.func1(0xeb5ac0, 0xc001fbf260, 0xc02004f100, 0x14603c0, 0xeb5ac0, 0xc001fbf260, 0xc00582e0c0)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/g
ithub.com/Azure/azure-storage-blob-go/azblob/zc_credential_shared_key.go:66 +0x2d2#012github.com/kahing/goofys/vendor/github.com/Azure/azure-pipeline-go/pipeline.PolicyFunc.Do(0xc045eed1d0, 0xeb5ac0, 0xc001fbf26
0, 0xc02004f100, 0xc001fbf260, 0xc00582e0c0, 0xc000000001, 0x0)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure-pipeline-go/pipeline/core.go:43 +0x44#012github.com/kahing/goofys
/vendor/github.com/Azure/azure-storage-blob-go/azblob.NewRetryPolicyFactory.func1.1(0xeb5a80, 0xc0000b0008, 0xc02004f000, 0x10, 0xbd9ee0, 0x64492d747301, 0xc01377da20)#012#011/home/kahing/go/src/github.com/kahin
g/goofys/vendor/github.com/Azure/azure-storage-blob-go/azblob/zc_policy_retry.go:204 +0x66c#012github.com/kahing/goofys/vendor/github.com/Azure/azure-pipeline-go/pipeline.PolicyFunc.Do(0xc02748be50, 0xeb5a80, 0x
c0000b0008, 0xc02004f000, 0xc01377dad8, 0x30, 0x28, 0x8)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure-pipeline-go/pipeline/core.go:43 +0x44#012github.com/kahing/goofys/vendor
/github.com/Azure/azure-storage-blob-go/azblob.NewUniqueRequestIDPolicyFactory.func1.1(0xeb5a80, 0xc0000b0008, 0xc02004f000, 0x10, 0xbd9ee0, 0x40c701, 0xc01377da20)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure-storage-blob-go/azblob/zc_policy_unique_request_id.go:19 +0xae#012github.com/kahing/goofys/vendor/github.com/Azure/azure-pipeline-go/pipeline.PolicyFunc.Do(0xc0067d55e0, 0xeb5a80, 0xc0000b0008, 0xc02004f000, 0xc01377dac0, 0x23, 0xc000260090, 0xc03191c928)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure-pipeline-go/pipeline/core.go:43 +0x44#012github.com/kahing/goofys/vendor/github.com/Azure/azure-storage-blob-go/azblob.NewTelemetryPolicyFactory.func1.1(0xeb5a80, 0xc0000b0008, 0xc02004f000, 0x1, 0x0, 0x1, 0xc01edea158)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure-storage-blob-go/azblob/zc_policy_telemetry.go:34 +0x15d#012github.com/kahing/goofys/vendor/github.com/Azure/azure-pipeline-go/pipeline.PolicyFunc.Do(0xc045eed200, 0xeb5a80, 0xc0000b0008, 0xc02004f000, 0xc045eed200, 0xc02004f000, 0xc03191c9f8, 0x40c7c8)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure-pipeline-go/pipeline/core.go:43 +0x44#012github.com/kahing/goofys/vendor/github.com/Azure/azure-pipeline-go/pipeline.(*pipeline).Do(0xc0002740c0, 0xeb5a80, 0xc0000b0008, 0xea6320, 0xc0009f7c20, 0xc02004f000, 0x23, 0xc02b447a40, 0x58, 0x0)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure-pipeline-go/pipeline/core.go:129 +0x81#012github.com/kahing/goofys/vendor/github.com/Azure/azure-storage-blob-go/azblob.blobClient.GetProperties(0xc000260030, 0x5, 0x0, 0x0, 0x0, 0xc000260038, 0x23, 0xc02b447a40, 0x58, 0x0, ...)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure-storage-blob-go/azblob/zz_generated_blob.go:761 +0x3a5#012github.com/kahing/goofys/vendor/github.com/Azure/azure-storage-blob-go/azblob.BlobURL.GetProperties(0xc000260030, 0x5, 0x0, 0x0, 0x0, 0xc000260038, 0x23, 0xc02b447a40, 0x58, 0x0, ...)#012#011/home/kahing/go/src/github.com/kahing/goofys/vendor/github.com/Azure/azure-storage-blob-go/azblob/url_blob.go:113 +0x11f#012github.com/kahing/goofys/internal.(*AZBlob).HeadBlob(0xc0002680b0, 0xc00587bf20, 0x1f, 0xc0360c1340, 0x32)#012#011/home/kahing/go/src/github.com/kahing/goofys/internal/backend_azblob.go:446 +0x240#012github.com/kahing/goofys/internal.(*Inode).LookUpInodeNotDir(0xc0038a7720, 0xc0360c1340, 0x32, 0xc0028c6720, 0xc0028c6660)#012#011/home/kahing/go/src/github.com/kahing/goofys/internal/dir.go:1295 +0x101#012created by github.com/kahing/goofys/internal.(*Inode).LookUpInodeMaybeDir#012#011/home/kahing/go/src/github.com/kahing/goofys/internal/dir.go:1340 +0x189

I have a lot of these logs (around 1GB in 4 hours) and it slows down the whole system.

dotslash commented 3 years ago

Do you have debug_s3 or debug_fuse flags enabled? That produces a log of logs

Also this log is formatted weirdly. Is this how the logs appear in your system?

ValentinB10 commented 3 years ago

No the debug_s3 or debug_fuse flags are not enabled. However, these logs are easy to reproduce with any VM. I tested it with ubuntu and debian and I have still the same issue. Is there any way to force goofys not to output logs?