SLOW CIFS/SMB file transfer on Mac [bug]

Status
Not open for further replies.

funnyprinter

Dabbler
Joined
Mar 14, 2014
Messages
18
How to configure CIFS that local and domain users have fast transfer speeds?

I'm setting up a new FreeNAS. I do have massive performance issues using CIFS / SMB / Samba in combination with an Active Directory (AD) structure. Local as well as domain users transfer data really slow. There as guest user is fine.

Transfer Speeds

CIFS / SMB

User ---------- write ------------ read
LocalUser ---- 21.3MB/s -------- 21.8MB/s
Domain ------- 19.7MB/s -------- 19.4MB/s
Guest----------105.1MB/s ------- 101.2MB/s

Mac via AFP with authentication against Active directory as a comparision:
write: 109.7MB/s
read: 108.9MB/s

SMB4.conf

Code:

[global]

    server max protocol = SMB3_11
    encrypt passwords = yes
    dns proxy = no
    strict locking = no
    oplocks = yes
    deadtime = 1
    max log size = 51200
    max open files = 588197
    logging = file
    load printers = no
    printing = bsd
    printcap name = /dev/null
    disable spoolss = yes
    getwd cache = yes
    guest account = nobody
    map to guest = Bad User
    obey pam restrictions = yes
    directory name cache size = 0
    kernel change notify = no
    panic action = /usr/local/libexec/samba/samba-backtrace
    nsupdate command = /usr/local/bin/samba-nsupdate -g
    server string = FreeNAS File Server
    ea support = yes
    store dos attributes = yes
    lm announce = yes
    acl allow execute always = true
    dos filemode = yes
    multicast dns register = yes
    domain logons = no
    idmap config *: backend = tdb
    idmap config *: range = 90000001-100000000
    server role = member server
    workgroup = MYDOMAIN
    realm = MYDOMAIN.LAN
    security = ADS
    client use spnego = yes
    cache directory = /var/tmp/.cache/.samba
    local master = no
    domain master = no
    preferred master = no
    ads dns update = yes
    winbind cache time = 7200
    winbind offline logon = yes
    winbind enum users = yes
    winbind enum groups = yes
    winbind nested groups = yes
    winbind use default domain = no
    winbind refresh tickets = yes
    idmap config MYDOMAIN: backend = rid
    idmap config MYDOMAIN: range = 20000-90000000
    allow trusted domains = no
    client ldap sasl wrapping = plain
    template shell = /bin/sh
    template homedir = /home/%D/%U
    netbios name = S-FREENAS
    pid directory = /var/run/samba
    create mask = 0666
    directory mask = 0777
    client ntlmv2 auth = yes
    dos charset = CP437
    unix charset = UTF-8
    log level = 1

[temp]

    path = /mnt/zfs03/temp
    printable = no
    veto files = /.snapshot/.windows/.mac/.zfs/
    writeable = yes
    browseable = yes
    vfs objects = zfs_space zfsacl aio_pthread streams_xattr catia fruit
    hide dot files = yes
    guest ok = yes
    nfs4:mode = special
    nfs4:acedup = merge
    nfs4:chown = true
    zfsacl:acesort = dontcare



TOP while file access via authentciated local root

Code:
last pid: 46255;  load averages:  0.81,  0.49,  0.39                                                     up 2+01:33:28  10:49:23

45 processes:  3 running, 42 sleeping
CPU: 11.7% user,  0.0% nice,  0.9% system,  0.0% interrupt, 87.4% idle
Mem: 273M Active, 3125M Inact, 15G Wired, 230M Cache, 734M Free
ARC: 14G Total, 985M MFU, 12G MRU, 290K Anon, 63M Header, 202M Other
Swap: 8192M Total, 148K Used, 8191M Free

  PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME    WCPU COMMAND

46144 root          1 102    0   337M 29744K CPU4    4   1:46 100.00% smbd
2443 root          1 -52   r0  6304K  2272K CPU1    1  13:39   0.10% watchdogd
11480 root         12  21    0   241M 20348K nanslp  1  18:20   0.00% collectd
4655 root          6  21    0   409M   183M select  7   7:11   0.00% python2.7
19466 root          1  52    0   237M 64044K select  7   2:46   0.00% python2.7
2779 root          1  20    0 36500K 18216K select  5   0:56   0.00% ntpd
1919 root          1  20    0 79388K  5024K kqread  3   0:16   0.00% syslog-ng
1230 root          1  20    0 13772K  4964K select  6   0:03   0.00% devd
5894 root          1  52    0   167M 48784K ttyin   2   0:01   0.00% python2.7
35361 root          4  52    0   169M 45904K usem    3   0:01   0.00% python2.7
5707 root          1  20    0 29176K   836K nanslp  7   0:01   0.00% cron
4384 root          1  32   10 17064K  1168K wait    4   0:01   0.00% sh
5693 root          1  20    0 51708K  3028K select  4   0:01   0.00% zfsd
36386 root          1  20    0   105M  8912K select  4   0:01   0.00% afpd
12778 www           1  20    0 40356K  3596K kqread  5   0:01   0.00% nginx
4361 root          1  20    0 30728K  1988K nanslp  6   0:00   0.00% smartd
36384 root          2  20    0 32932K  3000K kqread  7   0:00   0.00% netatalk
43965 root          1  20    0   409M 23608K select  3   0:00   0.00% winbindd
32798 root          1  20    0   109M  7072K select  2   0:00   0.00% sshd
44480 root          1  20    0   411M 23008K select  7   0:00   0.00% winbindd
46200 root          1  20    0 34500K  3372K CPU0    0   0:00   0.00% top
4167 root          1  47    0 71684K  6204K select  6   0:00   0.00% sshd
44409 root          1  20    0   416M 22860K select  7   0:00   0.00% winbindd
35358 nobody        1  20    0 25472K  2916K select  7   0:00   0.00% mdnsd
32801 root          1  20    0 36152K  4088K pause   7   0:00   0.00% csh
43956 root          1  20    0   235M 16612K select  3   0:00   0.00% nmbd
43960 root          1  20    0   288M 23116K select  3   0:00   0.00% smbd
43964 root          1  20    0   282M 22488K select  6   0:00   0.00% smbd
4560 root          1  20    0 40356K  2976K pause   5   0:00   0.00% nginx
36387 root          1  20    0 34808K  2856K select  1   0:00   0.00% cnid_metad
4856 root          1  20    0 14460K   472K sigwai  7   0:00   0.00% daemon
5896 root          1  52    0 14488K  2004K ttyin   3   0:00   0.00% getty
5900 root          1  52    0 14488K  2004K ttyin   4   0:00   0.00% getty
5897 root          1  52    0 14488K  2004K ttyin   0   0:00   0.00% getty
5901 root          1  52    0 14488K  2004K ttyin   5   0:00   0.00% getty
5895 root          1  52    0 14488K  2004K ttyin   1   0:00   0.00% getty
5898 root          1  52    0 14488K  2004K ttyin   6   0:00   0.00% getty
5899 root          1  52    0 14488K  2004K ttyin   7   0:00   0.00% getty
46156 root          1  20    0   410M 23628K select  4   0:00   0.00% winbindd
17982 root          1  52    0  8228K  1884K nanslp  5   0:00   0.00% sleep
46238 root          1  32   10  8228K  1884K nanslp  5   0:00   0.00% sleep
1918 root          1  52    0 38416K     0K wait    1   0:00   0.00% <syslog-ng>
4667 messagebus    1  52    0 27500K  2416K select  5   0:00   0.00% dbus-daemon
17979 root          1  52    0 17064K  2328K wait    0   0:00   0.00% sh
1217 root          1  52    0 16708K  2056K select  2   0:00   0.00% mouse


TOP while transfering as guest

Code:
last pid: 46439;  load averages:  0.91,  0.68,  0.49                                                     up 2+01:37:13  10:53:08
45 processes:  1 running, 44 sleeping
CPU:  0.8% user,  0.0% nice,  3.6% system,  1.9% interrupt, 93.7% idle
Mem: 273M Active, 3125M Inact, 15G Wired, 230M Cache, 734M Free
ARC: 14G Total, 1332M MFU, 13G MRU, 8994K Anon, 64M Header, 203M Other
Swap: 8192M Total, 148K Used, 8191M Free

PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME    WCPU COMMAND
46407 root          1  46    0   337M 29760K select  4   0:14  38.09% smbd
11480 root         12  21    0   241M 20380K nanslp  3  18:22   0.20% collectd
19466 root          1  52    0   237M 64044K select  6   2:46   0.20% python2.7
2443 root          1 -52   r0  6304K  2272K nanslp  2  13:40   0.10% watchdogd
4655 root          6  20    0   409M   183M select  6   7:15   0.00% python2.7
2779 root          1  20    0 36500K 18216K select  3   0:56   0.00% ntpd


Freenas Reporting

https://www.dropbox.com/s/2s59qcrlas8icna/freenas-performance-issues-loggedin-stats.png?dl=0

Hardware
  • AsRock C2750D4I
  • Intel Octa Core Avoton C2750 (8 Cores a 2.4 GHz. Turbo up to 2.6GHz)
  • 16GB DDR3 1600 ECC Ram
  • 4 WD Red Pro 4TB (2 stripped mirrors)
  • 1GB/s Lan
  • FreeNAS OS on on 32GB USB2.0 stick
This configuration seems to work fine on other systems, thus I'd exclude it as a reason for slow traffic.
 
Last edited:

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,554
How to configure CIFS that local and domain users have fast transfer speeds?

I'm setting up a new FreeNAS. I do have massive performance issues using CIFS / SMB / Samba in combination with an Active Directory (AD) structure. Local as well as domain users transfer data really slow. There as guest user is fine.

Transfer Speeds

CIFS / SMB

User ---------- write ------------ read
LocalUser ---- 21.3MB/s -------- 21.8MB/s
Domain ------- 19.7MB/s -------- 19.4MB/s
Guest----------105.1MB/s ------- 101.2MB/s

Mac via AFP with authentication against Active directory as a comparision:
write: 109.7MB/s
read: 108.9MB/s

SMB4.conf

Code:

[global]

    server max protocol = SMB3_11
    encrypt passwords = yes
    dns proxy = no
    strict locking = no
    oplocks = yes
    deadtime = 1
    max log size = 51200
    max open files = 588197
    logging = file
    load printers = no
    printing = bsd
    printcap name = /dev/null
    disable spoolss = yes
    getwd cache = yes
    guest account = nobody
    map to guest = Bad User
    obey pam restrictions = yes
    directory name cache size = 0
    kernel change notify = no
    panic action = /usr/local/libexec/samba/samba-backtrace
    nsupdate command = /usr/local/bin/samba-nsupdate -g
    server string = FreeNAS File Server
    ea support = yes
    store dos attributes = yes
    lm announce = yes
    acl allow execute always = true
    dos filemode = yes
    multicast dns register = yes
    domain logons = no
    idmap config *: backend = tdb
    idmap config *: range = 90000001-100000000
    server role = member server
    workgroup = MYDOMAIN
    realm = MYDOMAIN.LAN
    security = ADS
    client use spnego = yes
    cache directory = /var/tmp/.cache/.samba
    local master = no
    domain master = no
    preferred master = no
    ads dns update = yes
    winbind cache time = 7200
    winbind offline logon = yes
    winbind enum users = yes
    winbind enum groups = yes
    winbind nested groups = yes
    winbind use default domain = no
    winbind refresh tickets = yes
    idmap config MYDOMAIN: backend = rid
    idmap config MYDOMAIN: range = 20000-90000000
    allow trusted domains = no
    client ldap sasl wrapping = plain
    template shell = /bin/sh
    template homedir = /home/%D/%U
    netbios name = S-FREENAS
    pid directory = /var/run/samba
    create mask = 0666
    directory mask = 0777
    client ntlmv2 auth = yes
    dos charset = CP437
    unix charset = UTF-8
    log level = 1

[temp]

    path = /mnt/zfs03/temp
    printable = no
    veto files = /.snapshot/.windows/.mac/.zfs/
    writeable = yes
    browseable = yes
    vfs objects = zfs_space zfsacl aio_pthread streams_xattr catia fruit
    hide dot files = yes
    guest ok = yes
    nfs4:mode = special
    nfs4:acedup = merge
    nfs4:chown = true
    zfsacl:acesort = dontcare



TOP while file access via authentciated local root

Code:
last pid: 46255;  load averages:  0.81,  0.49,  0.39                                                     up 2+01:33:28  10:49:23

45 processes:  3 running, 42 sleeping
CPU: 11.7% user,  0.0% nice,  0.9% system,  0.0% interrupt, 87.4% idle
Mem: 273M Active, 3125M Inact, 15G Wired, 230M Cache, 734M Free
ARC: 14G Total, 985M MFU, 12G MRU, 290K Anon, 63M Header, 202M Other
Swap: 8192M Total, 148K Used, 8191M Free

  PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME    WCPU COMMAND

46144 root          1 102    0   337M 29744K CPU4    4   1:46 100.00% smbd
2443 root          1 -52   r0  6304K  2272K CPU1    1  13:39   0.10% watchdogd
11480 root         12  21    0   241M 20348K nanslp  1  18:20   0.00% collectd
4655 root          6  21    0   409M   183M select  7   7:11   0.00% python2.7
19466 root          1  52    0   237M 64044K select  7   2:46   0.00% python2.7
2779 root          1  20    0 36500K 18216K select  5   0:56   0.00% ntpd
1919 root          1  20    0 79388K  5024K kqread  3   0:16   0.00% syslog-ng
1230 root          1  20    0 13772K  4964K select  6   0:03   0.00% devd
5894 root          1  52    0   167M 48784K ttyin   2   0:01   0.00% python2.7
35361 root          4  52    0   169M 45904K usem    3   0:01   0.00% python2.7
5707 root          1  20    0 29176K   836K nanslp  7   0:01   0.00% cron
4384 root          1  32   10 17064K  1168K wait    4   0:01   0.00% sh
5693 root          1  20    0 51708K  3028K select  4   0:01   0.00% zfsd
36386 root          1  20    0   105M  8912K select  4   0:01   0.00% afpd
12778 www           1  20    0 40356K  3596K kqread  5   0:01   0.00% nginx
4361 root          1  20    0 30728K  1988K nanslp  6   0:00   0.00% smartd
36384 root          2  20    0 32932K  3000K kqread  7   0:00   0.00% netatalk
43965 root          1  20    0   409M 23608K select  3   0:00   0.00% winbindd
32798 root          1  20    0   109M  7072K select  2   0:00   0.00% sshd
44480 root          1  20    0   411M 23008K select  7   0:00   0.00% winbindd
46200 root          1  20    0 34500K  3372K CPU0    0   0:00   0.00% top
4167 root          1  47    0 71684K  6204K select  6   0:00   0.00% sshd
44409 root          1  20    0   416M 22860K select  7   0:00   0.00% winbindd
35358 nobody        1  20    0 25472K  2916K select  7   0:00   0.00% mdnsd
32801 root          1  20    0 36152K  4088K pause   7   0:00   0.00% csh
43956 root          1  20    0   235M 16612K select  3   0:00   0.00% nmbd
43960 root          1  20    0   288M 23116K select  3   0:00   0.00% smbd
43964 root          1  20    0   282M 22488K select  6   0:00   0.00% smbd
4560 root          1  20    0 40356K  2976K pause   5   0:00   0.00% nginx
36387 root          1  20    0 34808K  2856K select  1   0:00   0.00% cnid_metad
4856 root          1  20    0 14460K   472K sigwai  7   0:00   0.00% daemon
5896 root          1  52    0 14488K  2004K ttyin   3   0:00   0.00% getty
5900 root          1  52    0 14488K  2004K ttyin   4   0:00   0.00% getty
5897 root          1  52    0 14488K  2004K ttyin   0   0:00   0.00% getty
5901 root          1  52    0 14488K  2004K ttyin   5   0:00   0.00% getty
5895 root          1  52    0 14488K  2004K ttyin   1   0:00   0.00% getty
5898 root          1  52    0 14488K  2004K ttyin   6   0:00   0.00% getty
5899 root          1  52    0 14488K  2004K ttyin   7   0:00   0.00% getty
46156 root          1  20    0   410M 23628K select  4   0:00   0.00% winbindd
17982 root          1  52    0  8228K  1884K nanslp  5   0:00   0.00% sleep
46238 root          1  32   10  8228K  1884K nanslp  5   0:00   0.00% sleep
1918 root          1  52    0 38416K     0K wait    1   0:00   0.00% <syslog-ng>
4667 messagebus    1  52    0 27500K  2416K select  5   0:00   0.00% dbus-daemon
17979 root          1  52    0 17064K  2328K wait    0   0:00   0.00% sh
1217 root          1  52    0 16708K  2056K select  2   0:00   0.00% mouse


TOP while transfering as guest

Code:
last pid: 46439;  load averages:  0.91,  0.68,  0.49                                                     up 2+01:37:13  10:53:08
45 processes:  1 running, 44 sleeping
CPU:  0.8% user,  0.0% nice,  3.6% system,  1.9% interrupt, 93.7% idle
Mem: 273M Active, 3125M Inact, 15G Wired, 230M Cache, 734M Free
ARC: 14G Total, 1332M MFU, 13G MRU, 8994K Anon, 64M Header, 203M Other
Swap: 8192M Total, 148K Used, 8191M Free

PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME    WCPU COMMAND
46407 root          1  46    0   337M 29760K select  4   0:14  38.09% smbd
11480 root         12  21    0   241M 20380K nanslp  3  18:22   0.20% collectd
19466 root          1  52    0   237M 64044K select  6   2:46   0.20% python2.7
2443 root          1 -52   r0  6304K  2272K nanslp  2  13:40   0.10% watchdogd
4655 root          6  20    0   409M   183M select  6   7:15   0.00% python2.7
2779 root          1  20    0 36500K 18216K select  3   0:56   0.00% ntpd


Freenas Reporting

https://www.dropbox.com/s/2s59qcrlas8icna/freenas-performance-issues-loggedin-stats.png?dl=0

Hardware
  • AsRock C2750D4I
  • Intel Octa Core Avoton C2750
  • 16GB DDR3 1600 ECC Ram
  • 4 WD Red Pro 4TB (2 stripped mirrors)
  • 1GB/s Lan
  • FreeNAS OS on on 32GB USB2.0 stick
This configuration seems to work fine on other systems, thus I'd exclude it as a reason for slow traffic.
Try looking for error messages in /var/log/samba4/log.smbd. It might be a permissions issue.

Single-threaded performance does matter in Samba. Especially when you're working with small files.
 
Last edited:

funnyprinter

Dabbler
Joined
Mar 14, 2014
Messages
18
Try looking for error messages in /var/log/samba4/log.smbd.

Hardware specs are already includes above. Need anything more?

/var/log/samba4/log.smbd not really showing any errors, as I can read.

Code:
[2016/08/31 10:33:12.522958,  1] ../source3/profile/profile_dummy.c:30(set_profile_level)
  INFO: Profiling support unavailable in this build.
[2016/08/31 10:33:12.537275,  1] ../source3/smbd/files.c:218(file_init_global)
  file_init_global: Information only: requested 588197 open files, 59392 are available.
[2016/08/31 10:33:12.543395,  0] ../lib/util/become_daemon.c:124(daemon_ready)
  STATUS=daemon 'smbd' finished starting up and ready to serve connections
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,554
Hardware specs are already includes above. Need anything more?

/var/log/samba4/log.smbd not really showing any errors, as I can read.

Code:
[2016/08/31 10:33:12.522958,  1] ../source3/profile/profile_dummy.c:30(set_profile_level)
  INFO: Profiling support unavailable in this build.
[2016/08/31 10:33:12.537275,  1] ../source3/smbd/files.c:218(file_init_global)
  file_init_global: Information only: requested 588197 open files, 59392 are available.
[2016/08/31 10:33:12.543395,  0] ../lib/util/become_daemon.c:124(daemon_ready)
  STATUS=daemon 'smbd' finished starting up and ready to serve connections
Try checking /var/log/messages and your winbind logs under /var/log/samba4.

Try removing vfs objects and see if one of them or a combination is causing performance issues. Is this a single large file or lots of small files?

Also try increasing logging verbosity in samba.
 

funnyprinter

Dabbler
Joined
Mar 14, 2014
Messages
18
active directory disabled.
All vfs objects removed.

tailf -f /var/log/messages

Code:
Aug 31 12:01:14 s-fnas generate_smb4_conf.py: [common.pipesubr:66] Popen()ing: /sbin/sysctl -n 'kern.maxfilesperproc'
Aug 31 12:01:14 s-fnas generate_smb4_conf.py: [common.pipesubr:66] Popen()ing: mount
Aug 31 12:01:14 s-fnas generate_smb4_conf.py: [common.pipesubr:66] Popen()ing: mount
Aug 31 12:01:14 s-fnas generate_smb4_conf.py: [common.pipesubr:66] Popen()ing: /usr/local/bin/net -d 0 getlocalsid
Aug 31 12:01:15 s-fnas notifier: Performing sanity check on Samba configuration: OK
Aug 31 12:01:15 s-fnas notifier: Starting nmbd.
Aug 31 12:01:15 s-fnas notifier: Starting smbd.
Aug 31 12:01:15 s-fnas notifier: Starting winbindd.
Aug 31 12:01:16 s-fnas ActiveDirectory: /usr/sbin/service ix-kinit forcestop
Aug 31 12:01:16 s-fnas ActiveDirectory: /usr/sbin/service ix-hostname quietstart

no new messages while transfering


tail -f /var/log/samba/*

Code:
==> /var/log/samba4/log.nmbd <==
[2016/08/31 12:00:59.842525,  0] ../source3/nmbd/nmbd.c:58(terminate)
  Got SIGTERM: going down...
[2016/08/31 12:01:15.392989,  0] ../lib/util/become_daemon.c:124(daemon_ready)
  STATUS=daemon 'nmbd' finished starting up and ready to serve connections


==> /var/log/samba4/log.smbd <==
[2016/08/31 12:01:15.501509,  1] ../source3/profile/profile_dummy.c:30(set_profile_level)
  INFO: Profiling support unavailable in this build.
[2016/08/31 12:01:15.514240,  1] ../source3/smbd/files.c:218(file_init_global)
  file_init_global: Information only: requested 588197 open files, 59392 are available.
[2016/08/31 12:01:15.520410,  0] ../lib/util/become_daemon.c:124(daemon_ready)
  STATUS=daemon 'smbd' finished starting up and ready to serve connections


==> /var/log/samba4/log.winbindd <==
[2016/08/31 12:01:15.608227,  0] ../source3/winbindd/winbindd_cache.c:3245(initialize_winbindd_cache)
  initialize_winbindd_cache: clearing cache and re-creating with version number 2
[2016/08/31 12:01:15.611206,  0] ../lib/util/become_daemon.c:124(daemon_ready)
  STATUS=daemon 'winbindd' finished starting up and ready to serve connections

############ START OF TRANSFAR ##############

==> /var/log/samba4/log.wb-S-FNAS <==
[2016/08/31 12:05:42.210565,  0] ../source3/winbindd/winbindd_samr.c:624(sam_sid_to_name)
  sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-88-3-33188



Is the last log message meaningful?
 

funnyprinter

Dabbler
Joined
Mar 14, 2014
Messages
18
log level now on normal

tail -f /var/log/samba4/*

Code:
==> /var/log/samba4/log.smbd <==
[2016/08/31 12:14:07.082137,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file .DS_Store read=No write=No (numopen=3)
[2016/08/31 12:14:07.082816,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file .DS_Store (numopen=2) NT_STATUS_OK
[2016/08/31 12:14:07.084681,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file hello.txt.txt read=No write=No (numopen=3)
[2016/08/31 12:14:07.085283,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file hello.txt.txt (numopen=2) NT_STATUS_OK
[2016/08/31 12:14:07.085837,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file test-by-windows.txt read=No write=No (numopen=3)
[2016/08/31 12:14:07.086463,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file test-by-windows.txt (numopen=2) NT_STATUS_OK
[2016/08/31 12:14:07.087610,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file test-by-mac.txt read=No write=No (numopen=3)
[2016/08/31 12:14:07.088218,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file test-by-mac.txt (numopen=2) NT_STATUS_OK
[2016/08/31 12:14:48.908044,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file DiskSpeedTestTemp read=No write=Yes (numopen=3)
[2016/08/31 12:14:48.910711,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file DiskSpeedTestTemp read=No write=No (numopen=4)
[2016/08/31 12:14:48.911708,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file DiskSpeedTestTemp (numopen=3) NT_STATUS_OK
[2016/08/31 12:14:48.914241,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file DiskSpeedTestTemp read=No write=No (numopen=4)


==> /var/log/samba4/log.wb-S-FNAS <==
[2016/08/31 12:14:48.915044,  0] ../source3/winbindd/winbindd_samr.c:624(sam_sid_to_name)
  sam_sid_to_name: possible deadlock - trying to lookup SID S-1-5-88-3-33188

==> /var/log/samba4/log.smbd <==
[2016/08/31 12:14:48.916625,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file DiskSpeedTestTemp (numopen=3) NT_STATUS_OK
[2016/08/31 12:14:49.371034,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file .DS_Store read=No write=No (numopen=4)
[2016/08/31 12:14:49.371656,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file .DS_Store (numopen=3) NT_STATUS_OK
[2016/08/31 12:14:49.373438,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file hello.txt.txt read=No write=No (numopen=4)
[2016/08/31 12:14:49.374013,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file hello.txt.txt (numopen=3) NT_STATUS_OK
[2016/08/31 12:14:49.374565,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file test-by-windows.txt read=No write=No (numopen=4)
[2016/08/31 12:14:49.375121,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file test-by-windows.txt (numopen=3) NT_STATUS_OK
[2016/08/31 12:14:49.376219,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file test-by-mac.txt read=No write=No (numopen=4)
[2016/08/31 12:14:49.376779,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file test-by-mac.txt (numopen=3) NT_STATUS_OK
[2016/08/31 12:14:49.462886,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file DiskSpeedTestTemp read=No write=No (numopen=4)
[2016/08/31 12:14:49.463508,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file DiskSpeedTestTemp (numopen=3) NT_STATUS_OK
[2016/08/31 12:14:52.191093,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file DiskSpeedTestTemp read=No write=No (numopen=4)
[2016/08/31 12:14:52.191712,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file DiskSpeedTestTemp (numopen=3) NT_STATUS_OK
[2016/08/31 12:14:52.684013,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file DiskSpeedTestTemp read=No write=No (numopen=4)
[2016/08/31 12:14:52.684682,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file DiskSpeedTestTemp (numopen=3) NT_STATUS_OK
[2016/08/31 12:14:57.114750,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file DiskSpeedTestTemp (numopen=2) NT_STATUS_OK
[2016/08/31 12:14:57.117014,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file DiskSpeedTestTemp read=No write=No (numopen=3)
[2016/08/31 12:14:57.117676,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file DiskSpeedTestTemp (numopen=2) NT_STATUS_OK
[2016/08/31 12:14:57.118713,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file DiskSpeedTestTemp read=Yes write=No (numopen=3)
[2016/08/31 12:14:57.448326,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file DiskSpeedTestTemp read=No write=No (numopen=4)
[2016/08/31 12:14:57.449023,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file DiskSpeedTestTemp (numopen=3) NT_STATUS_OK
[2016/08/31 12:14:57.720684,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file .DS_Store read=No write=No (numopen=4)
[2016/08/31 12:14:57.721356,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file .DS_Store (numopen=3) NT_STATUS_OK
[2016/08/31 12:14:57.723419,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file hello.txt.txt read=No write=No (numopen=4)
[2016/08/31 12:14:57.724031,  2] ../source3/smbd/close.c:790(close_normal_file)
  root closed file hello.txt.txt (numopen=3) NT_STATUS_OK
[2016/08/31 12:14:57.724725,  2] ../source3/smbd/open.c:1005(open_file)
  root opened file test-by-windows.txt read=No write=No (numopen=4)
[2016/08/31 12:14:57.725297,  2] ../source3/smbd/close.c:790(close_normal_file)
...
 

nojohnny101

Wizard
Joined
Dec 3, 2015
Messages
1,478
Is this a single large file or lots of small files?

what type of files are you transferring?
 

funnyprinter

Dabbler
Joined
Mar 14, 2014
Messages
18
what type of files are you transferring?

In this case the files of Disk Speed Testing Tools:

  • Disk Speed Test by Black Magic Design for Mac
  • LanSpeed1 for Windows.
Basically they write 1 File with 1GB random data to disc and read it back in. So as written above only sequential file access, and no random IO tests, to ensure not disk io is the limiting factor.

Since speeds are only limited for authenticated smb users, the problem must correlate to smb, though. AFP and SMB guest users are transferring total fine with about 110MB/s which is for a 1Gb lan not too bad.
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,554
In this case the files of Disk Speed Testing Tools:

  • Disk Speed Test by Black Magic Design for Mac
  • LanSpeed1 for Windows.
Basically they write 1 File with 1GB random data to disc and read it back in. So as written above only sequential file access, and no random IO tests, to ensure not disk io is the limiting factor.

Since speeds are only limited for authenticated smb users, the problem must correlate to smb, though. AFP and SMB guest users are transferring total fine with about 110MB/s which is for a 1Gb lan not too bad.
Or correlate to your benchmark tool. :D Test with a real file through explorer.
 

funnyprinter

Dabbler
Joined
Mar 14, 2014
Messages
18
Since the difference in users comes from logging into the nas with a different user on os mounting, it doesn't make any difference copying files by hand or by tool. Tools are just automating the testing and measuring much faster and more accurate than I do it manually.

Copying ubuntu (700MB)
Root 41s
Guest 8s
 

funnyprinter

Dabbler
Joined
Mar 14, 2014
Messages
18
Or correlate to your benchmark tool. :D Test with a real file through explorer.

I did a lot of further testing. Problem still exits. It is not depending on the testing tool or transferring files manually. However seems to be mainly correlating to macs. I re-setup the server fully.

Retesting on windows shows windows is now better:

Windows - Guest
Writing ~92MB/s
Reading ~97MB/s
TOP ~30%-40%. Not maxing out.

Windows - Authenticate User (still dislike the numbers compared to mac guest)
Writing ~70MB/s
Reading ~76MB/s
TOP ~30%-58%. Not maxing out.

Mac - Guest
Write 107MB/s
Read 110MB/s
TOP smbd ~30%-40% CPU. No maxing out

Mac - Authenticated: (The problematic part, my majority of users)
Write 20MB/s
Read 20MB/s
TOP smbd ~100% CPU. Maxing out

Testing still 5GB chunks
 

funnyprinter

Dabbler
Joined
Mar 14, 2014
Messages
18
Just further Test as discusses on FreeNAS IRC Channel

Copying on Shell with top on mac and freenas, transfering a linux image with 667MB as test data.

As User testy:
time cp source target: real 37s = 18MB/s.
mac kernal_task went up to 25-30% usage, no smbd process on top list
Freenas smbd is varyying between 60%-90%

As Guest
time cp source target: real 7.5s = 89MB/s.
mac kernal_task went up to 90-120% usage, no smbd process on top list
Freenas smbd is varyying between 20%-30%
 

funnyprinter

Dabbler
Joined
Mar 14, 2014
Messages
18
Apple Security Bug Fix may be the cause of the problem

German tech news on heise report of a smb bug fix in Mac OS X El Capitan 10.11.5 slowing down due to newly activated signing in OSX. Apple turned on signing by default, to not be a security vulnerability by the Samba BadLock-Exploids. There is also a discussion on apple forums. Apple recommends updating the NAS system to the latest version, that the NAS supports signing correctly too.

SMB BadLock Security Bug
However, the problem may be solved by updating smb to the latest version, which is anyways recommended in reason of the badlock security vulnerable.

Quick Fix for making mac fast for now:
Disable signing (by default) on the SMB Client. This will “man in the middle attacks” and
possible “badlock” attacks, but you may be on a secure network.
Code:
echo "[default]" > /etc/nsmb.conf
echo signing_required=no >> /etc/nsmb.conf
reboot
 
Last edited by a moderator:
Status
Not open for further replies.
Top