Bug 1569868

Could you get us a log level 10 debug log, so that we see what is going on. This looks like it is running into a connection timeout.

See GVFS_SMB_DEBUG at

https://wiki.gnome.org/Projects/gvfs/doc

Created attachment 1454937 [details]
GVFS debug log with level 10

Ondrej, could you help finding what the issue is? I have no idea how to debug gvfs to see where and why it is so slow.

Hmm, I've already seen many bug reports regarding samba backend performance, but if I recall correctly, the problem always was file transfer speed, not directory listing. But if samba downgrade helps to fix this issue, I don't think this is gvfs issue. It would be nice to try with some other libsmbclient-based tools.

Is `smbclient` also so slow (though not sure that this really uses the libsmbclient methods)? It would be good to compare with KIO also...

smbclient //SERVERNAME/SHARE -U USER -W DOMAIN -c "ls DIR1/SUBDIR1/*"

Enumeration job consist of just `opendir`, `getdents`, `stat` and `closedir` libsmbclient methods, see:
https://gitlab.gnome.org/GNOME/gvfs/blob/master/daemon/gvfsbackendsmb.c#L1734

However, `ls /run/user/12184/gvfs/smb-share\:server\=SERVERNAME\,share\=SHARE/` uses fuse mount, which may also call other jobs. Can you please try it directly over `gvfs-ls`? Is `gvfs-ls` also similarly slow?

gvfs-mount smb://SERVERNAME/SHARE
gvfs-ls smb://SERVERNAME/SHARE/DIR1/SUBDIR1

The attached gvfs debug output, unfortunately, doesn't contain samba debug info for some reason. Can you please try again e.g. using the steps from https://wiki.gnome.org/Projects/gvfs/debugging#Getting_debug_logs and use the following as the second step and ideally only `gvfs-mount` and `gvfs-ls` as the third step:

GVFS_SMB_DEBUG=10 GVFS_DEBUG=1 $(find /usr/lib* -name gvfsd 2>/dev/null) --replace 2>&1 | tee gvfsd.log

I am able to reproduce some slowdown using RHEL 7.4 VM and folder with 10000 files against server on F29 VM on the same host. I suppose that it would be much more obvious with some remote server even with smaller amount of files. It is reproducible only by updating samba packages, so changing component to samba...

$ rpm -q libsmbclient
libsmbclient-4.6.2-8.el7.x86_64
$ time gio list -la "*" smb://192.168.122.252/user/test > /dev/null
real	0m4.619s
user	0m0.901s
sys	0m0.038s
$ time ls -la /mnt/test > /dev/null
real	0m1.733s
user	0m0.064s
sys	0m0.243s

$ sudo yum update samba*
$ rpm -q libsmbclient
libsmbclient-4.7.1-6.el7.x86_64 
$ time gio list -la "*" smb://192.168.122.252/user/test > /dev/null
real	0m6.463s
user	0m0.854s
sys	0m0.036s
$ time ls -la /mnt/test > /dev/null
real	0m1.632s
user	0m0.058s
sys	0m0.230s

GVfs calls smbc_opendir and smbc_getdents once and smbc_stat for EACH file in case of "-la" options. It seems to me that this is because smbc_stat is slower with new versions for some reason... any idea why?

I suppose that CIFS uses some faster approach which is not available in libsmbclient and thus is generally faster than GVfs. It can't be reproduced over smbclient tool, because it simply doesn't provide "-la" options. 

I am going to attach corresponding gvfsd.log files with GVFS_SMB_DEBUG=10-

Created attachment 1506399 [details]
gvfsd-samba-4.6.log

Created attachment 1506400 [details]
gvfsd-samba-4.7.log

Hi,

For your information, under RHEL 7.5 the problem was fixed after upgrading all related samba packages from version 4.7.1-6.el7 to 4.7.1-9.el7_5:

Aug 23 09:16:21 Updated: samba-common-4.7.1-9.el7_5.noarch
Aug 23 09:16:21 Updated: samba-common-libs-4.7.1-9.el7_5.x86_64
Aug 23 09:16:21 Updated: libwbclient-4.7.1-9.el7_5.x86_64
Aug 23 09:16:21 Updated: samba-client-libs-4.7.1-9.el7_5.x86_64
Aug 23 09:16:22 Updated: libsmbclient-4.7.1-9.el7_5.x86_64
Aug 23 09:16:22 Updated: samba-client-4.7.1-9.el7_5.x86_64

After upgrading to RHEL 7.6 and version 4.8.3-4.el7 of samba packages, the issue did not reappeared.

Dominique

Thanks for the feedback, however, I see the same slowness as described in Comment 7 also with 4.8.3-4.el7 and 4.7.1-9.el7_5, so maybe you hit an another issue than me...

To someone who could reproduce it:

I need network traces of browsing the exact same directory with Samba 4.6 and Samba 4.8 to be able to compare traces and see what is going on.

(In reply to Andreas Schneider from comment #12)
> To someone who could reproduce it:
> 
> I need network traces of browsing the exact same directory with Samba 4.6
> and Samba 4.8 to be able to compare traces and see what is going on.

I can assist, though I can test it with the Archlinux packages 4.6.7 and 4.8.5.
What kind of traces do you need? Are *.pcap files sufficient?

For now, what I see is: `ls -l` on a cifs mount is satisfied with just a single request:

    SMB2_FIND_ID_FULL_DIRECTORY_INFO Pattern: *

`gio list` with smbclient 4.6 uses SMB (v1) and for some unobvious reason does one QUERY_PATH_INFO for each found file.

`gio list` with smbclient 4.8 uses SMB2 and does three requests instead of one for each found file: 

    - Create Request File
    - GetInfo Request FILE_INFO/SMB2_FILE_ALL_INFO File
    - Close Request File

And as expected, this consumes x3 time compared to 4.6

Yes, I need pcap files.

The following link has some hints about tcpdump https://hackmd.io/s/SkHk8rXBz#

Created attachment 1518319 [details]
46.pcap

Created attachment 1518320 [details]
48.pcap

Attached 46.pcap and 48.pcap

Client commands:

    gio mount -a 'smb://okdistrhw/distr-ro'
    time gio list 'smb://okdistrhw/distr-ro/unmountable'

Non-default server config:

	[global]
	map to guest = Bad User

	[distr-ro]
	path = /exports/okdistr
	public = yes

Ah, here is the problem.

gio is doing opendir/readdir/close to get the file
name list.

At this point we're actually already fetching all
required info to satisfy a stat via SMB2_FIND_ID_BOTH_DIRECTORY_INFO.

Then gio does a stat() on every name it got from
the readdir call.

That is what is translating into QUERY_PATH_INFO in SMB1
and open/getinfo/close in SMB2.

What gio should be doing is the readdirplus() call,
which associates the stat info we already got in
the directory traversal.

Can someone point me at the gio code so I can see
exactly what libsmbclient calls it's using here ?

Jeremy.

Found the source code for the SMB backend to gvfs. It's doing:

  while (TRUE)
    {
      res = smbc_getdents (op_backend->smb_context, dir, (struct smbc_dirent *)dirents, sizeof (dirents));
      if (res <= 0)
        break;
      
      dirp = (struct smbc_dirent *)dirents;
      while (res > 0)
        {
          unsigned int dirlen;

          /* TODO: Only do stat if required for flags */
          
          if ((dirp->smbc_type == SMBC_DIR ||
               dirp->smbc_type == SMBC_FILE ||
               dirp->smbc_type == SMBC_LINK) &&
              strcmp (dirp->name, ".") != 0 &&
              strcmp (dirp->name, "..") != 0)
            {
              int stat_res;
              g_string_truncate (uri, uri_start_len);
              g_string_append_uri_escaped (uri, dirp->name, SUB_DELIM_CHARS ":@/", FALSE);

              if (matcher == NULL ||
                  g_file_attribute_matcher_matches_only (matcher, G_FILE_ATTRIBUTE_STANDARD_NAME))
                {
                  info = g_file_info_new ();
                  g_file_info_set_name (info, dirp->name);
                  g_vfs_job_enumerate_add_info (job, info);
                  g_object_unref (info);
                }
              else
                {
                  stat_res = smbc_stat (op_backend->smb_context,
                                                            uri->str, &st);

which is as I described. It should be calling smbc_readdirplus() instead here, which would directly avoid the extra smbc_stat() call.

Thanks for your help Jeremy! Moving the bug to Ondrej.

Ondrej, the call will be available with Samba in RHEL 7.7.

I've recently found "smbc_readdirplus()" and tried to use it there, however, it seems that "struct libsmb_file_info" doesn't contain info about file type which is crucial. There is only "attrs", which can be used to distinguish a directory from a file, but not e.g. from a symbolic link...  or am I mistaken?

See:
https://gitlab.gnome.org/GNOME/gvfs/issues/306
https://gitlab.gnome.org/GNOME/gvfs/merge_requests/21

Ondrej: https://lists.samba.org/archive/samba-technical/2019-January/131853.html

Andreas, thanks. So let's move the bug back to samba until smbc_readdirplus2 will be available.

I think this is a gvfs bug, you should open a new one for smbc_readdirplus2():

Add a new smbc_readdirplus2() function to smbclient for faster directory listing

Given the fact that the dependent samba bug hasn't been yet resolved and RHEL 7 is already in the maintenance phase, I am going to close this bug. Please make a clone for RHEL 8 if it is desirable.

Yes, please clone for RHEL 8, we are planning to address this in Samba, it's just that we're resource constrained right now.

I'm not able to reproduce with recent versions of gvfs and samba. But to be 100% sure can you please Amit ask customer to double check with 8.3.0 Beta?

(In reply to Tomas Pelka from comment #35)
> I'm not able to reproduce with recent versions of gvfs and samba. But to be
> 100% sure can you please Amit ask customer to double check with 8.3.0 Beta?

ping

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Moderate: GNOME security, bug fix, and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2020:4451