Information shared from different server are not syncronized

[MgWki]

Which version of blobfuse was used?

version 2.1.0

Which OS distribution and version are you using?

Red Hat Enterprise Linux release 9.2 (Plow)

If relevant, please share your mount command.

/usr/bin/blobfuse2 mount /mnt/wkicheckdr --config-file /root/BlobParameters_sharecmd.yml

What was the issue encountered?

The same mount command is made on many server to make visibility of the same AZ container.
When a user makes a change (vi ) on a file of the shared mounted filesystem and save the file, the modification is not available to the other servers until a time that is not clear (sometimes after minutes, sometimes after hours)
See for example:

Have you found a mitigation/solution?

We tried different configurations but without success. Our config file is the following:

cat /root/BlobParameters_sharecmd.yml

allow-other: true
logging:
type: base
level: log_info
file-path: /var/log/blob_sharecmd.log
components:

• libfuse
• stream
• file_cache
• attr_cache
• azstorage
  libfuse:
  #attribute-expiration-sec: 20
  #entry-expiration-sec: 20
  #negative-entry-expiration-sec: 20
  #fuse-trace: true
  #disable-writeback-cache: true
  #ignore-open-flags: true
  #direct-io: true
  attribute-expiration-sec: 120
  entry-expiration-sec: 120
  negative-entry-expiration-sec: 240

file_cache:
path: /mnt/BlobCache/sharecmd
max-size-mb: 0
cleanup-on-start: true
allow-non-empty-temp: true

Optional

timeout-sec: 10
sync-to-flush: true
refresh-sec: 10

attr_cache:
timeout-sec: 7200
no-cache-on-list : true
azstorage:
type: block
account-name: XXXX
account-key: XXXX
endpoint: https://XXXX
mode: key
container: azr-sharecmd
block-size-mb: 512
max-concurrency: 64
tier: hot
max-retries: 10

Please share logs if available.

LOG of the server 01 where the modification of file pippo is MADE

Thu Nov 2 15:38:10 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (948)]: FileCache::OpenFile : file=aggio/GAS/pippo, fd=13
Thu Nov 2 15:38:10 CET 2023 : blobfuse2[1606] : LOG_ERR [block_blob.go (516)]: BlockBlob::getAttrUsingList : blob aggio/GAS/.pippo.swp does not exist
Thu Nov 2 15:38:10 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (670)]: FileCache::CreateFile : file=aggio/GAS/.pippo.swp, fd=16
Thu Nov 2 15:38:10 CET 2023 : blobfuse2[1606] : LOG_ERR [block_blob.go (516)]: BlockBlob::getAttrUsingList : blob aggio/GAS/.pippo.swpx does not exist
Thu Nov 2 15:38:10 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (670)]: FileCache::CreateFile : file=aggio/GAS/.pippo.swpx, fd=17
Thu Nov 2 15:38:10 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (961)]: FileCache::CloseFile : name=aggio/GAS/.pippo.swpx, handle=11454 dirty. Flushing the file.
Thu Nov 2 15:38:10 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (961)]: FileCache::CloseFile : name=aggio/GAS/.pippo.swp, handle=11453 dirty. Flushing the file.
Thu Nov 2 15:38:10 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (670)]: FileCache::CreateFile : file=aggio/GAS/.pippo.swp, fd=16
Thu Nov 2 15:38:10 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (948)]: FileCache::OpenFile : file=aggio/GAS/pippo, fd=13
Thu Nov 2 15:38:24 CET 2023 : blobfuse2[1606] : LOG_WARNING [lru_policy.go (451)]: lruPolicy::DeleteItem : File in use /mnt/BlobCache/sharecmd/aggio/GAS/.pippo.swp
Thu Nov 2 15:38:44 CET 2023 : blobfuse2[1606] : LOG_WARNING [lru_policy.go (451)]: lruPolicy::DeleteItem : File in use /mnt/BlobCache/sharecmd/aggio/GAS/.pippo.swp
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_ERR [block_blob.go (516)]: BlockBlob::getAttrUsingList : blob aggio/GAS/4913 does not exist
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (670)]: FileCache::CreateFile : file=aggio/GAS/4913, fd=13
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (961)]: FileCache::CloseFile : name=aggio/GAS/4913, handle=11457 dirty. Flushing the file.
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (948)]: FileCache::OpenFile : file=aggio/GAS/pippo, fd=13
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_ERR [block_blob.go (516)]: BlockBlob::getAttrUsingList : blob aggio/GAS/pippo~ does not exist
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (670)]: FileCache::CreateFile : file=aggio/GAS/pippo~, fd=17
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (961)]: FileCache::CloseFile : name=aggio/GAS/pippo~, handle=11459 dirty. Flushing the file.
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_WARNING [libfuse_handler.go (676)]: Libfuse::libfuse_open : Flags (8001) not supported to open aggio/GAS/pippo when write back cache is on. Ignoring unsupported flags.
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (948)]: FileCache::OpenFile : file=aggio/GAS/pippo, fd=13
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (670)]: FileCache::CreateFile : file=aggio/GAS/pippo, fd=29
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (961)]: FileCache::CloseFile : name=aggio/GAS/pippo, handle=0 dirty. Flushing the file.
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (961)]: FileCache::CloseFile : name=aggio/GAS/pippo, handle=11460 dirty. Flushing the file.
Thu Nov 2 15:38:45 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (961)]: FileCache::CloseFile : name=aggio/GAS/.pippo.swp, handle=11455 dirty. Flushing the file.
Thu Nov 2 15:38:53 CET 2023 : blobfuse2[1606] : LOG_INFO [file_cache.go (948)]: FileCache::OpenFile : file=aggio/GAS/pippo, fd=13

LOG of the server 02 where the file is only read

Thu Nov 2 15:38:22 CET 2023 : blobfuse2[11796] : LOG_INFO [file_cache.go (948)]: FileCache::OpenFile : file=aggio/GAS/pippo, fd=13
Thu Nov 2 15:38:47 CET 2023 : blobfuse2[11796] : LOG_INFO [file_cache.go (948)]: FileCache::OpenFile : file=aggio/GAS/pippo, fd=13
Thu Nov 2 15:39:01 CET 2023 : blobfuse2[11796] : LOG_INFO [file_cache.go (948)]: FileCache::OpenFile : file=aggio/GAS/pippo, fd=13
Thu Nov 2 15:39:14 CET 2023 : blobfuse2[11796] : LOG_INFO [file_cache.go (948)]: FileCache::OpenFile : file=aggio/GAS/pippo, fd=13
Thu Nov 2 15:39:16 CET 2023 : blobfuse2[11796] : LOG_INFO [file_cache.go (948)]: FileCache::OpenFile : file=aggio/GAS/pippo, fd=13
Thu Nov 2 15:42:06 CET 2023 : blobfuse2[11796] : LOG_INFO [file_cache.go (948)]: FileCache::OpenFile : file=aggio/GAS/pippo, fd=13
Thu Nov 2 15:42:57 CET 2023 : blobfuse2[11796] : LOG_INFO [file_cache.go (948)]: FileCache::OpenFile : file=aggio/GAS/pippo, fd=13

[souravgupta-msft]

Hi @MgWki, thanks for reaching out. Can you please enable direct-io: true in your config file under libfuse section like this. Alternatively, you can add -o direct_io in your mount command.
Please remount and retry the operations and let us know if this fixes your issue.

[souravgupta-msft]

Also you will have to disable other caching like file cache. You can refer this sample config for your use case.

[MgWki]

Hi, we have installed new configuration that you have suggested and it seems working fine. Thanks

[souravgupta-msft]

Closing this as the suggested config worked. If you have additional questions, you can post it in this thread.

[MgWki]

Hi,
There is something that still it is not working. In the blob storage shared by different server we have recently modified a file. All the server see the modification except one that see the file with the last line corrupted.
Attached there is the log where is possible to see that there is a temporary file .swp in the cache. I have removed the cache but still the files from that server is seen corrupted.
Only after an unmount and remount of the blobfuse the file is seen correctly

Do you have any suggestion ?
Thanks
Best Regards

log_evidence.txt

[vibhansa-msft]

As per logs this file is not removed from cache because there is atleast one handle open for this:

Tue Nov  7 09:39:39 CET 2023 : blobfuse2[8234] : LOG_INFO [file_cache.go (790)]: FileCache::isDownloadRequired : Need to re-download cmd/.controllo_backup.sh.swp, but skipping as handle is already open