Write operation failed with file_cache

[abhiguptacse]

Which version of blobfuse was used?

2.4.0

Which OS distribution and version are you using?

Ubuntu 22.04

config-file used:

logging:
  type: base
  level: log_debug
 
components:
  - libfuse
  - file_cache
  - attr_cache
  - azstorage
 
libfuse:
  attribute-expiration-sec: 120
  entry-expiration-sec: 120
  negative-entry-expiration-sec: 240
 
file_cache:
  path: /tmp1/cache
  timeout-sec: 1200
  allow-non-empty-temp: true
  cleanup-on-start: true
  ignore-sync: true
  max-size-mb: 409600
  
attr_cache:
  timeout-sec: 7200
 
azstorage:
  type: block
  account-name: 
  endpoint: 
  mode: azcli
  container: test-blobfuse

What was the issue encountered?

Flush file operation is failing when writing with file cache for data size ~20GB.

Have you found a mitigation/solution?

No

Please share logs if available

Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_DEBUG [utils.go (156)]: SDK(Retry) : response 201
Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_DEBUG [utils.go (156)]: SDK(Retry) : exit due to non-retriable status code
Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_DEBUG [utils.go (156)]: SDK(Retry) : =====> Try=1 for PUT https://account.blob.core.windows.net/test-blobfuse/write_fio5.data?comp=REDACTED
Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_DEBUG [utils.go (156)]: SDK(Request) : ==> OUTGOING REQUEST (Try=1)
   PUT https://account.blob.core.windows.net/test-blobfuse/write_fio5.data?comp=blocklist
   Accept: application/xml
   Authorization: REDACTED
   Content-Length: 332927
   Content-Type: application/xml
   User-Agent: Azure-Storage-Fuse/2.4.0 (Ubuntu 22.04.4 LTS) azsdk-go-azblob/v1.4.0 (go1.23.1; linux)
   x-ms-blob-content-md5: REDACTED
   x-ms-blob-content-type: application/octet-stream
   x-ms-version: 2024-05-04

Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_DEBUG [utils.go (156)]: SDK(Response) : ==> REQUEST/RESPONSE (Try=1/190.366631ms, OpTime=190.507432ms) -- RESPONSE RECEIVED
   PUT https://account.blob.core.windows.net/test-blobfuse/write_fio5.data?comp=blocklist
   Accept: application/xml
   Authorization: REDACTED
   Content-Length: 332927
   Content-Type: application/xml
   User-Agent: Azure-Storage-Fuse/2.4.0 (Ubuntu 22.04.4 LTS) azsdk-go-azblob/v1.4.0 (go1.23.1; linux)
   x-ms-blob-content-md5: REDACTED
   x-ms-blob-content-type: application/octet-stream
   x-ms-version: 2024-05-04
   --------------------------------------------------------------------------------
   RESPONSE Status: 400 The specified block list is invalid.
   Content-Length: 221
   Content-Type: application/xml
   Date: Wed, 04 Dec 2024 10:14:57 GMT
   Server: Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0
   X-Ms-Error-Code: REDACTED
   X-Ms-Request-Id: b5586800-c01e-002e-2335-46e527000000
   X-Ms-Version: 2024-05-04

Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_DEBUG [utils.go (156)]: SDK(Retry) : response 400
Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_DEBUG [utils.go (156)]: SDK(Retry) : exit due to non-retriable status code
Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_DEBUG [utils.go (156)]: SDK(ResponseError) : PUT https://account.blob.core.windows.net/test-blobfuse/write_fio5.data
--------------------------------------------------------------------------------
RESPONSE 400: 400 The specified block list is invalid.
ERROR CODE: InvalidBlockList
--------------------------------------------------------------------------------
<?xml version="1.0" encoding="utf-8"?><Error><Code>InvalidBlockList</Code><Message>The specified block list is invalid.
RequestId:b5586800-c01e-002e-2335-46e527000000
Time:2024-12-04T10:14:57.5836411Z</Message></Error>
--------------------------------------------------------------------------------

Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_ERR [block_blob.go (924)]: BlockBlob::WriteFromFile : Failed to upload blob write_fio5.data [PUT https://account.blob.core.windows.net/test-blobfuse/write_fio5.data
--------------------------------------------------------------------------------
RESPONSE 400: 400 The specified block list is invalid.
ERROR CODE: InvalidBlockList
--------------------------------------------------------------------------------
<?xml version="1.0" encoding="utf-8"?><Error><Code>InvalidBlockList</Code><Message>The specified block list is invalid.
RequestId:b5586800-c01e-002e-2335-46e527000000
Time:2024-12-04T10:14:57.5836411Z</Message></Error>
--------------------------------------------------------------------------------
]
Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_ERR [file_cache.go (1344)]: FileCache::FlushFile : write_fio5.data upload failed [PUT https://account.blob.core.windows.net/test-blobfuse/write_fio5.data
--------------------------------------------------------------------------------
RESPONSE 400: 400 The specified block list is invalid.
ERROR CODE: InvalidBlockList
--------------------------------------------------------------------------------
<?xml version="1.0" encoding="utf-8"?><Error><Code>InvalidBlockList</Code><Message>The specified block list is invalid.
RequestId:b5586800-c01e-002e-2335-46e527000000
Time:2024-12-04T10:14:57.5836411Z</Message></Error>
--------------------------------------------------------------------------------
]
Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_ERR [libfuse_handler.go (827)]: Libfuse::libfuse_flush : error flushing file write_fio5.data, handle: 4 [PUT https://acount.blob.core.windows.net/test-blobfuse/write_fio5.data
--------------------------------------------------------------------------------
RESPONSE 400: 400 The specified block list is invalid.
ERROR CODE: InvalidBlockList
--------------------------------------------------------------------------------
<?xml version="1.0" encoding="utf-8"?><Error><Code>InvalidBlockList</Code><Message>The specified block list is invalid.
RequestId:b5586800-c01e-002e-2335-46e527000000
Time:2024-12-04T10:14:57.5836411Z</Message></Error>
--------------------------------------------------------------------------------
]
Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_TRACE [libfuse_handler.go (870)]: Libfuse::libfuse_release : write_fio5.data, handle: 4
Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_TRACE [file_cache.go (1081)]: FileCache::closeFileInternal : name=write_fio5.data, handle=4
Wed Dec  4 10:14:57 UTC 2024 : blobfuse2[608940] : [/mnt/test1] LOG_TRACE [file_cache.go (1268)]: FileCache::FlushFile : handle=4, path=write_fio5.data

[souravgupta-msft]

Parallel flush calls are being made by the user application. As a result of this, if one flush call succeeds, the other fails with the error InvalidBlockList because the blocks staged by the remaining flush calls are garbage collected by the backend.
We will fix this in our next release.