Re: Fwd: Re: Fedora27: NFS v4 terrible write performance, is async working

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 




Being a daredevil, I have used the NFS async option for 27 years without an issue on multiple systems :)

I have just mounted my ext4 disk with the same options you were using and the same NFS export options and the speed here looks the same as I had previously. As I can't wait 2+ hours so I'm just looking at ksysguard and it is showing a network rate of about 10 KBytes/s and the directory on the server is growing in size very very slowly.

This is using the current Fedora27 kernel 4.14.14-300.fc27.x86_64.

I will have a look at using wireshark to see if this shows anything.

This is a snippet from a wireshark trace of the NFS when untaring the linux kernel 4.14.15 sources into an NFSv4.2 mounted directory with "sync" option on my NFS server. The whole untar would take > 2 hours vs 13 seconds direct to the disk. This is about 850 MBytes of 60k files. The following is a single, small file write.

No.     Time           Source Destination           Protocol Length Info
   1880 11.928600315   192.168.202.2         192.168.202.1 NFS      380    V4 Call (Reply In 1881) OPEN DH: 0xac0502f2/sysfs-c2port    1881 11.950329198   192.168.202.1         192.168.202.2 NFS      408    V4 Reply (Call In 1880) OPEN StateID: 0xaa72    1882 11.950446430   192.168.202.2         192.168.202.1 NFS      304    V4 Call (Reply In 1883) SETATTR FH: 0x825014ee    1883 11.972608880   192.168.202.1         192.168.202.2 NFS      336    V4 Reply (Call In 1882) SETATTR    1884 11.972754709   192.168.202.2         192.168.202.1 TCP      1516   785 → 2049 [ACK] Seq=465561 Ack=183381 Win=8990 Len=1448 TSval=1663691771 TSecr=3103357902 [TCP segment of a reassembled PDU]    1885 11.972763078   192.168.202.2         192.168.202.1 TCP      1516   785 → 2049 [ACK] Seq=467009 Ack=183381 Win=8990 Len=1448 TSval=1663691771 TSecr=3103357902 [TCP segment of a reassembled PDU]    1886 11.972979437   192.168.202.2         192.168.202.1 NFS      332    V4 Call (Reply In 1888) WRITE StateID: 0xafdf Offset: 0 Len: 2931    1887 11.973074490   192.168.202.1         192.168.202.2 TCP      68     2049 → 785 [ACK] Seq=183381 Ack=468721 Win=24557 Len=0 TSval=3103357902 TSecr=1663691771    1888 12.017153631   192.168.202.1         192.168.202.2 NFS      248    V4 Reply (Call In 1886) WRITE    1889 12.017338766   192.168.202.2         192.168.202.1 NFS      260    V4 Call (Reply In 1890) GETATTR FH: 0x825014ee    1890 12.017834411   192.168.202.1         192.168.202.2 NFS      312    V4 Reply (Call In 1889) GETATTR    1891 12.017961690   192.168.202.2         192.168.202.1 NFS      328    V4 Call (Reply In 1892) SETATTR FH: 0x825014ee    1892 12.039456634   192.168.202.1         192.168.202.2 NFS      336    V4 Reply (Call In 1891) SETATTR    1893 12.039536705   192.168.202.2         192.168.202.1 NFS      284    V4 Call (Reply In 1894) CLOSE StateID: 0xaa72    1894 12.039979528   192.168.202.1         192.168.202.2 NFS      248    V4 Reply (Call In 1893) CLOSE    1895 12.040077180   192.168.202.2         192.168.202.1 NFS      392    V4 Call (Reply In 1896) OPEN DH: 0xac0502f2/sysfs-cfq-target-latency    1896 12.061903798   192.168.202.1         192.168.202.2 NFS      408    V4 Reply (Call In 1895) OPEN StateID: 0xaa72

It looks like this takes about 100ms to write this small file. With the approx 60k files in the archive this would take about 6000 secs, so is in the 2 hours ballpark or the untar that I am seeing.

Looks like OPEN 21ms, SETATTR 22ms, WRITE 44ms, second SETATTR 21ms a lot of time ...

The following is for an "async" mount:

No.     Time           Source Destination           Protocol Length Info
  37393 7.630012608    192.168.202.2         192.168.202.1 NFS      396    V4 Call (Reply In 37394) OPEN DH: 0x1f828ac9/vidioc-dbg-g-chip-info.rst   37394 7.630488451    192.168.202.1         192.168.202.2 NFS      408    V4 Reply (Call In 37393) OPEN StateID: 0xaa72   37395 7.630525117    192.168.202.2         192.168.202.1 NFS      304    V4 Call (Reply In 37396) SETATTR FH: 0x0f65c554   37396 7.630980560    192.168.202.1         192.168.202.2 NFS      336    V4 Reply (Call In 37395) SETATTR   37397 7.631035171    192.168.202.2         192.168.202.1 TCP      1516   785 → 2049 [ACK] Seq=13054241 Ack=3620329 Win=8990 Len=1448 TSval=1664595527 TSecr=3104261711 [TCP segment of a reassembled PDU]   37398 7.631038994    192.168.202.2         192.168.202.1 TCP      1516   785 → 2049 [ACK] Seq=13055689 Ack=3620329 Win=8990 Len=1448 TSval=1664595527 TSecr=3104261711 [TCP segment of a reassembled PDU]   37399 7.631042228    192.168.202.2         192.168.202.1 TCP      1516   785 → 2049 [ACK] Seq=13057137 Ack=3620329 Win=8990 Len=1448 TSval=1664595527 TSecr=3104261711 [TCP segment of a reassembled PDU]   37400 7.631195554    192.168.202.2         192.168.202.1 NFS      448    V4 Call (Reply In 37402) WRITE StateID: 0xafdf Offset: 0 Len: 4493   37401 7.631277423    192.168.202.1         192.168.202.2 TCP      68     2049 → 785 [ACK] Seq=3620329 Ack=13058965 Win=24550 Len=0 TSval=3104261712 TSecr=1664595527   37402 7.631506418    192.168.202.1         192.168.202.2 NFS      248    V4 Reply (Call In 37400) WRITE   37403 7.631529718    192.168.202.2         192.168.202.1 NFS      260    V4 Call (Reply In 37404) GETATTR FH: 0x0f65c554   37404 7.631946710    192.168.202.1         192.168.202.2 NFS      312    V4 Reply (Call In 37403) GETATTR   37405 7.631982683    192.168.202.2         192.168.202.1 NFS      328    V4 Call (Reply In 37406) SETATTR FH: 0x0f65c554   37406 7.632423600    192.168.202.1         192.168.202.2 NFS      336    V4 Reply (Call In 37405) SETATTR   37407 7.632461397    192.168.202.2         192.168.202.1 NFS      284    V4 Call (Reply In 37408) CLOSE StateID: 0xaa72   37408 7.632880138    192.168.202.1         192.168.202.2 NFS      248    V4 Reply (Call In 37407) CLOSE   37409 7.632926994    192.168.202.2         192.168.202.1 NFS      396    V4 Call (Reply In 37410) OPEN DH: 0x1f828ac9/vidioc-dbg-g-register.rst   37410 7.633470097    192.168.202.1         192.168.202.2 NFS      408    V4 Reply (Call In 37409) OPEN StateID: 0xaa72

It looks like this takes about 3ms to write this small file. With the approx 60k files in the archive this would take about 180 secs, so is in the 3 minutes ballpark that I am seeing.

It looks like each RPC call takes about 0.5ms. Why do there need to be some many RPC calls for this ? The OPEN call could set the attribs, no need for the later GETATTR or SETATTR calls. Even the CLOSE could be integrated with the WRITE and taking this further OPEN could do OPEN, SETATTR, and some WRITE all in one.

_______________________________________________
devel mailing list -- devel@xxxxxxxxxxxxxxxxxxxxxxx
To unsubscribe send an email to devel-leave@xxxxxxxxxxxxxxxxxxxxxxx




[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
[Index of Archives]     [Fedora Announce]     [Fedora Kernel]     [Fedora Testing]     [Fedora Formulas]     [Fedora PHP Devel]     [Kernel Development]     [Fedora Legacy]     [Fedora Maintainers]     [Fedora Desktop]     [PAM]     [Red Hat Development]     [Gimp]     [Yosemite News]
  Powered by Linux