Poor performance for AFP/CIFS Share on Mac OS 10.9 Mavericks

Status
Not open for further replies.

cyberjock

Inactive Account
Joined
Mar 25, 2012
Messages
19,526
That error means your logs are filling up. Presumably the 40KB/sec was because of some kind of problem on the server-end triggering logs which then turned into a full /var.

Probably not a "Mac" problem in particular as anything that can fill /var will cause problems.
 

xxup

Cadet
Joined
Dec 19, 2011
Messages
6
In /var/log/samba4 there are two large files. log.smbd (35Mb) and log.smdb.old (52Mb). In the CIFS control panel the log level is set at Normal. There are no other obvious large log files in the /var/log folder that I can see. The shell window in the GUI shows no messages since the upgrade to 9.2.1.5 and these messages. I assume, by this that everything is running "normally". In fact, apart from this Mac file copy to FreeNAS, the server has been running beautifully with this version of FreeNAS - no more High CPU and core dumps from Samba. This the extract from the GUI shell/log window to show that nothing of note has happened for the past 8 days:

Apr 30 20:16:49 bern mDNSResponder: mDNS_AddDNSServer: Lock not held! mDNS_busy (0) mDNS_reentrancy (0)
Apr 30 20:16:52 bern mDNSResponder: mDNS_Register_internal: ERROR!! Tried to register AuthRecord 0000000800C2FD60 bern.local. (Addr) that's already in the list
Apr 30 20:16:52 bern mDNSResponder: mDNS_Register_internal: ERROR!! Tried to register AuthRecord 0000000800C30180 45.1.168.192.in-addr.arpa. (PTR) that's already in the list
May 7 17:32:19 bern kernel: pid 96108 (smbd), uid 1001 inumber 21698 on /var: filesystem full
May 7 17:32:50 bern last message repeated 31 times

I just examined the 52Mb log.smbd.old file and there is nothing in there but messages about the file copy. This is the top of the file:

[2014/05/07 22:37:14.710899, 2] ../source3/smbd/close.c:780(close_normal_file) xxup closed file Photos/Slides/TBL/20140501/IMG_0557.JPG (numopen=5) NT_STATUS_OK
[2014/05/07 22:37:14.712757, 2] ../source3/smbd/dosmode.c:91(unix_mode) unix_mode(Photos/Slides/TBL/20140501/IMG_0136.JPG) inheriting from Photos/Slides/TBL/20140501
[2014/05/07 22:37:14.712821, 2] ../source3/smbd/dosmode.c:113(unix_mode) unix_mode(Photos/Slides/TBL/20140501/IMG_0136.JPG) inherit mode 40777
[2014/05/07 22:37:14.713439, 2] ../source3/smbd/open.c:972(open_file) xxup opened file Photos/Slides/TBL/20140501/IMG_0136.JPG read=No write=No (numopen=6)
[2014/05/07 22:37:14.715130, 2] ../source3/smbd/close.c:780(close_normal_file) xxup closed file Photos/Slides/TBL/20140501/IMG_0136.JPG (numopen=5) NT_STATUS_OK
[2014/05/07 22:37:14.716746, 2] ../source3/smbd/dosmode.c:91(unix_mode) unix_mode(Photos/Slides/TBL/20140501/IMG_0691.JPG) inheriting from Photos/Slides/TBL/20140501
[2014/05/07 22:37:14.716810, 2] ../source3/smbd/dosmode.c:113(unix_mode) unix_mode(Photos/Slides/TBL/20140501/IMG_0691.JPG) inherit mode 40777
[2014/05/07 22:37:14.717429, 2] ../source3/smbd/open.c:972(open_file) xxup opened file Photos/Slides/TBL/20140501/IMG_0691.JPG read=No write=No (numopen=6)
[2014/05/07 22:37:14.719098, 2] ../source3/smbd/close.c:780(close_normal_file) xxup closed file Photos/Slides/TBL/20140501/IMG_0691.JPG (numopen=5) NT_STATUS_OK
[2014/05/07 22:37:14.720679, 2] ../source3/smbd/dosmode.c:91(unix_mode) unix_mode(Photos/Slides/TBL/20140501/IMG_0408.JPG) inheriting from Photos/Slides/TBL/20140501
[2014/05/07 22:37:14.720741, 2] ../source3/smbd/dosmode.c:113(unix_mode) unix_mode(Photos/Slides/TBL/20140501/IMG_0408.JPG) inherit mode 40777
[2014/05/07 22:37:14.721496, 2] ../source3/smbd/open.c:972(open_file) xxup opened file Photos/Slides/TBL/20140501/IMG_0408.JPG read=No write=No (numopen=6)
[2014/05/07 22:37:14.723273, 2] ../source3/smbd/close.c:780(close_normal_file) xxup closed file Photos/Slides/TBL/20140501/IMG_0408.JPG (numopen=5) NT_STATUS_OK
[2014/05/07 22:37:14.725059, 2] ../source3/smbd/dosmode.c:91(unix_mode) unix_mode(Photos/Slides/TBL/20140501/IMG_0069.JPG) inheriting from Photos/Slides/TBL/20140501
[2014/05/07 22:37:14.725115, 2] ../source3/smbd/dosmode.c:113(unix_mode) unix_mode

The bottom of the file looks like:

[2014/05/07 22:43:54.595820, 2] ../source3/smbd/dosmode.c:113(unix_mode) unix_mode(Photos/Slides/TBL/20140501/IMG_0703.JPG) inherit mode 40777
[2014/05/07 22:43:54.596393, 2] ../source3/smbd/open.c:972(open_file) xxup opened file Photos/Slides/TBL/20140501/IMG_0703.JPG read=No write=No (numopen=6)
[2014/05/07 22:43:54.598070, 2] ../source3/smbd/close.c:780(close_normal_file) xxup closed file Photos/Slides/TBL/20140501/IMG_0703.JPG (numopen=5) NT_STATUS_OK
[2014/05/07 22:43:54.599849, 2] ../source3/smbd/dosmode.c:91(unix_mode) unix_mode(Photos/Slides/TBL/20140501/IMG_0075.JPG) inheriting from Photos/Slides/TBL/20140501
[2014/05/07 22:43:54.599913, 2] ../source3/smbd/dosmode.c:113(unix_mode) unix_mode(Photos/Slides/TBL/20140501/IMG_0075.JPG) inherit mode 40777
[2014/05/07 22:43:54.600501, 2] ../source3/smbd/open.c:972(open_file) xxup opened file Photos/Slides/TBL/20140501/IMG_0075.JPG read=No write=No (numopen=6)

If this file covers 6 minutes of the copy, then the server must have created hundreds of these log files to cover the entire six hour copy between the Mac and the FreeNAS server.

The current log.smbd file, which is only 35Mb in size, looks similar to the above until the copy finishes at 23:23 hours.
 
D

dlavigne

Guest
since the upgrade to 9.2.1.5

You can move the logs off of /var, which is very limited in space. Typically, this is set in http://doc.freenas.org/index.php/Settings#Advanced_Tab. It looks like doing an upgrade does not automatically create that system dataset. If that checkbox is already checked (not sure if it is or not on an upgrade), what happens if you uncheck it then check it again? Does that create the system dataset and move the logs there?
 

xxup

Cadet
Joined
Dec 19, 2011
Messages
6
Thank you foe the advice.

Yes checking the box does create the .system dataset. See the following console messages:

May 9 14:36:01 bern create_system_datasets.py: [common.pipesubr:58] Popen()ing: /sbin/zfs list -H 'zfs_vol_data/.system'
May 9 14:36:01 bern create_system_datasets.py: [common.pipesubr:58] Popen()ing: /sbin/zfs list -H 'zfs_vol_data/.system/samba4'
May 9 14:36:01 bern create_system_datasets.py: [common.pipesubr:58] Popen()ing: /sbin/zfs list -H 'zfs_vol_data/.system/syslog'
May 9 14:36:01 bern create_system_datasets.py: [common.pipesubr:58] Popen()ing: /sbin/zfs list -H 'zfs_vol_data/.system/cores'
May 9 14:36:01 bern create_system_datasets.py: [common.pipesubr:58] Popen()ing: /sbin/sysctl kern.corefile='/mnt/zfs_vol_data/.system/cores/%N.core' May 9 14:36:02 bern syslogd: kernel boot file is /boot/kernel/kernel

I will try a large copy again and see if the performance is improved.
 

xxup

Cadet
Joined
Dec 19, 2011
Messages
6
To test the changes, I copied the 867 files from the server to the SD card. It took 19 minutes - acceptable over wireless for the 3+Gb.

I then started a copy from the SD to a new folder on the server. Back to the slow speed.

The copy to the SD went from around 14:40 to 15:00 and the copy to the server from the SD card started just after 15:00 the CPU, Load and Network charts are attached.

Needless to say the same data copied to and from a Windows machine is very very fast.

The good news is that the log file messages have stopped, but it is creating a new 52Mb log file every 8 minutes. Something is still wrong here.

I will do another test connected via cable.
 

Attachments

  • MacCPU.jpg
    MacCPU.jpg
    59.9 KB · Views: 344
  • MACLoad.jpg
    MACLoad.jpg
    50.4 KB · Views: 348
  • MacNet.jpg
    MacNet.jpg
    47.7 KB · Views: 331

xxup

Cadet
Joined
Dec 19, 2011
Messages
6
Tested over GB ethernet. Only takes 5 minutes to make every 52Mb file. Copy speed is up to 150Kb (oh joy!).
 

cyberjock

Inactive Account
Joined
Mar 25, 2012
Messages
19,526
I will say that if you don't have appropriate network hardware that supports LACP, said hardware is properly setup and have a userbase of a size to make LACP work you very well could be the cause of your own problems. LACP works great when properly setup. But if you don't meet the requirements it'll cause all sorts of serious networking problems like slow speed, random disconnects, etc.

I'd disable any custom network settings you have including jumbo frames, LACP, etc and try your test again. I wouldn't be testing to/from an SD card. That's always going to be slow since SD cards are a fraction of the speeds you should be capable of getting.
 

xxup

Cadet
Joined
Dec 19, 2011
Messages
6
If this behaviour was exactly the same on the Windows computer I would agree with you, but I have just plugged the same SD card into the Windows Computer. Copy of the same files from the server to the 16 Gb SD card took two minutes at and Avg 31 Mbytes/sec and the copy of the same files to the server took 60 secs at an average of 65 Mbytes/sec. It only happens with a MAC. I am not keen to tamper with the server settings.

I have a Netgear Smart switch GS724T, I am confident that LACP is configured correctly and I do not use Jumbo frames. I do agree that SD cards are slower - in this case only 65 Mbytes/sec instead of my usual 80-100 Mbytes/sec, but I believe that the Windows test eliminates the SD card as the problem. There seems to be something happening when a MAC copies a file to the server that is generating these enormous log entries (52Mb every 8 minutes). The Log file after the windows copy only increased by 1.8Mb. I believe that the entries within the log are also different (compare the numopen= entries for example):

[2014/05/09 21:59:41.552836, 2] ../source3/smbd/dosmode.c:113 (unix_mode) unix_mode(Photos/Slides/TBL/TestArea) inherit mode 40777
[2014/05/09 21:59:41.740263, 2] ../source3/smbd/dosmode.c:91(unix_mode) unix_mode (Photos/Slides/TBL/TestArea/IMG_0849.JPG) inheriting from Photos/Slides/TBL/TestArea
[2014/05/09 21:59:41.740381, 2] ../source3/smbd/dosmode.c:113(unix_mode) unix_mode (Photos/Slides/TBL/TestArea/IMG_0849.JPG) inherit mode 40777
[2014/05/09 21:59:41.741007, 2] ../source3/smbd/open.c:972(open_file) xxup opened file Photos/Slides/TBL/TestArea/IMG_0849.JPG read=No write=No (numopen=41)
[2014/05/09 21:59:41.742586, 2] ../source3/smbd/close.c:780(close_normal_file) xxup closed file Photos/Slides/TBL/TestArea/IMG_0849.JPG (numopen=40) NT_STATUS_OK
[2014/05/09 21:59:41.754031, 2] ../source3/smbd/dosmode.c:91(unix_mode) unix_mode (Photos/Slides/TBL/TestArea/IMG_0829.JPG) inheriting from Photos/Slides/TBL/TestArea
[2014/05/09 21:59:41.754142, 2] ../source3/smbd/dosmode.c:113(unix_mode) unix_mode (Photos/Slides/TBL/TestArea/IMG_0829.JPG) inherit mode 40777
[2014/05/09 21:59:41.754747, 2] ../source3/smbd/open.c:972(open_file) xxup opened file Photos/Slides/TBL/TestArea/IMG_0829.JPG read=No write=No (numopen=41)
[2014/05/09 21:59:41.756059, 2] ../source3/smbd/dosmode.c:91(unix_mode) unix_mode

It is not a big issue for me. I normally copy files using Windows and the performance is excellent. I posted this information in the hope that it would help other MAC users with FreeNAS servers. Something is wrong when a copy process creates 52Mb log files every 8 minutes over a period of 6 hours using a MAC, but only takes 60 seconds on a Windows PC with mere 1.8Mb increase in the log file size.
 

cyberjock

Inactive Account
Joined
Mar 25, 2012
Messages
19,526
Yeah.. just because SD card works on Windows is not an indicator in the slightest that it will work with FreeBSD. I've got multiple SD cards that work great in Windows and never function properly in FreeBSD.

There's lots of technology going on under the hood, both in software and hardware, that make devices "just work". Don't be fooled by the perceived simplicity of "plug it in and it works". It's far more complex and the comparison that "since it works on Windows it should work on FreeBSD" is a big farse. ;)
 

Robert Trevellyan

Pony Wrangler
Joined
May 16, 2014
Messages
3,778
I experienced the same issue as the OP as far as the initial Time Machine backup to an AFP share being distressingly slow (FreeNAS-9.2.1.5-RELEASE-x64 (80c1d35)). After waiting a couple of days to back up around 100GB, my workaround was as follows:
  1. begin the backup on a Time Machine-enabled AFP share
  2. cancel the backup after it begins copying data
  3. tell Time machine to stop using the remote backup volume (it will inform you that no backups will be removed)
  4. delete the AFP share
  5. mount the sparsebundle through a CIFS share - this will connect your Mac to a volume named Time Machine Backups
  6. tell Time Machine to backup to the Time Machine Backups volume (you may have to work some tmutil-foo here)
  7. wait for the initial backup to complete
  8. tell Time Machine to stop using the Time Machine Backups volume
  9. unmount the sparsebundle
  10. delete the CIFS share
  11. create a new Time Machine-enabled AFP share
  12. tell Time Machine to start using the remote backup volume again
In my case, step 7 proceeded at a much faster rate than the AFP share, completing the next 200GB over WiFi in a matter of hours.

The point of reverting back to an AFP share for incremental backups is that Time Machine won't automatically mount and unmount a sparsebundle from a CIFS share, but it will do so for a Time Machine-enabled AFP share, even if the user isn't logged in. Performance is obviously less of an issue with incremental backups.
 
Joined
Mar 2, 2014
Messages
1
Another all-Mac user here (except for the FreeNAS box).

I'm using my FreeNAS system in a sort of hybrid mode, and I get decent performance from it over AFP. While I know that Apple loves CIFS/SMB, I refuse to use Microsoft protocols on general principle. What I do is:

a) use AFP shares for my very large files (videos from our TiVo mostly), and
b) iSCSI datasets for Time Machine backups using the ATTO iSCSI initiator (although the GlobalSAN one would work as well).

The Time Machine backups fly because, to OS X, the iSCSI volume looks like a local disk. No sparsebundle overhead.

Mind you, I do this because I have significant experience with iSCSI, as I work at Dell-EqualLogic (maker of iSCSI storage). But since there's no way I can afford an EqualLogic array for home use, FreeNAS is a terrific alternative.
 

Mario084

Dabbler
Joined
Oct 25, 2011
Messages
12
Hi guys,

I´m using freenas 9.2.1.5 and I´m also having problems with performance. I´m having 6 GB of RAM and when I start copying a file it´s really fast for about 10 seconds. But then the speed drops extremely to about 5 MB / sec. The 10 seconds before the speed is about 70 - 80 MB / sec.
Is somebody facing the same problem? I thought upgrading to 9.2.1.5 might help but I guess it didn´t...

When I copy some files from my windows pc to freenas (which is attached to the same network switch as the mac) I copy with about 85 MB / sec, constantly!

Thanks!
 

cyberjock

Inactive Account
Joined
Mar 25, 2012
Messages
19,526
The minimum RAM for 9.x is 8GB. Upgrade your system and see if that helps. The single easiest way to increase performance is more RAM, so if you could go to 16GB or something that would be a big help.
 

Savage

Dabbler
Joined
Jul 7, 2014
Messages
21
Starting to wonder if everyone has just started abandoning AFP or gave up here.

I know I am posting to an aging thread, but I was curious as to if any resolutions/work arounds etc might have cropped up for dealing with the slow 10.9 AFP issues. My experience was a drop from ~100MB/s pre 10.9 to ~40MB/s for transfer of large sized files via AFP. Spiky throughput when eyeballing network data throughput in Activity monitor, etc. Slower and far more variable performance on large batches of small files as well, etc.

Something I didn't see anyone else really mention : I did notice that multiple simultaneous transfers still can max out an interface. A half dozen or more simultaneous file transfers can push the reported throughput up to cap out a link (100-110+ MB/s for single gigabit and 150-200+ MB/s with a LAG on both ends.)
 

cyberjock

Inactive Account
Joined
Mar 25, 2012
Messages
19,526
To be honest, I wouldn't say it's "abandoned" as much as "not overly used or tested as much as CIFS on the forums". Most of the forum users are not using AFP (or even Apple devices for that matter) so coming here asking for help on AFP isn't exactly tapping a "wealth of knowledge and experience". Probably 75% of users (or more) are on CIFS so relatively speaking CIFS problems are definitely more often seen than AFP problems. As Apple themselves are steering away from AFP I consider it a dying protocol.

If this isn't an answer you like maybe you should consider these possible consequences when buying a computer that is used by something like 5% of the market. Buy stuff that is obscure and you set yourself up for being in a scenario where the answers are just as elusive.
 

Savage

Dabbler
Joined
Jul 7, 2014
Messages
21
Bah. Issue resolved after checking w/ a workstation running 10.9.3 instead of the one lingering system in our lab that is somehow still on 10.9.0. Bumped my test-lab FreeNAS to 9.2.1.6 as well.

For the AFP folks in the same oh-duh situation as me : The problem is not longer a problem, apparently. Large file transfer tests via AFP to a 9.2.1.6 FreeNAS pushing up to 113 MB/s via a single gigabit link. Googling this specific old issue doesn't net any concise answers anywhere really. The old forum posts that rank high on google searches seem to predate the fix by a large margin. So bah!

Cyberjock : I don't dislike your answer. Though I am fairly sure that the long list of clients I interact with that have large deployments of macs would roll their eyes. But I'm not here to split hairs. Peace out :)
 

cyberjock

Inactive Account
Joined
Mar 25, 2012
Messages
19,526
Cyberjock : I don't dislike your answer. Though I am fairly sure that the long list of clients I interact with that have large deployments of macs would roll their eyes. But I'm not here to split hairs. Peace out :)

I'm sure they would roll their eyes too, and they are welcome to either call Apple or iX for paid support as the offered free support (forums and IRC) isn't that deep with regards to Apple experience. Personally I think that Apple is making a smart choice by finally getting rid of AFP and switching to something that isn't proprietary.
 

Dennis.kulmosen

Explorer
Joined
Aug 13, 2013
Messages
96
To chime in on the AFP matter. I deploy lots of macs in video and A/V installations. Speed wise AFP is far superior than anything else on a mac. The very bad implementation that Apple has done with their SMBX (similar to smb2) has been a total disaster in my humble opinion. I welcome that getting a standard way of network protocol is the way to go, but in this case Apple has done everything wrong. So sticking to AFP, tweaking the clientside sysctl and using netatalk which outperform Apples own server side AFP on performance. My hopes is that if Apple continoue their hopeless SMBX implementation, the guys at netatalk make a client side AFP. Or that the guys at samba releases a proper gpl licensed smb for osx. :smile:
AFP is a very stable protocol just a shame that it doesnt do well with windows machines. ;-)
The reason that i havent done anything further in this thread is that i havent been able to reproduce the issue, of course i should have made a reply on that but i forgot during my busy work days. Now its holiday so its a different matter. ;-)
 

Savage

Dabbler
Joined
Jul 7, 2014
Messages
21
Dennis : I deal with mac workstations with probably similar usage cases/needs. (very large media workloads, large quantities of files and lots of capture/stream to/from file servers). Agree with you on AFP. It shines where SMB doesn't in those environments.
 

helloha

Contributor
Joined
Jul 6, 2014
Messages
109
To chime in on the AFP matter. I deploy lots of macs in video and A/V installations. Speed wise AFP is far superior than anything else on a mac. The very bad implementation that Apple has done with their SMBX (similar to smb2) has been a total disaster in my humble opinion. I welcome that getting a standard way of network protocol is the way to go, but in this case Apple has done everything wrong. So sticking to AFP, tweaking the clientside sysctl and using netatalk which outperform Apples own server side AFP on performance. My hopes is that if Apple continoue their hopeless SMBX implementation, the guys at netatalk make a client side AFP. Or that the guys at samba releases a proper gpl licensed smb for osx. :)
AFP is a very stable protocol just a shame that it doesnt do well with windows machines. ;-)
The reason that i havent done anything further in this thread is that i havent been able to reproduce the issue, of course i should have made a reply on that but i forgot during my busy work days. Now its holiday so its a different matter. ;-)

Hi Dennis, I realize this is an old thread. I was wondering what kind of tweaking you do in sysctl. I'm an AV professional and using freenas as an editing server. I just upgraded to 10GbE, it works really well on large files but I'm trying to optimize it for large sequences of small RAW files as well. So far I found this guide but was hoping to get some advice based on your experience. https://webcache.googleusercontent....10-6/+&cd=9&hl=en&ct=clnk&gl=be&client=safari

THX!
Karel.
 
Status
Not open for further replies.
Top