Bug #39932
Restore ports build optimization while retaining debug symbols
Motherboard: Super X10SDV-8C-TLN4F CPU: Intel Xeon D-1541 2.10 GHz Memory: 65403MB DDR4 Drives: FreeNAS installed on SuperMicro Sata dom, unsure of model. Volumes are hosted in a SuperMicro JBOD(SC847E26-RJBOD1) linked to FreeNAS box with SAS cable and are Seagate Constellation ES SAS(ST32000444SS), 12 of them,
Description
Original ticket:
Rsync is writing at half speed between local volumes after upgrade from 9.10.2-U5 to 11.0-U1. We run Rsync through a script sitting on FreeNAS.
The screen captures are still accurate in the previous ticket that we have submitted for this issue.
You have said on multiple occasions that this has been fixed in updates, but we are running the beta and still seeing the issue.
Let us know if you need any additional information or testing that needs to be done.
| DR-NAS2.PNG (36.6 KB) DR-NAS2.PNG | Test from NAS | ||
| rsync_9.10.2u5 (446 KB) rsync_9.10.2u5 | old binary | ||
| rsync_11.0u1 (639 KB) rsync_11.0u1 | standard binary | ||
| Copy of a 2.976 GiB ISO File (bandwidth).png (18.5 KB) Copy of a 2.976 GiB ISO File (bandwidth).png | |||
| python_benchmarks.png (87.5 KB) python_benchmarks.png | |||
| 11.1u5 vs. 11.2 Stable - 4KiB Random OPS.png (16.8 KB) 11.1u5 vs. 11.2 Stable - 4KiB Random OPS.png |
.png)
Subtasks
Related issues
Associated revisions
History
#1
Updated by Dru Lavigne almost 2 years ago
Updated by Dru Lavigne - Private changed from No to Yes
- Reason for Blocked set to Need additional information from Author
Noel: please attach a debug created on the BETA1 system to this ticket. Thanks!
#2
Updated by Dru Lavigne almost 2 years ago
- Related to Bug #25343: Rsync writing at half speed after upgrade from 9.10.2U5 to 11.0-U1 added
#3
Updated by Noel Miller almost 2 years ago
Updated by Noel Miller Dru Lavigne wrote:
Noel: please attach a debug created on the BETA1 system to this ticket. Thanks!
Dru,
It is the same behavior as seen in the original ticket, but we will plan on doing the test Monday and I will send you the results. Do you need any other debug information besides the write speeds on the jobs?
Thanks,
Noel
#4
Updated by Dru Lavigne almost 2 years ago
The dev will need the full debug to diagnose why this is still an issue.
#5
Updated by Noel Miller almost 2 years ago
Dru Lavigne wrote:
The dev will need the full debug to diagnose why this is still an issue.
Dru,
Before we run the tests on Monday, here is the script that is run (Destination and Source changed from each NAS we do it on)
- This script is used to rsync the backup working repository as created by Veeam and syncs it to the rotated disk repository called
- Source: /mnt/datavol/BackupRepository/Veeam
- Destination: /mnt/backup
START=$(date +%s)
rsync -avP --delete /mnt/datavol/BackupRepository/Veeam /mnt/backup
END=$(date +%s)
DIFF=$(($END - $START))
echo $(($DIFF/3600)) hr $(($DIFF%3600/60)) min $(($DIFF%60)) sec
#echo $(($DIFF/60)) min $(($DIFF%60)) sec
#echo "It took $DIFF seconds"
We are basically rsyncing to a set of backup disks which are then transported to a NAS in a remote location of the same model.
The only difference between the 2 NASes is the version of FreeNAS running on them.
One of them runs the rsync at the correct full speed and the other runs at nearly half the speed.
Is there anything you will need for debugging in this script that you will need to see?
Thanks,
Noel
#6
Updated by Dru Lavigne almost 2 years ago
The debug from the 1/2 speed one should suffice. It might turn out to be a hardware issue, a config issue, something else? Hard to tell without a debug.
#7
Updated by Noel Miller almost 2 years ago
Dru Lavigne wrote:
The debug from the 1/2 speed one should suffice. It might turn out to be a hardware issue, a config issue, something else? Hard to tell without a debug.
I apologize, but I am not super familiar with submitting bugs to you guys. Do you have a specific command you would like me to run to get you the information you need? Or do you want me to run a more verbose version of the script?
I just want to make sure I get you guys the information you need.
Thanks,
Noel
#8
Updated by Dru Lavigne almost 2 years ago
On the slow system, run System -> Advanced -> Save Debug. That will create a file you can attach to this ticket.
#9
Updated by Noel Miller almost 2 years ago
- File debug.tgz added
- File DR-NAS2.PNG DR-NAS2.PNG added
Dru Lavigne wrote:
On the slow system, run System -> Advanced -> Save Debug. That will create a file you can attach to this ticket.
Hello Dru,
I managed to get the information you asked for. I got a debug log during the time the issue was occurring.
Let me know if you need any other information!
Thanks,
Noel
#10
Updated by Dru Lavigne almost 2 years ago
- Assignee changed from Release Council to Alexander Motin
- Reason for Blocked deleted (
Need additional information from Author)
#11
Updated by Alexander Motin almost 2 years ago
Updated by Alexander Motin - Assignee changed from Alexander Motin to Ryan McKenzie
#13
Updated by Noel Miller almost 2 years ago
Noel Miller wrote:
Dru Lavigne wrote:
On the slow system, run System -> Advanced -> Save Debug. That will create a file you can attach to this ticket.
Hello Dru,
I managed to get the information you asked for. I got a debug log during the time the issue was occurring.
Let me know if you need any other information!
Thanks,
Noel
Hi Ryan,
Do you have any update for us regarding this issue? I am happy to provide more information if needed!
Thanks,
Noel
#14
Updated by Ryan McKenzie almost 2 years ago
Updated by Ryan McKenzie I got a FreeNAS system on 11.1u5 to try and reproduce this on. I have a few questions.
1) It looks like you are rsync-ing between two top level volumes (/mnt/datavol and /mnt/backup), residing on different disk pools, correct?
1a) What is the RAID type on the volume(s)?
1b) Do you have encryption enabled on all/any of the volume(s)?
2) What is the dataset size you are moving from the datavol backup repository to the backup volume?
3) What was the typical/expected speed of the rsync on the "old" fast system and what are you seeing now?
Thanks!
#15
Updated by Dru Lavigne almost 2 years ago
- Status changed from Unscreened to Blocked
- Reason for Blocked set to Need additional information from Author
#16
Updated by Noel Miller almost 2 years ago
Ryan McKenzie wrote:
I got a FreeNAS system on 11.1u5 to try and reproduce this on. I have a few questions.
1) It looks like you are rsync-ing between two top level volumes (/mnt/datavol and /mnt/backup), residing on different disk pools, correct?
1a) What is the RAID type on the volume(s)?
1b) Do you have encryption enabled on all/any of the volume(s)?
2) What is the dataset size you are moving from the datavol backup repository to the backup volume?
3) What was the typical/expected speed of the rsync on the "old" fast system and what are you seeing now?Thanks!
1. Yes
1a. Datavol has a set of mirrors. See zpool status below for both NAS4 and DR-NAS2
1b. Encryption is not enabled
2. 16TB Total Size, 13.5TB of data for backups
3. 180MB/s, getting about 90MB/s on slow system
NAS4 zpool status
pool: backup
state: ONLINE
scan: none requested
config:
NAME STATE READ WRITE CKSUM
backup ONLINE 0 0 0
raidz2-0 ONLINE 0 0 0
gptid/65c6839c-9741-11e8-af46-0090fa849e88 ONLINE 0 0 0
gptid/668d1eed-9741-11e8-af46-0090fa849e88 ONLINE 0 0 0
gptid/67564cbc-9741-11e8-af46-0090fa849e88 ONLINE 0 0 0
gptid/680b1279-9741-11e8-af46-0090fa849e88 ONLINE 0 0 0
gptid/68cf1e1c-9741-11e8-af46-0090fa849e88 ONLINE 0 0 0
gptid/6981b20f-9741-11e8-af46-0090fa849e88 ONLINE 0 0 0errors: No known data errors
pool: datavol
state: ONLINE
scan: resilvered 1.93T in 8h29m with 0 errors on Wed Aug 15 21:06:35 2018
config:NAME STATE READ WRITE CKSUM
datavol ONLINE 0 0 0
mirror-0 ONLINE 0 0 0
gptid/c2a323ee-8d1e-11e8-86e4-0090fa849e88 ONLINE 0 0 0
gptid/c2d1cdbc-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-1 ONLINE 0 0 0
gptid/c39bf4f5-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
gptid/c468b5a3-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-2 ONLINE 0 0 0
gptid/c5315a51-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
gptid/c5ff047d-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-3 ONLINE 0 0 0
gptid/ca4cf485-a0b1-11e8-af46-0090fa849e88 ONLINE 0 0 0
gptid/c78fb9bf-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-4 ONLINE 0 0 0
gptid/c85c0837-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
gptid/c92ccd0f-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-5 ONLINE 0 0 0
gptid/c9ff584d-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
gptid/cac46b56-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-6 ONLINE 0 0 0
gptid/cb8e33e7-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
gptid/cc596298-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-7 ONLINE 0 0 0
gptid/cd25942a-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
gptid/cdee306e-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-8 ONLINE 0 0 0
gptid/2f4c3f87-8d1e-11e8-86e4-0090fa849e88 ONLINE 0 0 0
gptid/cf90c74f-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-9 ONLINE 0 0 0
gptid/d05e1173-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
gptid/d134bc8f-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-10 ONLINE 0 0 0
gptid/d2053df5-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
gptid/d2d2e453-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-11 ONLINE 0 0 0
gptid/d3aa5bc6-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
gptid/d475fe61-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-12 ONLINE 0 0 0
gptid/d5469d27-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
gptid/d619f749-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-13 ONLINE 0 0 0
gptid/d6f53555-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
gptid/d7c0814e-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
mirror-14 ONLINE 0 0 0
gptid/d889e9e1-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
gptid/d95816fa-7767-11e5-a06e-0090fa849e88 ONLINE 0 0 0
logs
gptid/68aa4483-8d1a-11e8-86e4-0090fa849e88 ONLINE 0 0 0errors: No known data errors
DR-NAS2 zpool status
pool: backup
state: ONLINE
status: Some supported features are not enabled on the pool. The pool can
still be used, but some features are unavailable.
action: Enable all features using 'zpool upgrade'. Once this is done,
the pool may no longer be accessible by software that does not support
the features. See zpool-features(7) for details.
scan: none requested
config:
NAME STATE READ WRITE CKSUM
backup ONLINE 0 0 0
raidz2-0 ONLINE 0 0 0
gptid/1f95670e-9cd9-11e8-af46-0090fa849e88 ONLINE 0 0 0
gptid/205d5d15-9cd9-11e8-af46-0090fa849e88 ONLINE 0 0 0
gptid/210496f4-9cd9-11e8-af46-0090fa849e88 ONLINE 0 0 0
gptid/21c0f1b4-9cd9-11e8-af46-0090fa849e88 ONLINE 0 0 0
gptid/227fb52a-9cd9-11e8-af46-0090fa849e88 ONLINE 0 0 0
gptid/23301f8c-9cd9-11e8-af46-0090fa849e88 ONLINE 0 0 0errors: No known data errors
I apologize for delay in getting information.
Let me know if you have any insights!
Thanks,
Noel
#17
Updated by Dru Lavigne almost 2 years ago
- Status changed from Blocked to Unscreened
- Reason for Blocked deleted (
Need additional information from Author)
#18
Updated by Ryan McKenzie almost 2 years ago
I have done some basic investigations on this. I tested rsync performance to same zvol and to a different zvol on different mirrored pool. The test data is an actual backup of performance data files from our lab, size around 28GiB total with a good mix of large files like ISOs and lots of small files like CSVs. I used the customer script to perform the rsync and measure the time so our data would be comparable. WHen I did the upgrade I saved a copy of the OLD rsync binary and luckily it did run on the upgraded system.
Fresh install to 9.10.2u5 gives me:
| same pool | diff pool | |
| zfs send | 269.16 MiB/s | 317.55 MiB/s |
| rsync | 98.73 MiB/s | 99.34 MiB/s |
Upgrade to 11.0u1 gives me:
| same pool | diff pool | |
| rsync | 51.17 MiB/s | 58.12 MiB/s |
| rsync_OLDBIN | 105.64 MiB/s | 105.24 MiB/s |
So as you can see, I also reproduce the roughly 50% drop in rsync performance. Even though my system baseline is slower (FreeNAS mini 4 drives running on our office network), the performance drop is reproduced. However, the "old" rsync binary still performs well on the upgraded system.
I also ran a test on another system using zfs snap, zfs send and zfs recv to accomplish the same backup as a sanity check. The zfs-based backup method has similar (even slightly improving) performance from the old to the new FreeNAS version.
11.1u5 Fresh Install
| same pool | diff pool | |
| zfs send | 306.08 MiB/s | 352.00 MiB/s |
| rsync | 45.67 MiB/s | 51.01 MiB/s |
#19
Updated by Noel Miller almost 2 years ago
Ryan McKenzie wrote:
I have done some basic investigations on this. I tested rsync performance to same zvol and to a different zvol on different mirrored pool. The test data is an actual backup of performance data files from our lab, size around 28GiB total with a good mix of large files like ISOs and lots of small files like CSVs. I used the customer script to perform the rsync and measure the time so our data would be comparable. WHen I did the upgrade I saved a copy of the OLD rsync binary and luckily it did run on the upgraded system.
Fresh install to 9.10.2u5 gives me:
same pool diff pool zfs send 269.16 MiB/s 317.55 MiB/s rsync 98.73 MiB/s 99.34 MiB/s Upgrade to 11.0u1 gives me:
same pool diff pool rsync 51.17 MiB/s 58.12 MiB/s rsync_OLDBIN 105.64 MiB/s 105.24 MiB/s So as you can see, I also reproduce the roughly 50% drop in rsync performance. Even though my system baseline is slower (FreeNAS mini 4 drives running on our office network), the performance drop is reproduced. However, the "old" rsync binary still performs well on the upgraded system.
I also ran a test on another system using zfs snap, zfs send and zfs recv to accomplish the same backup as a sanity check. The zfs-based backup method has similar (even slightly improving) performance from the old to the new FreeNAS version.
11.1u5 Fresh Install
same pool diff pool zfs send 306.08 MiB/s 352.00 MiB/s rsync 45.67 MiB/s 51.01 MiB/s
Ryan,
I appreciate the feedback and extensive testing that was done on this!
What would be your suggestion moving forward regarding putting a solution in place?
Would you suggest trying to get a copy of the old binary and using it until you guys fix the bug on your side? If so, how would we go about doing that?
Any insight on this issue would be highly appreciated!
Thanks,
Noel
#20
Updated by Noel Miller almost 2 years ago
Noel Miller wrote:
Ryan McKenzie wrote:
I have done some basic investigations on this. I tested rsync performance to same zvol and to a different zvol on different mirrored pool. The test data is an actual backup of performance data files from our lab, size around 28GiB total with a good mix of large files like ISOs and lots of small files like CSVs. I used the customer script to perform the rsync and measure the time so our data would be comparable. WHen I did the upgrade I saved a copy of the OLD rsync binary and luckily it did run on the upgraded system.
Fresh install to 9.10.2u5 gives me:
same pool diff pool zfs send 269.16 MiB/s 317.55 MiB/s rsync 98.73 MiB/s 99.34 MiB/s Upgrade to 11.0u1 gives me:
same pool diff pool rsync 51.17 MiB/s 58.12 MiB/s rsync_OLDBIN 105.64 MiB/s 105.24 MiB/s So as you can see, I also reproduce the roughly 50% drop in rsync performance. Even though my system baseline is slower (FreeNAS mini 4 drives running on our office network), the performance drop is reproduced. However, the "old" rsync binary still performs well on the upgraded system.
I also ran a test on another system using zfs snap, zfs send and zfs recv to accomplish the same backup as a sanity check. The zfs-based backup method has similar (even slightly improving) performance from the old to the new FreeNAS version.
11.1u5 Fresh Install
same pool diff pool zfs send 306.08 MiB/s 352.00 MiB/s rsync 45.67 MiB/s 51.01 MiB/s Ryan,
I appreciate the feedback and extensive testing that was done on this!
What would be your suggestion moving forward regarding putting a solution in place?
Would you suggest trying to get a copy of the old binary and using it until you guys fix the bug on your side? If so, how would we go about doing that?
Any insight on this issue would be highly appreciated!
Thanks,
Noel
One other thing, would you suggest we use zfs send vs using rsync? I unfortunately am not super familiar with the ZFS command set in regards to moving files back and forth, so I would appreciate some help regarding that!
Thanks,
Noel
#21
Updated by Ryan McKenzie almost 2 years ago
- Status changed from Unscreened to Screened
Conclusions:
Because the old rsync binary still gets expected performance on the new FreeNAS code, and the fact that the zfs-based backup methodology performance stays steady, we can conclude that there was a change in rsync causing this performance reduction.
Next Steps:
I will run a dtrace on the old vs new rsync binaries to see if they are producing a different IO profile so investigation will continue.
In the mean time, a possible workaround seems to be copy an old rsync binary from another system or build one from older source. If your environment allows you to do so, the zfs-based solution for this backup would also be helpful for you in that they would accomplish the backup task AND give you some snapshots to act as restore points for your data.
Here is the modified script (based on your script) I was running to perform the backups, that might give you a good starting point on the zfs-based method. Note that when using the zfs method, the root folder you back up has to be created as a dataset under that zvol in the FreeNAS UI (it can't just be a directory you created under there on the client side).
START=$(date +%s)
#ZFS SEND same pool
#zfs snap -r datavol/perfdata@snap${START}
#zfs send -Rv datavol/perfdata@snap${START} | zfs recv -Fd datavol/BackupRepository
#ZFS SEND cross pool
#zfs snap -r datavol/BackupRepository@snap${START}
#zfs send -Rv datavol/BackupRepository@snap${START} | zfs recv -Fd backup
#RSYNC same pool
#rsync -avP /mnt/datavol/perfdata/ /mnt/datavol/BackupRepository/
#OLD RSYNC same pool
#/usr/local/bin/rsync_9.10.2u5 -avP /mnt/datavol/perfdata/ /mnt/datavol/BackupRepository/
#RSYNC cross pool
#rsync -avP /mnt/datavol/BackupRepository/ /mnt/backup/
#OLD RSYNC cross pool
#/usr/local/bin/rsync_9.10.2u5 -avP /mnt/datavol/BackupRepository/ /mnt/backup/
END=$(date +%s)
DIFF=$(($END - $START))
echo $(($DIFF/3600)) hr $(($DIFF%3600/60)) min $(($DIFF%60)) sec
#echo $(($DIFF/60)) min $(($DIFF%60)) sec
#echo "It took $DIFF seconds"
And here is a related forum article:
https://forums.freenas.org/index.php?threads/how-to-use-zfs-send-zfs-receive-to-back-up-my-current-pools-to-a-10tb-transfer-disk.59852/
#22
Updated by Ryan McKenzie almost 2 years ago
Checked the rsync --version on old vs new binary, they are the same version.
Looked at github for the history of the rsync port. FreeNAS 9.10.2u5 took it's last commit to the port on June 3, 2016. For FreeNAS 11.0 stable there was one more commit on March 16, 2017.
https://github.com/freenas/ports/commit/99d22d6510ab7a64ab16d4121ebe48d06677e47d#diff-ad55c0f9be48c5bff2957b314374e889
I'm going to read through it quickly before I start the dtrace testing to see if anything jumps out.
#23
Updated by Ryan McKenzie almost 2 years ago
That checkin is very benign, just moving ports from one location to another and doing some command line parsing stuff (popt).
Noel, can you please run "uname -a; pkg info rsync" on the 9.10 system you have so we can see if the package was built with different options?
root@freenas:~ # uname -a; pkg info rsync
FreeBSD freenas.local 11.0-STABLE FreeBSD 11.0-STABLE #0 r313908+b3722b04944(freenas/11.0-stable): Sat Jul 1 02:44:49 UTC 2017 root@gauntlet:/freenas-11-releng/freenas/_BE/objs/freenas-11-releng/freenas/_BE/os/sys/FreeNAS.amd64 amd64
rsync-3.1.2_2
Name : rsync
Version : 3.1.2_2
Installed on : Fri Jun 30 20:42:05 2017 PDT
Origin : net/rsync
Architecture : freebsd:11:x86:64
Prefix : /usr/local
Categories : net ipv6
Licenses : GPLv3
Maintainer : ehaupt@FreeBSD.org
WWW : http://rsync.samba.org/
Comment : Network file distribution/synchronization utility
Options :
ACL : on
ATIMES : off
DOCS : off
FLAGS : off
ICONV : on
POPT_PORT : off
RENAMED : off
SSH : on
TIMELIMIT : off
ZLIB_BASE : off
Annotations :
cpe : cpe:2.3:a:samba:rsync:3.1.2:::::freebsd11:x64:2
repo_type : binary
repository : local
Flat size : 1.29MiB
Description :
rsync is a replacement for rcp that has many more features.
rsync uses the "rsync algorithm" which provides a very fast method for
bringing remote files into sync. It does this by sending just the
differences in the files across the link, without requiring that both
sets of files are present at one of the ends of the link beforehand.
This makes rsync a good remote file distribution/synchronization utility
in a dialup PPP/SLIP environment.
Note, requires rsync on the destination machine.
There is a Computer Science Technical Report on the rsync algorithm is
included in the distribution, and is available as
ftp://samba.anu.edu.au/pub/rsync/tech_report.ps
WWW: http://rsync.samba.org/
#24
Updated by Ryan McKenzie almost 2 years ago
- Status changed from Screened to Blocked
- Assignee changed from Ryan McKenzie to Alexander Motin
- Reason for Blocked set to Need additional information from Author
- Needs QA changed from Yes to No
I did dtrace of the old vs new binaries. The IO histogram and average IO latency is not significantly different. The amount of time spent in the syscall "select" is significantly higher in the new binary vs the old binary so we may look into that.
The CPU utilization for both binaries is very similar also.
I'm going to bounce this ticket over to another team member who is going to take a final look at the issue before we declare it an rsync problem.
We would still like to see your output from "uname -a; pkg info rsync" on the 9.10 system you have.
#25
Updated by Ryan McKenzie almost 2 years ago
- File rsync_9.10.2u5 rsync_9.10.2u5 added
- File rsync_11.0u1 rsync_11.0u1 added
#26
Updated by Noel Miller almost 2 years ago
Ryan McKenzie wrote:
I did dtrace of the old vs new binaries. The IO histogram and average IO latency is not significantly different. The amount of time spent in the syscall "select" is significantly higher in the new binary vs the old binary so we may look into that.
The CPU utilization for both binaries is very similar also.
I'm going to bounce this ticket over to another team member who is going to take a final look at the issue before we declare it an rsync problem.
We would still like to see your output from "uname -a; pkg info rsync" on the 9.10 system you have.
Ryan,
Here is the output:
rsync-3.1.2_2
Name : rsync
Version : 3.1.2_2
Installed on : Mon Jul 24 19:34:30 2017 CDT
Origin : net/rsync
Architecture : freebsd:10:x86:64
Prefix : /usr/local
Categories : net ipv6
Licenses : GPLv3
Maintainer : ehaupt@FreeBSD.org
WWW : http://rsync.samba.org/
Comment : Network file distribution/synchronization utility
Options :
ACL : on
ATIMES : off
DOCS : off
FLAGS : off
ICONV : on
POPT_PORT : off
RENAMED : off
SSH : on
TIMELIMIT : off
ZLIB_BASE : off
Annotations :
cpe : cpe:2.3:a:samba:rsync:3.1.2:::::freebsd10:x64:2
repo_type : binary
repository : local
Flat size : 520KiB
Description :
rsync is a replacement for rcp that has many more features.
rsync uses the "rsync algorithm" which provides a very fast method for
bringing remote files into sync. It does this by sending just the
differences in the files across the link, without requiring that both
sets of files are present at one of the ends of the link beforehand.
This makes rsync a good remote file distribution/synchronization utility
in a dialup PPP/SLIP environment.
Note, requires rsync on the destination machine.
There is a Computer Science Technical Report on the rsync algorithm is
included in the distribution, and is available as
ftp://samba.anu.edu.au/pub/rsync/tech_report.ps
Thanks,
Noel
#27
Updated by Alexander Motin almost 2 years ago
- Status changed from Blocked to In Progress
- Reason for Blocked deleted (
Need additional information from Author)
I suspect I found the problem in excessive debugging enabled in FreeNAS during package build, possibly exactly in times of between FreeNAS 9.10 and 11. At least rsync from standard FreeBSD packages, and one I build myself are not affected, while built with that debug shows the reduced performance. I'll test it more.
#28
Updated by Alexander Motin almost 2 years ago
- Assignee changed from Alexander Motin to Ryan McKenzie
I've confirmed that disabled debugging helps rsync. Pushing to Ryan to benchmark other services built from ports: SMB, AFP, SSH (scp?), etc.
#29
Updated by Alexander Motin almost 2 years ago
- Target version changed from Backlog to 11.2-RC1
#30
Updated by Ryan McKenzie almost 2 years ago
- File Copy of a 2.976 GiB ISO File (bandwidth).png Copy of a 2.976 GiB ISO File (bandwidth).png added
We have found that rsync regains it's better bandwidth performance with the nodebug/optimized ports build. We also found that SCP gets a good performance benefit both with and without encryption during transfer. The results are inconclusive with SMB and AFP file sharing so I am running a more comprehensive set of benchmarks for those use cases.
#31
Updated by Noel Miller almost 2 years ago
Ryan McKenzie wrote:
We have found that rsync regains it's better bandwidth performance with the nodebug/optimized ports build. We also found that SCP gets a good performance benefit both with and without encryption during transfer. The results are inconclusive with SMB and AFP file sharing so I am running a more comprehensive set of benchmarks for those use cases.
Ryan,
Thank you for all the assistance on this and reaching out regarding updates. We have decided that copying the old binary over and using that is going to be the temporary solution until your solution is integrated into a new build. Even if this is implemented in a beta release, we'd like to know as soon as possible.
Feel free to continue to provide updates on this, I'm very curious as to what is the ultimate root cause is and what the solution ends up being!
Thanks,
Noel
#32
Updated by Ryan McKenzie almost 2 years ago
- Subject changed from Follow up to Bug #25343: Rsync writing at half speed after upgrade from 9.10.2U5 to 11.0-U1 to Ports built with debug on and optimizations disabled causing performance issues with various userspace applications
CHanged the name of this issue, it was:
Follow up to Bug #25343: Rsync writing at half speed after upgrade from 9.10.2U5 to 11.0-U1
The root cause of this issue is that the ports are now being built with debug symbols and the option used to do so also disabled compile time optimizations.
So far we have tested/identified the following:
-2x increase in rsync bandwidth by building the old way
-3x increase in scp bandwidth (compression on) by building the old way
-2x increase in scp bandwidth (compression off after authentication) by building the old way
APF copy and crosscopy of large file was tested, results inconclusive
AFP benchmarking with VDBENCH showed up to a 10% increase in 128k sequential write bandwidth (other read/write mixes and access patterns were inconclusive)
SMB copy and crosscopy of large file was tested, results inconclusive
Python benchmarking via pyperformance is underway. SMB benchmarking with VDBENCH will be done when more equipment becomes available again.
#33
Updated by Ryan McKenzie almost 2 years ago
- File python_benchmarks.png python_benchmarks.png added
Python benchmarks show a significant increase in performance from debug off and optimizations on. 2x-3x speedup on each benchmark. See attached graphs.
| test time (ms) | 11.1u5 | 11.2 nightly | 11.2 NODEBUG |
| 2to3 | 1740 | 1700 | 762 |
| json_dumps | 77.3 | 77.4 | 37 |
| json_loads | 0.156 | 0.155 | 0.0719 |
| pickle | 0.0589 | 0.0603 | 0.0281 |
| pickle_dict | 0.149 | 0.147 | 0.0712 |
| pickle_list | 0.0207 | 0.0205 | 0.00956 |
| pickle_pure_python | 3.59 | 3.13 | 1.33 |
| regex_compile | 1100 | 1100 | 492 |
| unpickle | 0.098 | 0.0976 | 0.0384 |
| unpickle_lisk | 0.0253 | 0.0252 | 0.0105 |
| unpickle_pure_python | 2.26 | 2.29 | 1.01 |
#34
Updated by Alexander Motin almost 2 years ago
- Assignee changed from Ryan McKenzie to Alexander Motin
I'll take this to finally disable debugging. Thank you, Ryan.
#35
Updated by Bug Clerk almost 2 years ago
Updated by Bug Clerk 
.png){kind=link}
- Status changed from In Progress to Ready for Testing
#36
Updated by Alexander Motin almost 2 years ago
- Status changed from Ready for Testing to In Progress
Not so fast, it was only a minor part. ;)
#37
Updated by Dru Lavigne almost 2 years ago
- File deleted (
debug.tgz)
#38
Updated by Dru Lavigne almost 2 years ago
- Private changed from Yes to No
#39
Updated by Alexander Motin almost 2 years ago
master PR: https://github.com/freenas/build/pull/108
11.2-stable PR: https://github.com/freenas/build/pull/110
master PR: https://github.com/freenas/py-libzfs/pull/17
11.2-stable PR: https://github.com/freenas/py-libzfs/pull/18
master PR: https://github.com/freenas/py-bsd/pull/2
11.2-stable PR: https://github.com/freenas/py-bsd/pull/3
master PR: https://github.com/freenas/ports/pull/139
master PR: https://github.com/freenas/ports/pull/137
#40
Updated by Alexander Motin almost 2 years ago
- Status changed from In Progress to Ready for Testing
PRs are merged. On my test builds I've finally observed that Samba binaries got smaller, hopefully due to debug disabled, so some new benchmarks would be interesting aside.
#41
Updated by Dru Lavigne almost 2 years ago
- Subject changed from Ports built with debug on and optimizations disabled causing performance issues with various userspace applications to Restore ports build optimization while retaining debug symbols
- Status changed from Ready for Testing to Done
- Needs Doc changed from Yes to No
- Needs Merging changed from Yes to No
#42
Updated by Dru Lavigne almost 2 years ago
- Status changed from Done to In Progress
#43
Updated by Alexander Motin almost 2 years ago
- Related to Bug #47459: Restore ports build optimization while retaining debug symbols added
#44
Updated by Alexander Motin almost 2 years ago
- Status changed from In Progress to Ready for Testing
#46
Updated by Dru Lavigne almost 2 years ago
- Status changed from Ready for Testing to Done
#47
Updated by Ryan McKenzie over 1 year ago
- File 11.1u5 vs. 11.2 Stable - 4KiB Random OPS.png 11.1u5 vs. 11.2 Stable - 4KiB Random OPS.png added
Finally had some time on windows and iMac clients to do this testing.
SMB
-the most significant change was a decrease in small block random reads by 10%, attached chart
-small block random writes saw smoother thread scaling and lower latency in 11.2, and the OPS difference was less than +/-5% and in margin or error
-streaming read performance was no different between the versions
-streaming write performance was better in 11.2 for each run, but less than +5% and in margin of error
AFP
-small block random performance was no different between the versions regardless off read/write mix
-streaming performance saw an across the board increase in bandwidth for all read/write mixes, but less than +5% and in margin of error