Samba performance degraded after last update

[shamael-01]

Hi,

Updating my RPI4 this week SMB performances dropped from consistent >=100MB/s to 60-70MB/s. Not much were updated recently, it may comes from the kernel 5.13.0-1016-raspi (a guess). At this time I'm fully updated but the last kernel 1017 seems not active yet (flash-kernel not triggered) even if present on the /boot

Does it ring a bell?

#Version info
            .-/+oossssoo+/-. root@xxxxxx
        `:+ssssssssssssssssss+:` ------------
      -+ssssssssssssssssssyyssss+- OS: Ubuntu 21.10 aarch64
    .ossssssssssssssssssdMMMNysssso. Host: Raspberry Pi 4 Model B Rev 1.4
   /ssssssssssshdmmNNmmyNMMMMhssssss/ Kernel: 5.13.0-1016-raspi
  +ssssssssshmydMMMMMMMNddddyssssssss+ Uptime: 41 mins
 /sssssssshNMMMyhhyyyyhmNMMMNhssssssss/ Packages: 1860 (dpkg), 10 (snap)
.ssssssssdMMMNhsssssssssshNMMMdssssssss. Shell: bash 5.1.8
+sssshhhyNMMNyssssssssssssyNMMMysssssss+ Resolution: 1920x1080
ossyNMMMNyMMhsssssssssssssshmmmhssssssso WM: Mutter
ossyNMMMNyMMhsssssssssssssshmmmhssssssso WM Theme: Adwaita
+sssshhhyNMMNyssssssssssssyNMMMysssssss+ Theme: Adwaita [GTK3]
.ssssssssdMMMNhsssssssssshNMMMdssssssss. Icons: Adwaita [GTK3]
 /sssssssshNMMMyhhyyyyhdNMMMNhssssssss/ Terminal: gnome-terminal
  +sssssssssdmydMMMMMMMMddddyssssssss+ CPU: BCM2835 (4) @ 1.800GHz
   /ssssssssssshdmNNNNmyNMMMMhssssss/ Memory: 1504MiB / 7808MiB
    .ossssssssssssssssssdMMMNysssso.
      -+sssssssssssssssssyyyssss+-
        `:+ssssssssssssssssss+:`
            .-/+oossssoo+/-.

#The /boot content
/boot
total 51679
drwxr-xr-x 5 root root 4096 Feb 22 08:18 ./
drwxr-xr-x 20 root root 4096 Jun 28 2021 ../
-rw-r--r-- 1 root root 241429 Jan 20 09:09 config-5.13.0-1016-raspi
-rw-r--r-- 1 root root 241429 Feb 9 10:01 config-5.13.0-1017-raspi
lrwxrwxrwx 1 root root 44 Feb 22 08:13 dtb -> dtbs/5.13.0-1017-raspi/./bcm2711-rpi-4-b.dtb*
lrwxrwxrwx 1 root root 44 Feb 16 08:12 dtb-5.13.0-1016-raspi -> dtbs/5.13.0-1016-raspi/./bcm2711-rpi-4-b.dtb*
lrwxrwxrwx 1 root root 44 Feb 22 08:13 dtb-5.13.0-1017-raspi -> dtbs/5.13.0-1017-raspi/./bcm2711-rpi-4-b.dtb*
drwxr-xr-x 17 root root 4096 Feb 22 08:13 dtbs/
drwxr-xr-x 5 root root 7168 Jan 1 1970 firmware/
drwxr-xr-x 2 root root 4096 Jun 24 2021 grub/
lrwxrwxrwx 1 root root 28 Feb 22 08:12 initrd.img -> initrd.img-5.13.0-1017-raspi
-rw-r--r-- 1 root root 11583918 Feb 16 08:11 initrd.img-5.13.0-1016-raspi
-rw-r--r-- 1 root root 11593765 Feb 22 08:13 initrd.img-5.13.0-1017-raspi
lrwxrwxrwx 1 root root 28 Feb 22 08:12 initrd.img.old -> initrd.img-5.13.0-1016-raspi
-rw------- 1 root root 5114984 Jan 20 09:09 System.map-5.13.0-1016-raspi
-rw------- 1 root root 5115142 Feb 9 10:01 System.map-5.13.0-1017-raspi
lrwxrwxrwx 1 root root 25 Feb 22 08:12 vmlinuz -> vmlinuz-5.13.0-1017-raspi
-rw------- 1 root root 9498568 Jan 20 09:09 vmlinuz-5.13.0-1016-raspi
-rw------- 1 root root 9497818 Feb 9 10:01 vmlinuz-5.13.0-1017-raspi
lrwxrwxrwx 1 root root 25 Feb 22 08:12 vmlinuz.old -> vmlinuz-5.13.0-1016-raspi

#Recently installed
grep "install " /var/log/dpkg.log
2022-02-02 08:02:32 install linux-raspi-headers-5.13.0-1016:arm64 <none> 5.13.0-1016.18
2022-02-02 08:02:48 install linux-headers-5.13.0-1016-raspi:arm64 <none> 5.13.0-1016.18
2022-02-02 08:02:53 install linux-modules-5.13.0-1016-raspi:arm64 <none> 5.13.0-1016.18
2022-02-02 08:02:59 install linux-image-5.13.0-1016-raspi:arm64 <none> 5.13.0-1016.18
2022-02-16 08:09:44 install libqt5sql5:arm64 <none> 5.15.2+dfsg-12ubuntu1.1
2022-02-16 08:09:44 install libqt5sql5-sqlite:arm64 <none> 5.15.2+dfsg-12ubuntu1.1
2022-02-22 08:11:28 install linux-raspi-headers-5.13.0-1017:arm64 <none> 5.13.0-1017.19
2022-02-22 08:11:43 install linux-headers-5.13.0-1017-raspi:arm64 <none> 5.13.0-1017.19
2022-02-22 08:11:48 install linux-modules-5.13.0-1017-raspi:arm64 <none> 5.13.0-1017.19
2022-02-22 08:11:54 install linux-image-5.13.0-1017-raspi:arm64 <none> 5.13.0-1017.19
---
ProblemType: Bug
ApportVersion: 2.20.11-0ubuntu71
Architecture: arm64
AudioDevicesInUse:
 USER PID ACCESS COMMAND
 /dev/snd/controlC1: booster 1354 F.... pulseaudio
 /dev/snd/controlC0: booster 1354 F.... pulseaudio
CasperMD5CheckResult: unknown
DistroRelease: Ubuntu 21.10
ImageMediaBuild: 20210421
IwConfig:
 lo no wireless extensions.

 eth0 no wireless extensions.
Lspci-vt: -[0000:00]---00.0-[01]----00.0 VIA Technologies, Inc. VL805/806 xHCI USB 3.0 Controller
Package: linux-raspi 5.13.0.1017.22
PackageArchitecture: arm64
ProcFB: 0 BCM2708 FB
ProcKernelCmdLine: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=1920 bcm2708_fb.fbheight=1080 bcm2708_fb.fbswap=1 smsc95xx.macaddr=E4:5F:01:29:45:26 vc_mem.mem_base=0x3eb00000 vc_mem.mem_size=0x3ff00000 dwc_otg.lpm_enable=0 console=tty1 root=LABEL=writable rootfstype=ext4 elevator=deadline rootwait fixrtc quiet splash
ProcVersionSignature: Ubuntu 5.13.0-1016.18-raspi 5.13.19
PulseList: Error: command ['pacmd', 'list'] failed with exit code 1: No PulseAudio daemon running, or not running as session daemon.
RelatedPackageVersions:
 linux-restricted-modules-5.13.0-1016-raspi N/A
 linux-backports-modules-5.13.0-1016-raspi N/A
 linux-firmware 1.201.4
RfKill:

StagingDrivers: vc_sm_cma snd_bcm2835 bcm2835_mmal_vchiq bcm2835_isp bcm2835_codec bcm2835_v4l2
Tags: arm64-image raspi-image impish staging
Uname: Linux 5.13.0-1016-raspi aarch64
UpgradeStatus: Upgraded to impish on 2021-12-20 (68 days ago)
UserGroups: N/A
_MarkForUpload: True
acpidump:

[shamael-01 (shamael-01)]

Update:
The situation remains, the RPI4 has now frozen with a 10GB samba transfer. This never happened in the past since June 2021, even with much bigger amount of data. The RPI is headless so I didn't catch the possible displayed message, SSH/VNC/ping/samba were all unavailable suddenly.

Something maybe interesting: right after the reboot I retried the samba transfer and I get my usual speed 105-110MB/s. As I did several reboot after the kernel update it may comes by time (the slowness).

I do not see anything obvious in the syslog except a gap in the flow of message, printed again when the restart occured

[shamael-01 (shamael-01)]

Slow SMB speed back 2hours after my previous post (and possible associated crash)

[Juerg Haefliger (juergh)]

Please run 'sudo apport-collect 1962180'.

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

apport information

[shamael-01 (shamael-01)]

Dear Juerg, it's done

[shamael-01 (shamael-01)]

New update received, see below. The samba slowness remains. Not the place to mention it maybe but snap update to Firefox 98.0-3 kill it, not possible to start it anymore.

grep "install " /var/log/dpkg.log
2022-03-09 07:53:59 install linux-raspi-headers-5.13.0-1020:arm64 <none> 5.13.0-1020.22
2022-03-09 07:54:13 install linux-headers-5.13.0-1020-raspi:arm64 <none> 5.13.0-1020.22
2022-03-09 07:54:19 install linux-modules-5.13.0-1020-raspi:arm64 <none> 5.13.0-1020.22
2022-03-09 07:54:25 install linux-image-5.13.0-1020-raspi:arm64 <none> 5.13.0-1020.22

uname -r
5.13.0-1020-raspi

[Juerg Haefliger (juergh)]

1) Are you sure the network is the bottleneck and not your local storage device?

2) Are the drives self-powered or are they powered over USB? If powered over USB, they might draw too much current from the Pi which could lead to all sorts of problems. Try with a powered hub.

3) Are there any messages in the kernel log (dmesg) at or before the time when the transfer rate drops?

4) Can you try to disable UAS for the two drives to see if that makes a difference? See https://forums.raspberrypi.com/viewtopic.php?f=28&t=245931.
Add 'usb-storage.quirks=174c:1153:u usb-storage.quirks=174c:55a:u' to /boot/firmware/cmdline.txt, reboot and check dmesg that UAS is disabled.

[shamael-01 (shamael-01)]

Hi Juerg

1) The local storage is an UASP WD RED able to read and right on a continuous may >120MB/S. An iPerf test shows >910Mbps in both ways on a 10min test, even now the SMB issue exist. For some background I use this setup daily for more than 8 months, I get consistent transfer >100MB/s each time. In the past a comparable behaviour occurred after an update too, and was fixed some week after (no bug raised.

2) I've two drive on the RPI4, both UASP enabled: an SSD (M.2 powered over USB) and an HDD self-powered handling the shares.

3)None specifics. Currently I didn't encounter a new crash since the last one, the slower SMB speed remains. One thing I may have missed: The CPU seems higher than before. This may be a root cause but I've here only a feeling, no counter to prove it (before vs now).

4) I will try to pickup times to try it, but I'm not keen to adopt this setup. I specifically selected components to have it enabled, and it worked as expected up to this update.

Thank you

[Juerg Haefliger (juergh)]

I'm not seeing a significant drop in SMB transfer rate between kernels 5.13.0-1015-raspi and 5.13.0-1016-raspi:

+ uname -r
5.13.0-1015-raspi
+ dd of=samba/juergh/foo if=/dev/zero bs=1G count=10
10+0 records in
10+0 records out
10737418240 bytes (11 GB, 10 GiB) copied, 96.5918 s, 111 MB/s
+ dd if=samba/juergh/foo of=/dev/null bs=1G count=10
10+0 records in
10+0 records out
10737418240 bytes (11 GB, 10 GiB) copied, 98.8129 s, 109 MB/s

+ uname -r
5.13.0-1016-raspi
+ dd of=samba/juergh/foo if=/dev/zero bs=1G count=10
10+0 records in
10+0 records out
10737418240 bytes (11 GB, 10 GiB) copied, 95.5841 s, 112 MB/s
+ dd if=samba/juergh/foo of=/dev/null bs=1G count=10
10+0 records in
10+0 records out
10737418240 bytes (11 GB, 10 GiB) copied, 99.4568 s, 108 MB/s

This is pretty much link saturation. Maybe your case is related to disk IO.

[shamael-01 (shamael-01)]

Hi Juerg,

This is of course a possibility but I tested it at the setup time and right now:

sudo hdparm -t /dev/sda
/dev/sda:
 Timing buffered disk reads: 442 MB in 3.00 seconds = 147.14 MB/sec

sudo hdparm -t --direct /dev/sda
/dev/sda:
 Timing O_DIRECT disk reads: 450 MB in 3.01 seconds = 149.73 MB/sec

This is consistent over 10 tests, lowest value was 141 MB/sec (all other services running). The fact this happened after an update twice in a year, corrected after some weeks the first time, is a clue.
I see some similarities in this topic https://github.com/raspberrypi/linux/issues/4133 but as it's not a major topic the root cause should be specific to some setup or conditions (a guess)

[Juerg Haefliger (juergh)]

Can you run my tests to rule out the disk?

[shamael-01 (shamael-01)]

All remote computers with 1Gbps support are Windows OS by my place. I'll try to find something.
I launched the command locally on the Ubuntu server to have a first result

sudo dd if=/dev/zero of=/XXXXX/test1.img bs=1G count=10
0+0 records in
10+0 records out
10737418240 bytes (11 GB, 10 GiB) copied, 107.628 s, 99.8 MB/s

PS: Be aware I previously used the hdparm read tests because all the raised problem here concerns read only. The source is the RPI samba shares, destination an NVMe SSD under Windows

[Juerg Haefliger (juergh)]

Oh, the Pi is the server not the client. Hold on then.

[shamael-01 (shamael-01)]

Indeed, sorry if this was not clear since the beginning.
I pull daily some data of the same time from the RPI SMB share to my computer, so SMB read traffic for the RPI.

EDIT: I see new updates coming and a new kernel (see below). If such has any interest (but you know my suspicion :) )
linux-headers-raspi/impish-updates,impish-security 5.13.0.1022.27 arm64 [upgradable from: 5.13.0.1020.25]
linux-image-raspi/impish-updates,impish-security 5.13.0.1022.27 arm64 [upgradable from: 5.13.0.1020.25]

[Juerg Haefliger (juergh)]

Using the Pi as a samba server, I see no difference between these kernels. Maybe you have some cron job or other thing that kicks in periodically or your disk is doing periodic SMART monitoring? But that wouldn't explain why you believe there is a difference between kernels...

5.13.0-1022-raspi

Write
10737418240 bytes (11 GB, 10 GiB) copied, 99.046 s, 108 MB/s

Read
10737418240 bytes (11 GB, 10 GiB) copied, 105.49 s, 102 MB/s

5.13.0-1016-raspi

Write
10737418240 bytes (11 GB, 10 GiB) copied, 98.479 s, 109 MB/s

Read
10737418240 bytes (11 GB, 10 GiB) copied, 104.85 s, 102 MB/s

5.13.0-1015-raspi

Write
10737418240 bytes (11 GB, 10 GiB) copied, 100.223 s, 107 MB/s

Read
10737418240 bytes (11 GB, 10 GiB) copied, 105.445 s, 102 MB/s

[shamael-01 (shamael-01)]

It may be kernel or other package, but kernels was the only dpkg.log entries between a the stable >100MB/secs situation and now. I just installed the 5.13.0-1022-raspi (see my edit above) followed by a reboot. As noticed the situation seems always better during a small amount of time after a restart but anyway I just transferred 10GB with a very stable 105-108MB/sec.

Their are indeed small system interactions (SMART, script and other), the same as always. I keep digging and have to say thank you for the time you spent on this already

[Juerg Haefliger (juergh)]

How much data are you pulling and how frequent?

[shamael-01 (shamael-01)]

Let's say 5-8GB per day

[Juerg Haefliger (juergh)]

Is this still an issue with 22.04 and the 5.15 kernel?

[shamael-01 (shamael-01)]

Dear Juerg,

Well "just in time" may be the right words. I updated a couple of weeks ago to 22.04 and it was gone, as with the last update of 21.10 (sorry for the lack of update). It's mitigated now by the last 5.15.0-1011-raspi (5.15.0-1011.13) introducing again a lower speed.
As always tested on multiple transfer per day.

Anyway I'm not sure we will be able to fix or mitigate it here, the pattern is clear with an 24/7 computer facing slowness or not depending the update. when it's fine, I have no slowness at all for weeks. But the number of variables doesn't help me in terms for research.

Feel free to close the ticket prior the holidays :), another one can still be opened if necessary.

Thank you for your time
Cheers

[Juerg Haefliger (juergh)]

Ok, thanks for the update. I'll close the ticket then. Please open a new one if you can clearly demonstrate that the kernel is the culprit (which I'm still not totally convinced of).