USB sandisk now very slow

phil524 · June 3, 2022, 2:58pm

Hello,

Since years I backup my data on 4 64GB USB sandisk (ultra plus SD XC). This is done via a bash script using many “cp -a source dest” commands
I use a USB hub V.3

# lspci
07:00.0 USB controller: Renesas Technology Corp. uPD720201 USB 3.0 Host Controller (rev 03)

The last backups took many more time:
Backup on 9 march 2022: the backup size was 43 GB
sandisk 1 28 minutes
sandisk 2 29 minutes
sandisk 3 40 minutes
sandisk 4 29 minutes
backup on 27 may 2022: the backup size was 44 GB
sandisk 1 176 minutes
sandisk 2 186 minutes
sandisk 3 237 minutes
sandisk 4 181 minutes
Something has changed between march and may 20222 >:(
I tried to change the USB cable but nothing changed.
I doubt that suddenly 4 sandisk can be simultaneously defective
Some tests

# top
Tasks: 338 total,   1 running, 337 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.6 us,  0.2 sy,  0.0 ni, 72.1 id, 27.0 wa,  0.0 hi,  0.0 si,  0.1 st
MiB Mem : 12916.65+total,  545.914 free, 2761.820 used, 9608.922 buff/cache
MiB Swap:    0.000 total,    0.000 free,    0.000 used. 9935.145 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND 
11249 philippe  20   0 2298564 366620 120544 S 8.940 2.772   0:46.96 seamonkey 
12869 root      20   0    4288   1304   1144 D 0.993 0.010   0:04.94 cp
 9366 philippe  20   0  853840 125860 100280 S 0.662 0.952   0:14.88 konsole
  245 root       0 -20       0      0      0 I 0.331 0.000   0:00.26 kworker/5:1H-kblockd
 1889 root      20   0  431680 164176 126004 S 0.331 1.241   6:08.32 Xorg.bin
 7448 root      20   0       0      0      0 D 0.331 0.000   0:11.13 kworker/u24:1+flush-8:48
10165 philippe  20   0  832148 100452  80972 S 0.331 0.759   0:03.24 kdesu
13240 root      20   0    8408   4404   3484 R 0.331 0.033   0:00.41 top

**# iostat -kyx /dev/sdd 5 50**
Linux 5.17.9-1-default (hpprol2)        06/03/22        _x86_64_        (12 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.02    0.00    0.08   14.04    0.05   85.81
Device            r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz     f/s f_await  aqu-sz  %util
sdd              0.40      0.00     0.00   0.00   50.50     0.00    8.60   6542.40     4.20  32.81  145.93   760.74    0.00      0.00     0.00   0.00    0.00     0.00    0.00    0.00    1.28  72.96

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.03    0.00    0.02   12.59    0.03   87.32
Device            r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz     f/s f_await  aqu-sz  %util
sdd              0.40      0.00     0.00   0.00   15.50     0.00    2.20   1561.60     4.00  64.52  974.82   709.82    0.00      0.00     0.00   0.00    0.00     0.00    0.00    0.00    2.15 100.00

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.03    0.00    0.05   16.77    0.05   83.10
Device            r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz     f/s f_await  aqu-sz  %util
sdd              0.20      0.00     0.00   0.00    3.00     0.00    0.80    652.00     0.00   0.00 1241.75   815.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00    0.00    0.99 100.00

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.02    0.00    0.03   16.35    0.03   83.57
Device            r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz     f/s f_await  aqu-sz  %util
sdd              0.40      0.00     0.00   0.00  493.50     0.00    2.80   2070.40     6.40  69.57  804.93   739.43    0.00      0.00     0.00   0.00    0.00     0.00    0.00    0.00    2.45  93.12

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.02    0.00    0.03   14.97    0.05   84.93
Device            r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz     f/s f_await  aqu-sz  %util
sdd              0.40      0.00     0.00   0.00  230.50     0.00    3.80   2821.60     3.80  50.00  379.79   742.53    0.00      0.00     0.00   0.00    0.00     0.00    0.00    0.00    1.54  98.96

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.12    0.00    0.10   18.46    0.17   81.15
Device            r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz     f/s f_await  aqu-sz  %util
sdd              0.20      0.00     0.00   0.00  650.00     0.00    5.80    185.60     5.40  48.21  163.59    32.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00    0.00    1.08  87.28

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.02    0.00    0.05   16.18    0.05   83.70
Device            r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz     f/s f_await  aqu-sz  %util
sdd              0.40      0.00     0.00   0.00  216.00     0.00    5.60   4260.00     2.60  31.71  377.29   760.71    0.00      0.00     0.00   0.00    0.00     0.00    0.00    0.00    2.20  98.64

Seems that the write speed can change from 185 up to 6542Kb/s ??
I use zypper dup to update my system when a new snapshot is available.
Is this a bug or can it be a hardware problem?
The USB details

lsusb -v -s 005:002

Bus 005 Device 002: ID 0781:cfcc SanDisk Corp. SDDR-C531
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               3.10
  bDeviceClass            0 
  bDeviceSubClass         0 
  bDeviceProtocol         0 
  bMaxPacketSize0         9
  idVendor           0x0781 SanDisk Corp.
  idProduct          0xcfcc 
  bcdDevice           29.20
  iManufacturer           3 SanDisk
  iProduct                4 SDDR-C531
....
  SuperSpeed USB Device Capability:
    bLength                10
    bDescriptorType        16
    bDevCapabilityType      3
    bmAttributes         0x00
    wSpeedsSupported   0x000e
      Device can operate at Full Speed (12Mbps)
      Device can operate at High Speed (480Mbps)
      Device can operate at SuperSpeed (5Gbps)
    bFunctionalitySupport   1
      Lowest fully-functional device speed is Full Speed (12Mbps)
    bU1DevExitLat          10 micro seconds
    bU2DevExitLat        2047 micro seconds

Regards
Philippe

karlmistelberger · June 3, 2022, 6:40pm

I get what I got in the past:

**erlangen:/media/DMC-TZ71 #** fio --name=random-write --ioengine=posixaio --rw=randwrite --bs=1m --size=2g --numjobs=1 --iodepth=1 --runtime=60 --time_based --end_fsync=1  
random-write: (g=0): rw=randwrite, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=posixaio, iodepth=1 
fio-3.30 
Starting 1 process 
Jobs: 1 (f=1): [w(1)][100.0%][eta 00m:00s]                          
random-write: (groupid=0, jobs=1): err= 0: pid=29307: Fri Jun  3 18:36:58 2022 
  write: IOPS=71, BW=71.3MiB/s (74.7MB/s)(6145MiB/86239msec); 0 zone resets 
    slat (usec): min=17, max=139, avg=35.10, stdev= 7.11 
    clat (usec): min=584, max=1717, avg=640.68, stdev=97.76 
     lat (usec): min=614, max=1857, avg=675.79, stdev=98.48 
    clat percentiles (usec): 
     |  1.00th=  594],  5.00th=  603], 10.00th=  603], 20.00th=  611], 
     | 30.00th=  611], 40.00th=  611], 50.00th=  619], 60.00th=  627], 
     | 70.00th=  627], 80.00th=  644], 90.00th=  668], 95.00th=  701], 
     | 99.00th= 1270], 99.50th= 1287], 99.90th= 1598], 99.95th= 1647], 
     | 99.99th= 1713] 
   bw (  MiB/s): min=  300, max= 1512, per=100.00%, avg=1117.09, stdev=475.76, samples=11 
   iops        : min=  300, max= 1512, avg=1117.09, stdev=475.76, samples=11 
  lat (usec)   : 750=96.53%, 1000=1.01% 
  lat (msec)   : 2=2.46% 
  cpu          : usr=0.26%, sys=4.06%, ctx=31742, majf=0, minf=25 
  IO depths    : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% 
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% 
     issued rwts: total=0,6145,0,0 short=0,0,0,0 dropped=0,0,0,0 
     latency   : target=0, window=0, percentile=100.00%, depth=1 

Run status group 0 (all jobs): 
  WRITE: bw=71.3MiB/s (74.7MB/s), 71.3MiB/s-71.3MiB/s (74.7MB/s-74.7MB/s), io=6145MiB (6443MB), run=86239-86239msec 

Disk stats (read/write): 
  sdc: ios=42/7885, merge=0/2434, ticks=240/124632, in_queue=124872, util=93.33% 
**erlangen:/media/DMC-TZ71 #**