Re: Bug 252358 - cp(1) of large files is causing 100% CPU utilization and poor transfer of ~168M/minute

[Rick Macklem]

Well, it depends on what "stressdisk" (never heard of it) does.
If it:
1 - Reads a large non-sparse file on a UFS file system.
2 - Uses lseek(SEEK_DATA/SEEK_HOLE) with a small blocksize
 or copy_file_range(2) with a small length. (copy_file_range(2)
 does SEEK_DATA/SEEK_HOLE internally.)
then maybe. Otherwise, not.

rick


From: owner-freebsd-curr...@freebsd.org  on 
behalf of Graham Perrin 
Sent: Sunday, January 3, 2021 4:21 AM
To: freebsd-current@freebsd.org
Subject: Bug 252358 - cp(1) of large files is causing 100% CPU utilization and 
poor transfer of ~168M/minute

CAUTION: This email originated from outside of the University of Guelph. Do not 
click links or open attachments unless you recognize the sender and know the 
content is safe. If in doubt, forward suspicious emails to ith...@uoguelph.ca


On 02/01/2021 20:05, Matthias Apitz wrote:

> Here we go:https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=252358


Thank you.

I plan to build and install 82397d791966b09d344251bc709cd9db2b3a1902;




In the meantime: might 252358 be the cause of a peculiarity that I
encountered, a week or so ago, whilst using sysutils/stressdisk with a
particular (or particular type of) USB thumb drive?

 tl;dr whilst trying to
test the flash device on USB at da0, there was _unexpected thrashing_ of
the hard disk drive at ada0

___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Bug 252358 - cp(1) of large files is causing 100% CPU utilization and poor transfer of ~168M/minute

[Graham Perrin]

On 02/01/2021 20:05, Matthias Apitz wrote:


Here we go:https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=252358



Thank you.

I plan to build and install 82397d791966b09d344251bc709cd9db2b3a1902;




In the meantime: might 252358 be the cause of a peculiarity that I 
encountered, a week or so ago, whilst using sysutils/stressdisk with a 
particular (or particular type of) USB thumb drive?


 tl;dr whilst trying to 
test the flash device on USB at da0, there was _unexpected thrashing_ of 
the hard disk drive at ada0


___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: cp(1) of large files is causing 100% CPU utilization and poor transfer

[Alan Somers]

LGTM!  This patch also fixes another problem: the previous version of cp,
when copying a large sparse file on UFS, would create some UFS indirect
blocks (because it would keep truncating the file to larger sizes).  The
output file would still be sparse, but it would take up more space than the
original.  IIRC about 0.2% of the empty space would get used by UFS
indirect blocks.  But your patch fixes it.

What I said earlier about needing to modify vn_generic_copy_file_range
wasn't quite correct.  I confused len with xfer when I was reading the
code.  The change I proposed to vn_generic_copy_file_range would only make
a difference if the process receives many interrupts.

And here's some background for other people reading the thread: the reason
that the initial copy_file_range implementation in cp only used a 2 MB
block size is because vn_generic_copy_file_range wasn't always
interruptible, and we didn't want cp to block for minutes or even hours
during a long transfer.  Subsequently rmacklem made
vn_generic_copy_file_range interruptible, but we never raised the block
size in cp.

-Alan

On Sat, Jan 2, 2021 at 2:42 PM Rick Macklem  wrote:

> The attached small patch seems to fix the problem.
> My hunch is that, for a large non-sparse file, SEEK_DATA
> SEEK_HOLE takes a fairly long time.
> These are done for each copy_file_range(2) syscall.
>
> cp was doing lots of them because of the small len argument.
> Bumping the len up to SSIZE_MAX results in far fewer sycalls
> and, therefore, SEEK_DATAs and SEEK_HOLEs.
>
> Without the patch, cp took 6 times as long as dd.
> With the patch, cp takes less time than dd.
>
> I'll put the patch on the bug report. Matthias, can you test
> the patch?
>
> Thanks for reporting this, rick
> ps: All my test programs use SSIZE_MAX unless they were
>  not supposed to copy to eof, which explains why I
>  missed this. My bad, for the testing.;-)
>
> 
> From: owner-freebsd-curr...@freebsd.org 
> on behalf of Matthias Apitz 
> Sent: Saturday, January 2, 2021 3:05 PM
> To: Alan Somers
> Cc: Rick Macklem; FreeBSD CURRENT; Konstantin Belousov; Kirk McKusick
> Subject: Re: cp(1) of large files is causing 100% CPU utilization and poor
> transfer
>
> CAUTION: This email originated from outside of the University of Guelph.
> Do not click links or open attachments unless you recognize the sender and
> know the content is safe. If in doubt, forward suspicious emails to
> ith...@uoguelph.ca
>
>
> El día sábado, enero 02, 2021 a las 11:29:36a. m. -0700, Alan Somers
> escribió:
>
> > > El día sábado, enero 02, 2021 a las 05:06:05p. m. +, Rick Macklem
> > > escribió:
> > >
> > > > Just fyi, I've reproduced the problem.
> > > > All I did was create a 20Gbyte file
> > > > on UFS on a slow (4Gbyte or RAM,
> > > > slow spinning disk) laptop.
> > > > (The UFS file system is just what the installer creates these days.)
> > > >
> > > > cp still hasn't finished and is definitely
> > > > taking a looott longer than dd did.
> > > >
> > > > I'll start drilling down later to-day.
> > > >
> > > > I'll admit doing lots of testing of copy_file_range(2)
> > > > with large sparse files, but I may have missed testing
> > > > a large non-sparse file.
> > > >
> > > > rick
> > > > ps: I've added Kostik and Kirk to the cc.
> > >
> > > As the problem seems to be clear now, should I still file a PR?
> > > I'm happy to do so.
> > >
> >
> > Yes please .  That will help ensure that we don't lose track of it.
>
> Here we go: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=252358
>
> Thanks
>
> matthias
>
> --
> Matthias Apitz, ✉ g...@unixarea.de, http://www.unixarea.de/
> +49-176-38902045
> Public GnuPG key: http://www.unixarea.de/key.pub
> ¡Con Cuba no te metas!  «»  Don't mess with Cuba!  «»  Leg Dich nicht mit
> Kuba an!
> http://www.cubadebate.cu/noticias/2020/12/25/en-video-con-cuba-no-te-metas/
> ___
> freebsd-current@freebsd.org mailing list
> https://lists.freebsd.org/mailman/listinfo/freebsd-current
> To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"
>
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: cp(1) of large files is causing 100% CPU utilization and poor transfer

[Rick Macklem]

The attached small patch seems to fix the problem.
My hunch is that, for a large non-sparse file, SEEK_DATA
SEEK_HOLE takes a fairly long time.
These are done for each copy_file_range(2) syscall.

cp was doing lots of them because of the small len argument.
Bumping the len up to SSIZE_MAX results in far fewer sycalls
and, therefore, SEEK_DATAs and SEEK_HOLEs.

Without the patch, cp took 6 times as long as dd.
With the patch, cp takes less time than dd.

I'll put the patch on the bug report. Matthias, can you test
the patch?

Thanks for reporting this, rick
ps: All my test programs use SSIZE_MAX unless they were
 not supposed to copy to eof, which explains why I
 missed this. My bad, for the testing.;-)


From: owner-freebsd-curr...@freebsd.org  on 
behalf of Matthias Apitz 
Sent: Saturday, January 2, 2021 3:05 PM
To: Alan Somers
Cc: Rick Macklem; FreeBSD CURRENT; Konstantin Belousov; Kirk McKusick
Subject: Re: cp(1) of large files is causing 100% CPU utilization and poor 
transfer

CAUTION: This email originated from outside of the University of Guelph. Do not 
click links or open attachments unless you recognize the sender and know the 
content is safe. If in doubt, forward suspicious emails to ith...@uoguelph.ca


El día sábado, enero 02, 2021 a las 11:29:36a. m. -0700, Alan Somers escribió:

> > El día sábado, enero 02, 2021 a las 05:06:05p. m. +, Rick Macklem
> > escribió:
> >
> > > Just fyi, I've reproduced the problem.
> > > All I did was create a 20Gbyte file
> > > on UFS on a slow (4Gbyte or RAM,
> > > slow spinning disk) laptop.
> > > (The UFS file system is just what the installer creates these days.)
> > >
> > > cp still hasn't finished and is definitely
> > > taking a looott longer than dd did.
> > >
> > > I'll start drilling down later to-day.
> > >
> > > I'll admit doing lots of testing of copy_file_range(2)
> > > with large sparse files, but I may have missed testing
> > > a large non-sparse file.
> > >
> > > rick
> > > ps: I've added Kostik and Kirk to the cc.
> >
> > As the problem seems to be clear now, should I still file a PR?
> > I'm happy to do so.
> >
>
> Yes please .  That will help ensure that we don't lose track of it.

Here we go: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=252358

Thanks

matthias

--
Matthias Apitz, ✉ g...@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub
¡Con Cuba no te metas!  «»  Don't mess with Cuba!  «»  Leg Dich nicht mit Kuba 
an!
http://www.cubadebate.cu/noticias/2020/12/25/en-video-con-cuba-no-te-metas/
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"


cp.patch
Description: cp.patch
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: cp(1) of large files is causing 100% CPU utilization and poor transfer

[Matthias Apitz]

El día sábado, enero 02, 2021 a las 11:29:36a. m. -0700, Alan Somers escribió:

> > El día sábado, enero 02, 2021 a las 05:06:05p. m. +, Rick Macklem
> > escribió:
> >
> > > Just fyi, I've reproduced the problem.
> > > All I did was create a 20Gbyte file
> > > on UFS on a slow (4Gbyte or RAM,
> > > slow spinning disk) laptop.
> > > (The UFS file system is just what the installer creates these days.)
> > >
> > > cp still hasn't finished and is definitely
> > > taking a looott longer than dd did.
> > >
> > > I'll start drilling down later to-day.
> > >
> > > I'll admit doing lots of testing of copy_file_range(2)
> > > with large sparse files, but I may have missed testing
> > > a large non-sparse file.
> > >
> > > rick
> > > ps: I've added Kostik and Kirk to the cc.
> >
> > As the problem seems to be clear now, should I still file a PR?
> > I'm happy to do so.
> >
> 
> Yes please .  That will help ensure that we don't lose track of it.

Here we go: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=252358

Thanks

matthias

-- 
Matthias Apitz, ✉ g...@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub
¡Con Cuba no te metas!  «»  Don't mess with Cuba!  «»  Leg Dich nicht mit Kuba 
an!
http://www.cubadebate.cu/noticias/2020/12/25/en-video-con-cuba-no-te-metas/
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: cp(1) of large files is causing 100% CPU utilization and poor transfer

[Alan Somers]

On Sat, Jan 2, 2021 at 11:28 AM Matthias Apitz  wrote:

> El día sábado, enero 02, 2021 a las 05:06:05p. m. +, Rick Macklem
> escribió:
>
> > Just fyi, I've reproduced the problem.
> > All I did was create a 20Gbyte file
> > on UFS on a slow (4Gbyte or RAM,
> > slow spinning disk) laptop.
> > (The UFS file system is just what the installer creates these days.)
> >
> > cp still hasn't finished and is definitely
> > taking a looott longer than dd did.
> >
> > I'll start drilling down later to-day.
> >
> > I'll admit doing lots of testing of copy_file_range(2)
> > with large sparse files, but I may have missed testing
> > a large non-sparse file.
> >
> > rick
> > ps: I've added Kostik and Kirk to the cc.
>
> As the problem seems to be clear now, should I still file a PR?
> I'm happy to do so.
>
> matthias
>

Yes please .  That will help ensure that we don't lose track of it.
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: cp(1) of large files is causing 100% CPU utilization and poor transfer

[Matthias Apitz]

El día sábado, enero 02, 2021 a las 05:06:05p. m. +, Rick Macklem escribió:

> Just fyi, I've reproduced the problem.
> All I did was create a 20Gbyte file
> on UFS on a slow (4Gbyte or RAM,
> slow spinning disk) laptop.
> (The UFS file system is just what the installer creates these days.)
> 
> cp still hasn't finished and is definitely
> taking a looott longer than dd did.
> 
> I'll start drilling down later to-day.
> 
> I'll admit doing lots of testing of copy_file_range(2)
> with large sparse files, but I may have missed testing
> a large non-sparse file.
> 
> rick
> ps: I've added Kostik and Kirk to the cc.

As the problem seems to be clear now, should I still file a PR?
I'm happy to do so.

matthias



-- 
Matthias Apitz, ✉ g...@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub
¡Con Cuba no te metas!  «»  Don't mess with Cuba!  «»  Leg Dich nicht mit Kuba 
an!
http://www.cubadebate.cu/noticias/2020/12/25/en-video-con-cuba-no-te-metas/
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: cp(1) of large files is causing 100% CPU utilization and poor transfer

[Alan Somers]

It seems pretty clear to me, based on my experiments, that FIOSEEKHOLE is
O(n) in filesize on UFS (though not on ZFS).  And
vn_generic_copy_file_range calls VOP_IOCTL(..., FIOSEEKHOLE) once for every
block it copies, where blocks can range from 4KB to 1 MB.  So I think there
are three required actions:

1) Fix vn_generic_copy_file_range to remember the hole locations across
different iterations of its loop.
2) Increase the block size that cp uses with copy_file_range.  Right now
it's 2MB, but it should be much larger.
3) Optionally, improve UFS's FIOSEEKHOLE performance.  But it probably
won't be necessary if we fix 1 and 2.

-Alan

On Sat, Jan 2, 2021 at 10:06 AM Rick Macklem  wrote:

> Just fyi, I've reproduced the problem.
> All I did was create a 20Gbyte file
> on UFS on a slow (4Gbyte or RAM,
> slow spinning disk) laptop.
> (The UFS file system is just what the installer creates these days.)
>
> cp still hasn't finished and is definitely
> taking a looott longer than dd did.
>
> I'll start drilling down later to-day.
>
> I'll admit doing lots of testing of copy_file_range(2)
> with large sparse files, but I may have missed testing
> a large non-sparse file.
>
> rick
> ps: I've added Kostik and Kirk to the cc.
>
>
> 
> From: owner-freebsd-curr...@freebsd.org 
> on behalf of Alan Somers 
> Sent: Saturday, January 2, 2021 11:30 AM
> To: Matthias Apitz; FreeBSD CURRENT
> Subject: Re: cp(1) of large files is causing 100% CPU utilization and poor
> transfer
>
> CAUTION: This email originated from outside of the University of Guelph.
> Do not click links or open attachments unless you recognize the sender and
> know the content is safe. If in doubt, forward suspicious emails to
> ith...@uoguelph.ca
>
>
> On Sat, Jan 2, 2021 at 9:12 AM Matthias Apitz  wrote:
>
> > El día sábado, enero 02, 2021 a las 09:06:24a. m. -0700, Alan Somers
> > escribió:
> >
> > > > As I said, it can be reproduced using only the local file system.
> This
> > > > was setup recently on a SSD:
> > > >
> > > > # dmesg | grep ada0
> > > > ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
> > > > ada0:  ACS-2 ATA SATA 3.x device
> > > > ada0: Serial Number F995890846
> > > > ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 1024bytes)
> > > > ada0: Command Queueing enabled
> > > > ada0: 488386MB (1000215216 512 byte sectors)
> > > >
> > > > and by this procedure:
> > > >
> > > > # gpart create -s gpt ada0
> > > > # gpart add -t freebsd-boot -s 512k -a4k -l ssdboot ada0
> > > > # gpart bootcode -b /boot/pmbr -p /boot/gptboot -i1 ada0
> > > > # gpart add -t freebsd-ufs -l ssdrootfs -b 1m -s 2g ada0
> > > > # gpart add -t freebsd-ufs -l ssdvarfs -a 1m -s 2g ada0
> > > > # gpart add -t freebsd-ufs -l ssdusrfs -a 1m ada0
> > > > # newfs -U -t /dev/gpt/ssdrootfs
> > > > # newfs -U -t /dev/gpt/ssdvarfs
> > > > # newfs -U -t /dev/gpt/ssdusrfs
> > > >
> > > > # gpart show -l ada0
> > > > =>40  1000215136  ada0  GPT  (477G)
> > > >   401024 1  ssdboot  (512K)
> > > > 1064 984- free -  (492K)
> > > > 2048 4194304 2  ssdrootfs  (2.0G)
> > > >  4196352 4194304 3  ssdvarfs  (2.0G)
> > > >  839065616777216 4  ssdswap  (8.0G)
> > > > 25167872   975046656 5  ssdusrfs  (465G)
> > > >   1000214528 648- free -  (324K)
> > > >
> > > > # mount -t ufs
> > > > /dev/gpt/ssdrootfs on / (ufs, local, soft-updates)
> > > > /dev/gpt/ssdvarfs on /var (ufs, local, soft-updates)
> > > > /dev/gpt/ssdusrfs on /usr (ufs, local, soft-updates)
> > > >
> > > > When I run in the /usr fs the command
> > > >
> > > > # cp -p guru-20210102.tar.gz xxx
> > > >
> > > > it copies around 168M per minute.
> > > >
> >
> > > Is that copying from /usr to /usr, or from /usr to /var or /?
> >
> > # cd /home/backups
> > # cp -p guru-20210102.tar.gz xxx
> >
> > i.e. from /usr to /usr.
> >
> > matthias
> >
>
> Ok, let's narrow this down.  Could you please run the command with the
> attached D script ?
> sudo dtrace -s copy_file_range.d -c "cp -p guru-20210102.tar.gz xxx"
> ___
> freebsd-current@freebsd.org mailing list
> https://lists.freebsd.org/mailman/listinfo/freebsd-current
> To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"
>
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: cp(1) of large files is causing 100% CPU utilization and poor transfer

[Rick Macklem]

Just fyi, I've reproduced the problem.
All I did was create a 20Gbyte file
on UFS on a slow (4Gbyte or RAM,
slow spinning disk) laptop.
(The UFS file system is just what the installer creates these days.)

cp still hasn't finished and is definitely
taking a looott longer than dd did.

I'll start drilling down later to-day.

I'll admit doing lots of testing of copy_file_range(2)
with large sparse files, but I may have missed testing
a large non-sparse file.

rick
ps: I've added Kostik and Kirk to the cc.



From: owner-freebsd-curr...@freebsd.org  on 
behalf of Alan Somers 
Sent: Saturday, January 2, 2021 11:30 AM
To: Matthias Apitz; FreeBSD CURRENT
Subject: Re: cp(1) of large files is causing 100% CPU utilization and poor 
transfer

CAUTION: This email originated from outside of the University of Guelph. Do not 
click links or open attachments unless you recognize the sender and know the 
content is safe. If in doubt, forward suspicious emails to ith...@uoguelph.ca


On Sat, Jan 2, 2021 at 9:12 AM Matthias Apitz  wrote:

> El día sábado, enero 02, 2021 a las 09:06:24a. m. -0700, Alan Somers
> escribió:
>
> > > As I said, it can be reproduced using only the local file system. This
> > > was setup recently on a SSD:
> > >
> > > # dmesg | grep ada0
> > > ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
> > > ada0:  ACS-2 ATA SATA 3.x device
> > > ada0: Serial Number F995890846
> > > ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 1024bytes)
> > > ada0: Command Queueing enabled
> > > ada0: 488386MB (1000215216 512 byte sectors)
> > >
> > > and by this procedure:
> > >
> > > # gpart create -s gpt ada0
> > > # gpart add -t freebsd-boot -s 512k -a4k -l ssdboot ada0
> > > # gpart bootcode -b /boot/pmbr -p /boot/gptboot -i1 ada0
> > > # gpart add -t freebsd-ufs -l ssdrootfs -b 1m -s 2g ada0
> > > # gpart add -t freebsd-ufs -l ssdvarfs -a 1m -s 2g ada0
> > > # gpart add -t freebsd-ufs -l ssdusrfs -a 1m ada0
> > > # newfs -U -t /dev/gpt/ssdrootfs
> > > # newfs -U -t /dev/gpt/ssdvarfs
> > > # newfs -U -t /dev/gpt/ssdusrfs
> > >
> > > # gpart show -l ada0
> > > =>40  1000215136  ada0  GPT  (477G)
> > >   401024 1  ssdboot  (512K)
> > > 1064 984- free -  (492K)
> > > 2048 4194304 2  ssdrootfs  (2.0G)
> > >  4196352 4194304 3  ssdvarfs  (2.0G)
> > >  839065616777216 4  ssdswap  (8.0G)
> > > 25167872   975046656 5  ssdusrfs  (465G)
> > >   1000214528 648- free -  (324K)
> > >
> > > # mount -t ufs
> > > /dev/gpt/ssdrootfs on / (ufs, local, soft-updates)
> > > /dev/gpt/ssdvarfs on /var (ufs, local, soft-updates)
> > > /dev/gpt/ssdusrfs on /usr (ufs, local, soft-updates)
> > >
> > > When I run in the /usr fs the command
> > >
> > > # cp -p guru-20210102.tar.gz xxx
> > >
> > > it copies around 168M per minute.
> > >
>
> > Is that copying from /usr to /usr, or from /usr to /var or /?
>
> # cd /home/backups
> # cp -p guru-20210102.tar.gz xxx
>
> i.e. from /usr to /usr.
>
> matthias
>

Ok, let's narrow this down.  Could you please run the command with the
attached D script ?
sudo dtrace -s copy_file_range.d -c "cp -p guru-20210102.tar.gz xxx"
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: cp(1) of large files is causing 100% CPU utilization and poor transfer

[Alan Somers]

On Sat, Jan 2, 2021 at 9:12 AM Matthias Apitz  wrote:

> El día sábado, enero 02, 2021 a las 09:06:24a. m. -0700, Alan Somers
> escribió:
>
> > > As I said, it can be reproduced using only the local file system. This
> > > was setup recently on a SSD:
> > >
> > > # dmesg | grep ada0
> > > ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
> > > ada0:  ACS-2 ATA SATA 3.x device
> > > ada0: Serial Number F995890846
> > > ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 1024bytes)
> > > ada0: Command Queueing enabled
> > > ada0: 488386MB (1000215216 512 byte sectors)
> > >
> > > and by this procedure:
> > >
> > > # gpart create -s gpt ada0
> > > # gpart add -t freebsd-boot -s 512k -a4k -l ssdboot ada0
> > > # gpart bootcode -b /boot/pmbr -p /boot/gptboot -i1 ada0
> > > # gpart add -t freebsd-ufs -l ssdrootfs -b 1m -s 2g ada0
> > > # gpart add -t freebsd-ufs -l ssdvarfs -a 1m -s 2g ada0
> > > # gpart add -t freebsd-ufs -l ssdusrfs -a 1m ada0
> > > # newfs -U -t /dev/gpt/ssdrootfs
> > > # newfs -U -t /dev/gpt/ssdvarfs
> > > # newfs -U -t /dev/gpt/ssdusrfs
> > >
> > > # gpart show -l ada0
> > > =>40  1000215136  ada0  GPT  (477G)
> > >   401024 1  ssdboot  (512K)
> > > 1064 984- free -  (492K)
> > > 2048 4194304 2  ssdrootfs  (2.0G)
> > >  4196352 4194304 3  ssdvarfs  (2.0G)
> > >  839065616777216 4  ssdswap  (8.0G)
> > > 25167872   975046656 5  ssdusrfs  (465G)
> > >   1000214528 648- free -  (324K)
> > >
> > > # mount -t ufs
> > > /dev/gpt/ssdrootfs on / (ufs, local, soft-updates)
> > > /dev/gpt/ssdvarfs on /var (ufs, local, soft-updates)
> > > /dev/gpt/ssdusrfs on /usr (ufs, local, soft-updates)
> > >
> > > When I run in the /usr fs the command
> > >
> > > # cp -p guru-20210102.tar.gz xxx
> > >
> > > it copies around 168M per minute.
> > >
>
> > Is that copying from /usr to /usr, or from /usr to /var or /?
>
> # cd /home/backups
> # cp -p guru-20210102.tar.gz xxx
>
> i.e. from /usr to /usr.
>
> matthias
>

Ok, let's narrow this down.  Could you please run the command with the
attached D script ?
sudo dtrace -s copy_file_range.d -c "cp -p guru-20210102.tar.gz xxx"
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: cp(1) of large files is causing 100% CPU utilization and poor transfer

[Matthias Apitz]

El día sábado, enero 02, 2021 a las 09:06:24a. m. -0700, Alan Somers escribió:

> > As I said, it can be reproduced using only the local file system. This
> > was setup recently on a SSD:
> >
> > # dmesg | grep ada0
> > ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
> > ada0:  ACS-2 ATA SATA 3.x device
> > ada0: Serial Number F995890846
> > ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 1024bytes)
> > ada0: Command Queueing enabled
> > ada0: 488386MB (1000215216 512 byte sectors)
> >
> > and by this procedure:
> >
> > # gpart create -s gpt ada0
> > # gpart add -t freebsd-boot -s 512k -a4k -l ssdboot ada0
> > # gpart bootcode -b /boot/pmbr -p /boot/gptboot -i1 ada0
> > # gpart add -t freebsd-ufs -l ssdrootfs -b 1m -s 2g ada0
> > # gpart add -t freebsd-ufs -l ssdvarfs -a 1m -s 2g ada0
> > # gpart add -t freebsd-ufs -l ssdusrfs -a 1m ada0
> > # newfs -U -t /dev/gpt/ssdrootfs
> > # newfs -U -t /dev/gpt/ssdvarfs
> > # newfs -U -t /dev/gpt/ssdusrfs
> >
> > # gpart show -l ada0
> > =>40  1000215136  ada0  GPT  (477G)
> >   401024 1  ssdboot  (512K)
> > 1064 984- free -  (492K)
> > 2048 4194304 2  ssdrootfs  (2.0G)
> >  4196352 4194304 3  ssdvarfs  (2.0G)
> >  839065616777216 4  ssdswap  (8.0G)
> > 25167872   975046656 5  ssdusrfs  (465G)
> >   1000214528 648- free -  (324K)
> >
> > # mount -t ufs
> > /dev/gpt/ssdrootfs on / (ufs, local, soft-updates)
> > /dev/gpt/ssdvarfs on /var (ufs, local, soft-updates)
> > /dev/gpt/ssdusrfs on /usr (ufs, local, soft-updates)
> >
> > When I run in the /usr fs the command
> >
> > # cp -p guru-20210102.tar.gz xxx
> >
> > it copies around 168M per minute.
> >

> Is that copying from /usr to /usr, or from /usr to /var or /?

# cd /home/backups
# cp -p guru-20210102.tar.gz xxx

i.e. from /usr to /usr.

matthias

-- 
Matthias Apitz, ✉ g...@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub
¡Con Cuba no te metas!  «»  Don't mess with Cuba!  «»  Leg Dich nicht mit Kuba 
an!
http://www.cubadebate.cu/noticias/2020/12/25/en-video-con-cuba-no-te-metas/
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: cp(1) of large files is causing 100% CPU utilization and poor transfer

[Alan Somers]

On Sat, Jan 2, 2021 at 9:02 AM Matthias Apitz  wrote:

> El día sábado, enero 02, 2021 a las 08:42:01a. m. -0700, Alan Somers
> escribió:
>
> > > # dd if=guru-20210102.tar.gz
> of=/mnt/AcerC720/backups/guru-20210102.tar.gz
> > > bs=8m
> > > 4601+1 records in
> > > 4601+1 records out
> > > 38603862368 bytes transferred in 506.778929 secs (76174956 bytes/sec)
> > > # ls -lh guru-20210102.tar.gz
> > > -r  1 root  wheel36G  2 ene.  12:19 guru-20210102.tar.gz
> > >
> > > When I use cp(1) what I normaly do the transfer is very poor and causes
> > > 100% CPU itilization:
> > >
> > > # cp -p guru-20210102.tar.gz /mnt/AcerC720/backups/xxx
> > > ^C
> > >
> > > killed after 1 minute; transfered in 1 minute:
> > >
> > > # ls -lh /mnt/AcerC720/backups/xxx
> > > -r  1 root  wheel   168M  2 ene.  15:34
> /mnt/AcerC720/backups/xxx
> > >
> > > 168*1024*1024/60 = 2936012 bytes/sec   ./. 76174956 bytes/sec
> > >
> > > Trussing the cp(1) process shows these sys calls:
> > >
> > > # truss -p 37655
> > > copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> > > copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> > > copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> > > copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> > > copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> > >
> > > The problem is unrelated to the external disk, also a copy
> > > in the local file system shows the same transfer speed of 168M per
> > > minute.
>
> > Not an issue I've heard of before.  Could you please describe how your
> USB
> > and local disk are formatted?  Also, where is the source file stored?  It
> > could be that the source file's file system has a very slow
> implementation
> > of FIOSEEKDATA/FIOSEEKHOLE.
> > -Alan
>
>
> As I said, it can be reproduced using only the local file system. This
> was setup recently on a SSD:
>
> # dmesg | grep ada0
> ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
> ada0:  ACS-2 ATA SATA 3.x device
> ada0: Serial Number F995890846
> ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 1024bytes)
> ada0: Command Queueing enabled
> ada0: 488386MB (1000215216 512 byte sectors)
>
> and by this procedure:
>
> # gpart create -s gpt ada0
> # gpart add -t freebsd-boot -s 512k -a4k -l ssdboot ada0
> # gpart bootcode -b /boot/pmbr -p /boot/gptboot -i1 ada0
> # gpart add -t freebsd-ufs -l ssdrootfs -b 1m -s 2g ada0
> # gpart add -t freebsd-ufs -l ssdvarfs -a 1m -s 2g ada0
> # gpart add -t freebsd-ufs -l ssdusrfs -a 1m ada0
> # newfs -U -t /dev/gpt/ssdrootfs
> # newfs -U -t /dev/gpt/ssdvarfs
> # newfs -U -t /dev/gpt/ssdusrfs
>
> # gpart show -l ada0
> =>40  1000215136  ada0  GPT  (477G)
>   401024 1  ssdboot  (512K)
> 1064 984- free -  (492K)
> 2048 4194304 2  ssdrootfs  (2.0G)
>  4196352 4194304 3  ssdvarfs  (2.0G)
>  839065616777216 4  ssdswap  (8.0G)
> 25167872   975046656 5  ssdusrfs  (465G)
>   1000214528 648- free -  (324K)
>
> # mount -t ufs
> /dev/gpt/ssdrootfs on / (ufs, local, soft-updates)
> /dev/gpt/ssdvarfs on /var (ufs, local, soft-updates)
> /dev/gpt/ssdusrfs on /usr (ufs, local, soft-updates)
>
> When I run in the /usr fs the command
>
> # cp -p guru-20210102.tar.gz xxx
>
> it copies around 168M per minute.
>
> matthias
>

Is that copying from /usr to /usr, or from /usr to /var or /?
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: cp(1) of large files is causing 100% CPU utilization and poor transfer

[Matthias Apitz]

El día sábado, enero 02, 2021 a las 08:42:01a. m. -0700, Alan Somers escribió:

> > # dd if=guru-20210102.tar.gz of=/mnt/AcerC720/backups/guru-20210102.tar.gz
> > bs=8m
> > 4601+1 records in
> > 4601+1 records out
> > 38603862368 bytes transferred in 506.778929 secs (76174956 bytes/sec)
> > # ls -lh guru-20210102.tar.gz
> > -r  1 root  wheel36G  2 ene.  12:19 guru-20210102.tar.gz
> >
> > When I use cp(1) what I normaly do the transfer is very poor and causes
> > 100% CPU itilization:
> >
> > # cp -p guru-20210102.tar.gz /mnt/AcerC720/backups/xxx
> > ^C
> >
> > killed after 1 minute; transfered in 1 minute:
> >
> > # ls -lh /mnt/AcerC720/backups/xxx
> > -r  1 root  wheel   168M  2 ene.  15:34 /mnt/AcerC720/backups/xxx
> >
> > 168*1024*1024/60 = 2936012 bytes/sec   ./. 76174956 bytes/sec
> >
> > Trussing the cp(1) process shows these sys calls:
> >
> > # truss -p 37655
> > copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> > copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> > copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> > copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> > copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> >
> > The problem is unrelated to the external disk, also a copy
> > in the local file system shows the same transfer speed of 168M per
> > minute.

> Not an issue I've heard of before.  Could you please describe how your USB
> and local disk are formatted?  Also, where is the source file stored?  It
> could be that the source file's file system has a very slow implementation
> of FIOSEEKDATA/FIOSEEKHOLE.
> -Alan


As I said, it can be reproduced using only the local file system. This
was setup recently on a SSD:

# dmesg | grep ada0
ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
ada0:  ACS-2 ATA SATA 3.x device
ada0: Serial Number F995890846
ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 1024bytes)
ada0: Command Queueing enabled
ada0: 488386MB (1000215216 512 byte sectors)

and by this procedure:

# gpart create -s gpt ada0
# gpart add -t freebsd-boot -s 512k -a4k -l ssdboot ada0
# gpart bootcode -b /boot/pmbr -p /boot/gptboot -i1 ada0
# gpart add -t freebsd-ufs -l ssdrootfs -b 1m -s 2g ada0
# gpart add -t freebsd-ufs -l ssdvarfs -a 1m -s 2g ada0
# gpart add -t freebsd-ufs -l ssdusrfs -a 1m ada0
# newfs -U -t /dev/gpt/ssdrootfs
# newfs -U -t /dev/gpt/ssdvarfs
# newfs -U -t /dev/gpt/ssdusrfs

# gpart show -l ada0
=>40  1000215136  ada0  GPT  (477G)
  401024 1  ssdboot  (512K)
1064 984- free -  (492K)
2048 4194304 2  ssdrootfs  (2.0G)
 4196352 4194304 3  ssdvarfs  (2.0G)
 839065616777216 4  ssdswap  (8.0G)
25167872   975046656 5  ssdusrfs  (465G)
  1000214528 648- free -  (324K)

# mount -t ufs
/dev/gpt/ssdrootfs on / (ufs, local, soft-updates)
/dev/gpt/ssdvarfs on /var (ufs, local, soft-updates)
/dev/gpt/ssdusrfs on /usr (ufs, local, soft-updates)

When I run in the /usr fs the command

# cp -p guru-20210102.tar.gz xxx

it copies around 168M per minute.

matthias


-- 
Matthias Apitz, ✉ g...@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub
¡Con Cuba no te metas!  «»  Don't mess with Cuba!  «»  Leg Dich nicht mit Kuba 
an!
http://www.cubadebate.cu/noticias/2020/12/25/en-video-con-cuba-no-te-metas/
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: cp(1) of large files is causing 100% CPU utilization and poor transfer

[Alan Somers]

On Sat, Jan 2, 2021 at 7:59 AM Matthias Apitz  wrote:

>
> This is with:
>
> # uname -a
> FreeBSD c720-r368166 13.0-CURRENT FreeBSD 13.0-CURRENT #23 r368166M: Thu
> Dec 17 13:12:37 CET 2020 
> guru@c720-r368166:/usr/obj/usr/src/amd64.amd64/sys/GENERIC
> amd64
>
> I copy often large backup files to an external USB disk and hit the
> following problem since updating to r368166:
>
> A transfer with dd(1) works fast and as expected (~70M / sec):
>
> # dd if=guru-20210102.tar.gz of=/mnt/AcerC720/backups/guru-20210102.tar.gz
> bs=8m
> 4601+1 records in
> 4601+1 records out
> 38603862368 bytes transferred in 506.778929 secs (76174956 bytes/sec)
> # ls -lh guru-20210102.tar.gz
> -r  1 root  wheel36G  2 ene.  12:19 guru-20210102.tar.gz
>
> When I use cp(1) what I normaly do the transfer is very poor and causes
> 100% CPU itilization:
>
> # cp -p guru-20210102.tar.gz /mnt/AcerC720/backups/xxx
> ^C
>
> killed after 1 minute; transfered in 1 minute:
>
> # ls -lh /mnt/AcerC720/backups/xxx
> -r  1 root  wheel   168M  2 ene.  15:34 /mnt/AcerC720/backups/xxx
>
> 168*1024*1024/60 = 2936012 bytes/sec   ./. 76174956 bytes/sec
>
> Trussing the cp(1) process shows these sys calls:
>
> # truss -p 37655
> copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
> copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
>
> The problem is unrelated to the external disk, also a copy
> in the local file system shows the same transfer speed of 168M per
> minute.
>
> Is this a known issue or a regressionc ?
>
> I see in the man page of copy_file_range(2) that this is new with
> FreeBSD 13...
>
> matthias
>

Not an issue I've heard of before.  Could you please describe how your USB
and local disk are formatted?  Also, where is the source file stored?  It
could be that the source file's file system has a very slow implementation
of FIOSEEKDATA/FIOSEEKHOLE.
-Alan
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

cp(1) of large files is causing 100% CPU utilization and poor transfer

[Matthias Apitz]

This is with:

# uname -a
FreeBSD c720-r368166 13.0-CURRENT FreeBSD 13.0-CURRENT #23 r368166M: Thu Dec 17 
13:12:37 CET 2020 
guru@c720-r368166:/usr/obj/usr/src/amd64.amd64/sys/GENERIC  amd64

I copy often large backup files to an external USB disk and hit the
following problem since updating to r368166:

A transfer with dd(1) works fast and as expected (~70M / sec):

# dd if=guru-20210102.tar.gz of=/mnt/AcerC720/backups/guru-20210102.tar.gz bs=8m
4601+1 records in
4601+1 records out
38603862368 bytes transferred in 506.778929 secs (76174956 bytes/sec)
# ls -lh guru-20210102.tar.gz
-r  1 root  wheel36G  2 ene.  12:19 guru-20210102.tar.gz

When I use cp(1) what I normaly do the transfer is very poor and causes
100% CPU itilization:

# cp -p guru-20210102.tar.gz /mnt/AcerC720/backups/xxx
^C

killed after 1 minute; transfered in 1 minute:

# ls -lh /mnt/AcerC720/backups/xxx
-r  1 root  wheel   168M  2 ene.  15:34 /mnt/AcerC720/backups/xxx

168*1024*1024/60 = 2936012 bytes/sec   ./. 76174956 bytes/sec

Trussing the cp(1) process shows these sys calls:

# truss -p 37655
copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)
copy_file_range(0x3,0x0,0x4,0x0,0x20,0x0)= 2097152 (0x20)

The problem is unrelated to the external disk, also a copy
in the local file system shows the same transfer speed of 168M per
minute.

Is this a known issue or a regressionc ?

I see in the man page of copy_file_range(2) that this is new with
FreeBSD 13...

matthias
-- 
Matthias Apitz, ✉ g...@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub
¡Con Cuba no te metas!  «»  Don't mess with Cuba!  «»  Leg Dich nicht mit Kuba 
an!
http://www.cubadebate.cu/noticias/2020/12/25/en-video-con-cuba-no-te-metas/
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"