search

Azure / azure-storage-fuse

A virtual file system adapter for Azure Blob storage
Other
660 stars 206 forks source link

No mount and no error messages. #428

Closed cris-b closed 3 years ago

cris-b commented 4 years ago

Which version of the blobfuse was used?

1.0.3 and 1.2.3

Which OS (please include version) are you using?

RHEL 8.2

What problem was encountered?

Since updating RHEL, blobfuse has completely stopped working, with no error messages in the log.

Running blobfuse from command line gives return code 0, however the mount is not there and no blobfuse process is running.

Even with log level debug, the only messages in the log is:

Jun 24 13:56:56 ip-10-0-0-172 blobfuse[30960]: Setting logging level to : LOG_DEBUG

If I run the process in gdb and follow the fork, it exits normally.

have tried with AZURE_STORAGE_SAS_TOKEN and AZURE_STORAGE_ACCESS_KEY.

Have you found a mitigation/solution?

No

By default, blobfuse logs errors to syslog. If this is relevant, is there anything in the syslog that might be helpful?

only this is output: Jun 24 13:56:56 ip-10-0-0-172 blobfuse[30960]: Setting logging level to : LOG_DEBUG

If relevant, please share your mount command.

blobfuse --container-name=bla-data --tmp-path=/home/crisb/b --log-level=LOG_DEBUG /home/crisb/r

NaraVen commented 4 years ago

blobfuse /home/crisb/r --container-name=bla-data --tmp-path=/home/crisb/b --config-file=--log-level=LOG_DEBUG

Try the above. If there is no config file you need to set the accountName and accountKey as environment variables

cris-b commented 4 years ago

yes, i'm setting AZURE_STORAGE_ACCESS_KEY and AZURE_STROAGE_ACCOUNT before running that.

note this was working, the only change is updating RHEL, so something in those updates must have broken blobfuse, but I cant find out what without any log info to go on..

NaraVen commented 4 years ago

could you please try pulling down the source code and compiling using the build.sh?

cris-b commented 4 years ago

yes, i have done that with 1.2.3 - same issue.

NaraVen commented 4 years ago

you can get the error output to the console using sudo journalctl -fn0 &

could you please start blobfuse from another terminal after running the above and send the output/error you see.

cris-b commented 4 years ago

no output at all when doing that.

AdamOstgaard commented 4 years ago

We have the same problem. Running CentOS Linux release 8.2.2004 (Core). Tested and it is working correctly on CentOS Linux release 8.1.1911 (Core), both was built from source. We are getting the following when running --log-level=LOG_DEBUG

Function azs_destroy, in file /home/---/azure-storage-fuse/blobfuse/utilities.cpp, line 575: azs_destroy called.
Function ensure_files_directory_exists_in_cache, in file /home/---/azure-storage-fuse/blobfuse/utilities.cpp, line 244: Making cache di>
Function ensure_files_directory_exists_in_cache, in file /home/---/azure-storage-fuse/blobfuse/utilities.cpp, line 244: Making cache di>
Function ensure_files_directory_exists_in_cache, in file /home/---/azure-storage-fuse/blobfuse/utilities.cpp, line 244: Making cache di>
Mon Jul  6 16:05:17 2020 ==> REQUEST/RESPONSE
    GET https://[account-name].blob.core.windows.net/[container-name]?comp=list&delimiter=/&include=metadata&maxresults=1&restype=container
    User-Agent: [Azure-Storage-Fuse/1.2.4]
    x-ms-date: [Mon, 06 Jul 2020 14:05:12 GMT]
    x-ms-version: [2018-11-09]
    Authorization: [REDACTED]
    Transfer-Encoding: []
    --------------------------------------------------------------------------------
    RESPONSE Status: 200
    Content-Type: [application/xml]
    Date: [Mon, 06 Jul 2020 14:05:17 GMT]
    Server: [Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0]
    Transfer-Encoding: [chunked]
    x-ms-request-id: [a5e4c722-401e-0058-329e-539954000000]
    x-ms-version: [2018-11-09]
Setting logging level to : LOG_DEBUG
cris-b commented 4 years ago

still happens with 1.3.1

NaraVen commented 4 years ago

@crs-b, Your output shows it is connecting successfully after authentication. Is it not mounting?

cris-b commented 4 years ago

all I see is:

Sep 3 15:17:02 ip-10-0-0-172 blobfuse[18380]: Setting logging level to : LOG_DEBUG

afterwards there are no blobfuse processes running and no further output.

NaraVen commented 4 years ago

Does it also show this? REQUEST/RESPONSE GET https://[account-name].blob.core.windows.net/[container-name]?comp=list&delimiter=/&include=metadata&maxresults=1&restype=container User-Agent: [Azure-Storage-Fuse/1.2.4] x-ms-date: [Mon, 06 Jul 2020 14:05:12 GMT] x-ms-version: [2018-11-09] Authorization: [REDACTED] Transfer-Encoding: []

RESPONSE Status: 200
Content-Type: [application/xml]
Date: [Mon, 06 Jul 2020 14:05:17 GMT]
Server: [Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0]
Transfer-Encoding: [chunked]
x-ms-request-id: [a5e4c722-401e-0058-329e-539954000000]
x-ms-version: [2018-11-09]
cris-b commented 4 years ago

no, I see no other log messages before this

cris-b commented 4 years ago

apologies, my syslog was not setup correctly, I see:

--------------------------------------RESPONSE Status :: 200 :: Sep 4 09:32:32 ip-10-0-0-172 blobfuse[11469]: Successfully Authenticated! Sep 4 09:32:32 ip-10-0-0-172 blobfuse[11471]: azs_init ran Sep 4 09:32:32 ip-10-0-0-172 blobfuse[11471]: Function azs_destroy, in file /home/crisb/azure-storage-fuse-1.3.1/blobfuse/utilities.cpp, line 425: azs_destroy called.

cris-b commented 4 years ago

I have found a fix, using -o debug I was getting this:

[crisb@ip-10-0-0-172 azure-storage-fuse-1.3.1]$ sudo /usr/bin/blobfuse /rpd-qa-data/ --log-level=LOG_DEBUG --tmp-path=/tmp/blobfuse --config-file=/etc/blobfuse.cfg -o attr_timeout=240 -o entry_timeout=240 -o negative_timeout=120 -o allow_other -o debug FUSE library version: 2.9.7 nullpath_ok: 0 nopath: 0 utime_omit_ok: 0 unique: 2, opcode: INIT (26), nodeid: 0, insize: 56, pid: 0 INIT: 7.31 flags=0x03fffffb max_readahead=0x00020000 INIT: 7.19 flags=0x00000031 max_readahead=0x00400000 max_write=0x00400000 max_background=128 congestion_threshold=96 unique: 2, success, outsize: 40 fuse: reading device: Invalid argument

seems this is related to the max_write being set to 4mb (4194304) in azs_init. After commenting this out the filesystem uses 128kb for max_write and successfully mounts.

vibhansa-msft commented 4 years ago

@cris-b what is the kernel version you are having. We already have a check that on linux kernel < 5.4 only we set max write as later were not working with this config.

vibhansa-msft commented 4 years ago

I see as per your logs you have libfuse 2.9.7, where this config is working fine for me. We have observed with libfuse version 2.9.9 we face the mount issue with respect to max_write.

cris-b commented 4 years ago

this is RHEL kernel 4.18.0-193.6.3.el8_2.x86_64 which is what was shipped with RHEL 8.2.

it looks to me like setting max_write to 4mb is wrong...

incidentally if I set FUSE_CAP_BIG_WRITES (as blobfuse does for kernel 5.4+) I still end up with 128kb as the max_write.

NaraVen commented 4 years ago

128kb is fuse default. Could you please try our latest code from master. It falls to the default of 128kb for any kerbel version above 4.15

zhen432156 commented 4 years ago

@cris-b @vibhansa-msft I ran into the same issue. I set up blobfuse, It all worked fine. After VM reboot, the mount is gone, I just can not remount it: vdb@driverm2:/mnt/blobfuse/cdml$ blobfuse /mnt/blobfuse/cdml --config-file=/mnt/blobfuse/connection.cfg --tmp-path=/mnt/blobfuse/tmp -o debug FUSE library version: 2.9.7 nullpath_ok: 0 nopath: 0 utime_omit_ok: 0 unique: 2, opcode: INIT (26), nodeid: 0, insize: 56, pid: 0 INIT: 7.31 flags=0x03fffffb max_readahead=0x00020000 INIT: 7.19 flags=0x00000031 max_readahead=0x00400000 max_write=0x00400000 max_background=128 congestion_threshold=96 unique: 2, success, outsize: 40 fuse: reading device: Invalid argument

I took @cris-b 's advice, tried to set up max_write in /etc/fuse.conf, but it says invalid parameters. Wondering how did @cris-b changed the max_write. vdb@driverm2:/mnt/blobfuse/cdml$ more /etc/fuse.conf

/etc/fuse.conf - Configuration file for Filesystem in Userspace (FUSE)

Set the maximum number of FUSE mounts allowed to non-root users.

The default is 1000.

mount_max = 1000

Allow non-root users to specify the allow_other or allow_root mount options.

user_allow_other

The Ubuntu linux kernel is: vdb@driverm2:/mnt/blobfuse/cdml$ lsb_release -a No LSB modules are available. Distributor ID: Ubuntu Description: Ubuntu 18.04.3 LTS Release: 18.04 Codename: bionic

zhen432156 commented 4 years ago

Linux kernel version: vdb@driverm2:/mnt/blobfuse/cdml$ uname -a Linux driverm2 5.4.0-1025-azure #25~18.04.1-Ubuntu SMP Sat Sep 5 15:28:57 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

The reboot updated linux kernel from 5.3.0-1020-azure to 5.4.0-1025-azure

zhen432156 commented 4 years ago

I have fixed the issue, seems the new kernel does not work with the version of fuse I have

NaraVen commented 4 years ago

@zhen432156 blobfuse 1.3.2 supports the newly upgrafed Linux 18.04. Did you upgrade blobfuse to 1.3.2?

e212156822000 commented 4 years ago

@zhen432156

I took @cris-b 's advice, tried to set up max_write in /etc/fuse.conf, but it says invalid parameters. Wondering how did @cris-b changed the max_write.

Here is how I fix the issue in Ubuntu18.04 (5.4.0-1025-azure)

  1. Download the source code of version 1.1.1 from GitHub
  2. Open file /azure-storage-fuse-1.1.1/blobfuse/blobfuse.cpp
  3. Go to Line 218, and commet out conn->max_write = 4194304;
  4. Run ./azure-storage-fuse-1.1.1/build.sh
  5. Execute blobfuse in /azure-storage-fuse-1.1.1/build, and everything is done.

Like @NaraVen mentioned before, upgrading blobfuse to version 1.3.2 will fix this issue immediately.

vibhansa-msft commented 4 years ago

Version 1.3.2 has the fix for the same. Feel free to reopen this if issue persists.

oskr201569 commented 3 years ago

I am having the same problem, I run the mount command: sudo blobfuse ~/resources --tmp-path=/datadisk/resource/blobfusetmp --config-file=/home/useradmin/fuse_connection.cfg --file-cache-timeout-in-seconds=120 --use-attr-cache=false --log-level=LOG_DEBUG -o allow_other

In the logs it is normal that the connection is established but the command does not end I must end it with ctrl + c. When comparing with another virtual machine where if the blobfuse connection works in the logs, an additional log appears after the http 200 that says: blobfuse [2818]: azs_init ran

The logs of the machine where it works for me after the mount in the syslog except for the last one that comes out of more. Could you guide me about azs_init what is it and what could it be?

Logs en syslog:

blobfuse[7155]: Account name found blobfuse[7155]: Account Key found blobfuse[7155]: Container name found blobfuse[7155]: Setting logging level to : LOG_DEBUG blobfuse[7155]: release is 5.400000, Kernel version is 5.4.0-1034-azure blobfuse[7155]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk. blobfuse[7155]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk/resource. blobfuse[7155]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk/resource/blobfusetmp. blobfuse[7155]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk/resource/blobfusetmp/root. blobfuse[7155]: Initializing blobfuse using BlockBlob blobfuse[7155]: Setup storage client blobfuse[7155]: Authenticating using account key blobfuse[7155]: ==> REQUEST/RESPONSE :: GET https://<>/resources?comp=list&delimiter=/&include=metadata&maxresults=1&restype=container?&User-Agent=azure-storage-fuse/1.3.5&x-ms-date=Mon,04 Jan 2021 19:56:24 GMT&x-ms-version=2018-11-09&Authorization=****&Transfer-Encoding=--------------------------------------------------------------------------------RESPONSE Status :: 200 :: REQ ID : c8cfec6e-501e-0004-73d3-e2a74b000000 blobfuse[7155]: Successfully Authenticated!

Thanks,

vibhansa-msft commented 3 years ago

@oskr201569 : Kindly upgrade to latest blobfuse version 1.3.6. You can take up a compatible rpm for your OS from below location. https://github.com/Azure/azure-storage-fuse/releases/tag/blobfuse-1.3.6

oskr201569 commented 3 years ago

Good morning,

I did the blobfuse update finished but the problem persists. This is the information of the kernel: Linux ZUE2ATAPCDRBS01 5.4.0-1034-azure # 35 ~ 18.04.1-Ubuntu SMP Thu Dec 10 09:13:52 UTC 2020 x86_64 x86_64 x86_64 GNU / Linux

and this is the ubuntu version:

No LSB modules are available. Distributor ID: Ubuntu Description: Ubuntu 18.04.5 LTS Release: 18.04 Codename: bionic

any suggestion

vibhansa-msft commented 3 years ago

@oskr201569 : kindly share your mount command and debug logs with the updated version.

oskr201569 commented 3 years ago

Hi vibhansa

This is the command to mount: sudo blobfuse ~/resources --tmp-path=/datadisk/resource/blobfusetmp --config-file=/home/useradmin/fuse_connection.cfg --file-cache-timeout-in-seconds=120 --use-attr-cache=false --log-level=LOG_DEBUG -o allow_other

This is log of SYSLOG Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Account name found Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Account Key found Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Container name found Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Setting logging level to : LOG_DEBUG Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: release is 5.400000, Kernel version is 5.4.0-1034-azure Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: CURL Version is 7.58.0 Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk. Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk/resource. Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk/resource/blobfusetmp. Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk/resource/blobfusetmp/root. Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Initializing blobfuse using BlockBlob Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Setup storage client Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Kernel version is 5.400000 Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: libcurl version is 7.580000 Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Authenticating using account key Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: ==> REQUEST/RESPONSE :: GET https://**hostofresource**/resources?comp=list&delimiter=/&include=metadata&maxresults=1&restype=container?&User-Agent=azure-storage-fuse/1.3.6&x-ms-date=Tue, 05 Jan 2021 17:48:53 GMT&x-ms-version=2018-11-09&Authorization=****&Transfer-Encoding=--------------------------------------------------------------------------------RESPONSE Status :: 200 :: REQ ID : 747a42d8-e01e-004c-1e8b-e3ba7c000000 Jan 5 17:48:53 ZUE2ATAPCDRBS01 blobfuse[3887]: Successfully Authenticated!

vibhansa-msft commented 3 years ago

@oskr201569 : As per above logs your connection to the container is going through fine. However as you mentioned in the previous comments you do not see the log stating "azs_init ran", which basically means the fuse daemon has not been initialized in your case. This might be due to some fuse driver issue, you can reinstall the fuse driver and try out. If the problem persists add "-d" option in the command line and share the logs.

oskr201569 commented 3 years ago

Thanks for your answers, try as requested by uninstalling and reinstalling like this:

Try 1 # sudo apt-get install blobfuse

Reading package lists... Done Building dependency tree Reading state information... Done The following NEW packages will be installed: blobfuse 0 upgraded, 1 newly installed, 0 to remove and 26 not upgraded. Need to get 7079 kB of archives. After this operation, 21.3 MB of additional disk space will be used. Get:1 https://packages.microsoft.com/ubuntu/18.04/prod bionic/main amd64 blobfuse amd64 1.3.6 [7079 kB] Fetched 7079 kB in 0s (16.8 MB/s) Selecting previously unselected package blobfuse. (Reading database ... 217367 files and directories currently installed.) Preparing to unpack .../blobfuse_1.3.6_amd64.deb ... Unpacking blobfuse (1.3.6) ... Setting up blobfuse (1.3.6) ...

Try 2 # sudo apt-get install blobfuse -d

Reading package lists... Done Building dependency tree Reading state information... Done blobfuse is already the newest version (1.3.6). 0 upgraded, 0 newly installed, 0 to remove and 26 not upgraded.

In both it was installed but when trying to mount it does not work

LOGS: Jan 6 19:42:47 ZUE2ATAPCDRBS01 systemd-resolved[1073]: Server returned error NXDOMAIN, mitigating potential DNS violation DVE-2018-0001, retrying transaction with reduced feature level UDP. Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Account name found Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Account Key found Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Container name found Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Setting logging level to : LOG_DEBUG Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: release is 5.400000, Kernel version is 5.4.0-1035-azure Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: CURL Version is 7.58.0 Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk. Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk/resource. Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk/resource/blobfusetmp. Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk/resource/blobfusetmp/root. Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Initializing blobfuse using BlockBlob Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Setup storage client Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Kernel version is 5.400000 Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: libcurl version is 7.580000 Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Authenticating using account key Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: ==> REQUEST/RESPONSE :: GET https://cuentaalmacenamiento.blob.core.windows.net/resources?comp=list&delimiter=/&include=metadata&maxresults=1&restype=container?&User-Agent=azure-storage-fuse/1.3.6&x-ms-date=Wed, 06 Jan 2021 19:43:09 GMT&x-ms-version=2018-11-09&Authorization=****&Transfer-Encoding=--------------------------------------------------------------------------------RESPONSE Status :: 200 :: REQ ID : b7d071d8-201e-0021-7564-e40e37000000 Jan 6 19:43:09 ZUE2ATAPCDRBS01 blobfuse[5898]: Successfully Authenticated!

With the .deb file downloaded when executing the installation in this way it is not possible to install:

Try 3 # sudo apt install /home/useradmin/blobfuse-1.3.6-ubuntu-18.04-x86_64.deb -d

Reading package lists... Done Building dependency tree Reading state information... Done Note, selecting 'blobfuse' instead of '/home/useradmin/blobfuse-1.3.6-ubuntu-18.04-x86_64.deb' The following NEW packages will be installed: blobfuse 0 upgraded, 1 newly installed, 0 to remove and 26 not upgraded. Need to get 0 B/7080 kB of archives. After this operation, 21.3 MB of additional disk space will be used. Get:1 /home/useradmin/blobfuse-1.3.6-ubuntu-18.04-x86_64.deb blobfuse amd64 1.3.6 [7080 kB] Download complete and in download only mode N: Download is performed unsandboxed as root as file '/home/useradmin/blobfuse-1.3.6-ubuntu-18.04-x86_64.deb' couldn't be accessed by user '_apt'. - pkgAcquire::Run (13: Permission denied)

to complement . . .

Canceling the mount command with ctrl + c and trying to enter the mount directory gives the following: cd resources -bash: cd: resources: Transport endpoint is not connected When you see the details of the directory, it looks like this: d????????? ? ? ? ? ? resources

This failed attempt is solved by restarting the virtual machine that disconnect de storage account but not yet connect correctly

Am I missing something?

vibhansa-msft commented 3 years ago

@oskr201569 : Sorry I think my message was not conveyed properly. By reinstalling fuse driver I meant reinstalling 'libfuse' and not 'blobfuse'. Follow below command for the same

Once this is done, mount with your regular blobfuse command and check it works for you or not. If the problem still persists add '-d' command line parameter to the mount command (sudo blobfuse ....). This will print bunch of logs on the console. Share those console logs along with syslog of blobfuse.

oskr201569 commented 3 years ago

I uninstalled the libraries and reinstalled it, but it still doesn't work The console does not throw an error, the following appears in syslog:

Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: 2021-01-07T23:26:26.741699Z ERROR SendTelemetryHandler ExtHandler Event:name=WALinuxAgent, op=ReportEventErrors, message=DroppedEventsCount: 1 Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: Reasons (first 5 errors): [ProtocolError] [Wireserver Exception] [ProtocolError] [Wireserver Failed] URI http://xxxx.xxxx.xxxx.xxxx/machine?comp=telemetrydata [HTTP Failed] Status Code 400: Traceback (most recent call last): Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: File "bin/WALinuxAgent-2.2.53-py2.7.egg/azurelinuxagent/common/protocol/wire.py", line 560, in call_wireserver Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: raise ProtocolError(msg) Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: azurelinuxagent.common.exception.ProtocolError: [ProtocolError] [Wireserver Failed] URI http://xxxx.xxxx.xxxx.xxxx/machine?comp=telemetrydata [HTTP Failed] Status Code 400 Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: During handling of the above exception, another exception occurred: Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: Traceback (most recent call last): Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: File "bin/WALinuxAgent-2.2.53-py2.7.egg/azurelinuxagent/common/protocol/wire.py", line 1087, in _send_event Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: self.send_event(provider_id, buf[provider_id]) Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: File "bin/WALinuxAgent-2.2.53-py2.7.egg/azurelinuxagent/common/protocol/wire.py", line 1071, in send_event Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: resp = self.call_wireserver(restutil.http_post, uri, data, header) Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: File "bin/WALinuxAgent-2.2.53-py2.7.egg/azurelinuxagent/common/protocol/wire.py", line 568, in call_wireserver Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: ustr(e))) Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: azurelinuxagent.common.exception.ProtocolError: [ProtocolError] [Wireserver Exception] [ProtocolError] [Wireserver Failed] URI http://xxxx.xxxx.xxxx.xxxx/machine?comp=telemetrydata [HTTP Failed] Status Code 400 Jan 7 23:26:26 ZUE2ATAPCDRBS01 python3[1485]: , duration=0 Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Account name found Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Account Key found Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Container name found Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Setting logging level to : LOG_DEBUG Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: release is 5.400000, Kernel version is 5.4.0-1035-azure Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: CURL Version is 7.58.0 Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk. Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk/resource. Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk/resource/blobfusetmp. Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Function ensure_files_directory_exists_in_cache, in file /home/vsts/work/1/s/blobfuse/utilities.cpp, line 96: Making cache directory /datadisk/resource/blobfusetmp/root. Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Initializing blobfuse using BlockBlob Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Setup storage client Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Kernel version is 5.400000 Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: libcurl version is 7.580000 Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Authenticating using account key Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: ==> REQUEST/RESPONSE :: GET https://cuentaAlmacenamiento/resources?comp=list&delimiter=/&include=metadata&maxresults=1&restype=container?&User-Agent=azure-storage-fuse/1.3.6&x-ms-date=Thu, 07 Jan 2021 23:26:40 GMT&x-ms-version=2018-11-09&Authorization=****&Transfer-Encoding=--------------------------------------------------------------------------------RESPONSE Status :: 200 :: REQ ID : 9e516969-101e-0058-2e4c-e5f213000000 Jan 7 23:26:41 ZUE2ATAPCDRBS01 blobfuse[14475]: Successfully Authenticated! Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: 2021-01-07T23:27:30.805784Z ERROR SendTelemetryHandler ExtHandler Event:name=WALinuxAgent, op=ReportEventErrors, message=DroppedEventsCount: 1 Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: Reasons (first 5 errors): [ProtocolError] [Wireserver Exception] [ProtocolError] [Wireserver Failed] URI http://xxxx.xxxx.xxxx.xxxx/machine?comp=telemetrydata [HTTP Failed] Status Code 400: Traceback (most recent call last): Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: File "bin/WALinuxAgent-2.2.53-py2.7.egg/azurelinuxagent/common/protocol/wire.py", line 560, in call_wireserver Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: raise ProtocolError(msg) Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: azurelinuxagent.common.exception.ProtocolError: [ProtocolError] [Wireserver Failed] URI http://xxxx.xxxx.xxxx.xxxx/machine?comp=telemetrydata [HTTP Failed] Status Code 400 Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: During handling of the above exception, another exception occurred: Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: Traceback (most recent call last): Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: File "bin/WALinuxAgent-2.2.53-py2.7.egg/azurelinuxagent/common/protocol/wire.py", line 1087, in _send_event Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: self.send_event(provider_id, buf[provider_id]) Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: File "bin/WALinuxAgent-2.2.53-py2.7.egg/azurelinuxagent/common/protocol/wire.py", line 1071, in send_event Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: resp = self.call_wireserver(restutil.http_post, uri, data, header) Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: File "bin/WALinuxAgent-2.2.53-py2.7.egg/azurelinuxagent/common/protocol/wire.py", line 568, in call_wireserver Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: ustr(e))) Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: azurelinuxagent.common.exception.ProtocolError: [ProtocolError] [Wireserver Exception] [ProtocolError] [Wireserver Failed] URI http://xxxx.xxxx.xxxx.xxxx/machine?comp=telemetrydata [HTTP Failed] Status Code 400 Jan 7 23:27:30 ZUE2ATAPCDRBS01 python3[1485]: , duration=0

vibhansa-msft commented 3 years ago

@oskr201569 : Did you try '-d' option in mount command. As azs_init is not called there is some issue with respect to libfuse in your VM. When you execute mount command and it does not return can you check output of 'df' command from another terminal to validate whether file-system was mounted or not. I suspect it will not show your mount directory in the output.

Also just wanted to confirm one thing from the logs: blobfuse[14475]: ==> REQUEST/RESPONSE :: GET https://cuentaAlmacenamiento/resources? in this log, you have changed the URL to hide sensitive info right ? Just asking because I don't see any 'blob' endpoint URL here. Just trying to confirm there is no configuration issue.

oskr201569 commented 3 years ago

Good afternoon I did the test adding -d to the mount command but it doesn't show me any additional information in logs. When executing the mount and entering through another console to make df, it is also blocked. When canceling the mount and doing df the following appears:

df: /resources: Transport endpoint is not connected Filesystem 1K-blocks Used Available Use% Mounted on udev 4058340 0 4058340 0% /dev tmpfs 815348 1068 814280 1% /run /dev/sdd1 30309264 26284144 4008736 87% / tmpfs 4076740 0 4076740 0% /dev/shm tmpfs 5120 4 5116 1% /run/lock tmpfs 4076740 0 4076740 0% /sys/fs/cgroup tmpfs 4076740 8 4076732 1% /tmp /dev/sdd15 106858 3671 103188 4% /boot/efi /dev/sda1 131586052 61476 124797360 1% /datadisk /dev/mapper/vgbackup-lvbackup 536604676 567528 536037148 1% /backup /dev/mapper/vgroot-lvvar 26204160 16103204 10100956 62% /var /dev/loop1 100224 100224 0 100% /snap/core/10577 /dev/loop0 128896 128896 0 100% /snap/docker/471 /dev/loop2 100352 100352 0 100% /snap/core/10583 /dev/mapper/vgroot-lvvartmp 5232640 38388 5194252 1% /var/tmp /dev/mapper/vgroot-lvhome 10475520 5125584 5349936 49% /home /dev/mapper/vgroot-lvvarlog 5232640 1949972 3282668 38% /var/log /dev/sde1 16775164 45332 16729832 1% /mnt tmpfs 815348 0 815348 0% /run/user/1000

From the path hide the name of the blobstorage, so it comes out: https://nombrecuenta.blob.core.windows.net/resources?comp=list&delimiter=/&include=metadata&maxresults=1&restype=container?&User-Agent=azure-storage-fuse/1.3.6&x-ms-date=Wed, 06 Jan 2021 19:43:09 GMT & x-ms-version = 2018-11-09 & Authorization = **** & Transfer-Encoding = ----------------------- -------------------------------------------------- ------- RESPONSE Status :: 200 :: REQ ID: b7d071d8-201e-0021-7564-e40e37000000

vibhansa-msft commented 3 years ago

"-d" not giving any output seems bit weird as that shall launch fuse in debug mode and it shall list all the system calls happening under the hood. This does not appear to be a blobfuse issue, rather something wrong with VM and/or libFuse installation. Is this problem hit only a particular VM, can you try out on some other VM/Machine.

oskr201569 commented 3 years ago

If it happens in that virtual machine, I have another one where this blobfuse is and there it does not generate a problem but I have not found the cause of the error.

NaraVen commented 3 years ago

@oskr201569 , It appears that something is blocking your VM to be in a good state. I suspect cloud_init is not initialized that's why fuse is not triggering init. Can you create a new VM and move on? Here is a link to a similar WALinuxAgent issue https://github.com/Azure/WALinuxAgent/issues/2129

vibhansa-msft commented 3 years ago

Does this issue still persist or there was some VM issue as suspected.

NaraVen commented 3 years ago

In 1.3.7 Blobfuse prints out the errors. This particular issue is also an AKS issue. So I am closing this one at this time.