Reads and writes slow to 5MB/s after a short time

[sarahbau]

I am in the process of getting unraid configured to see if I want to replace my Debian server setup. I'm trying to copy from my ext4 drives installed in the server to an xfs drive I set up in unRAID. I installed the "Unassigned Devices" plugin, and mounted my Plex drive. I then sshed in from my laptop and used rsync to copy the data over (from server drive to server drive. No network involved other than the ssh session). I noticed that while the speeds started out fine (100MB/s), they dropped off to 5MB/s after a minute or so. I checked the status of the server and saw that there was no CPU usage and only 7% RAM usage, so it's not like it got bogged down or anything.

 

I stopped the transfer, then tried to run hdparm to test the drive speeds, but it wouldn't run on either drive (it just sat there indefinitely after listing the drive number). I restarted the server, mounted the drives again, and tested with hdparm again:

root@Oort-Cloud:/mnt/disks/2TB_1# hdparm -t /dev/sde1
/dev/sde1:
 Timing buffered disk reads: 240 MB in  3.01 seconds =  79.84 MB/sec
 
 root@Oort-Cloud:/mnt/disk1/unraidtest# hdparm -t /dev/sdd1
/dev/sdd1:
 Timing buffered disk reads: 946 MB in  3.00 seconds = 314.83 MB/sec

80MB/s and 315MB/s was more like it, so I started rsync again, and saw speeds drop off again:

root@Oort-Cloud:/mnt/disks# rsync -av --partial --progress 2TB_1 ../disk1/unraidtest 
sending incremental file list
2TB_1/plex/anime/Attack on Titan/
2TB_1/plex/anime/Attack on Titan/Attack_on_Titan-s01e05-First_Battle.mkv
    888,928,607 100%   97.89MB/s    0:00:08 (xfr#5, ir-chk=1029/1119)
2TB_1/plex/anime/Attack on Titan/Attack_on_Titan-s01e06-The_World_the_Girl_Saw.mkv
    604,475,710 100%   88.21MB/s    0:00:06 (xfr#6, ir-chk=1028/1119)
2TB_1/plex/anime/Attack on Titan/Attack_on_Titan-s01e07-Small_Blade.mkv
    696,125,324 100%   92.51MB/s    0:00:07 (xfr#7, ir-chk=1027/1119)
2TB_1/plex/anime/Attack on Titan/Attack_on_Titan-s01e08-I_Can_Hear_His_Heartbeat.mkv
    763,192,167 100%   99.09MB/s    0:00:07 (xfr#8, ir-chk=1026/1119)
2TB_1/plex/anime/Attack on Titan/Attack_on_Titan-s01e09-Whereabouts_of_His_Left_Arm_[v2].mkv
    797,470,790 100%    4.76MB/s    0:02:39 (xfr#9, ir-chk=1025/1119)
2TB_1/plex/anime/Attack on Titan/Attack_on_Titan-s01e10-Response.mkv
     28,934,144   3%    5.28MB/s    0:02:19  ^C
rsync error: received SIGINT, SIGTERM, or SIGHUP (code 20) at rsync.c(636) [sender=3.1.2]
rsync error: received SIGINT, SIGTERM, or SIGHUP (code 20) at io.c(504) [generator=3.1.2]

So, I'm confused. This isn't even going over the network, or using the shares. This is directly on the server, using hardware I know to be good, and has worked for years. The source drive is a lowly 2TB WD Green, but the destination is a 4 drive hardware RAID5 on an LSI RAID card with WD RE drives. My first thought was that maybe it was using the RAM as cache, and filling that up, but the server has 16GB of RAM, and it slowed down after only 2.8GB of transfers (and as mentioned above, only 7% of the RAM was being used, so it didn't appear to be caching it).

 

After letting the server sit idle for a while (I didn't time it. Maybe 30-60 minutes though), I decided to see if the speed would be back to normal, and it was, for a few seconds anyway:

root@Oort-Cloud:/mnt/disks# rsync -av --partial --progress 2TB_1 ../disk1/unraidtest
sending incremental file list
2TB_1/plex/anime/Attack on Titan/
2TB_1/plex/anime/Attack on Titan/Attack_on_Titan-s01e10-Response.mkv
    782,283,385 100%   50.86MB/s    0:00:14 (xfr#1, ir-chk=1024/1119)
2TB_1/plex/anime/Attack on Titan/Attack_on_Titan-s01e11-Idol.mkv
    775,618,055 100%   99.02MB/s    0:00:07 (xfr#2, ir-chk=1023/1119)
2TB_1/plex/anime/Attack on Titan/Attack_on_Titan-s01e12-Wound_[v2].mkv
    743,200,607 100%   94.28MB/s    0:00:07 (xfr#3, ir-chk=1022/1119)
2TB_1/plex/anime/Attack on Titan/Attack_on_Titan-s01e13-Primal_Desire.mkv
    858,939,567 100%   12.23MB/s    0:01:06 (xfr#4, ir-chk=1021/1119)
2TB_1/plex/anime/Attack on Titan/Attack_on_Titan-s01e14-Can't_Look_into_His_Eyes_Yet.mkv
    640,042,530 100%    5.14MB/s    0:01:58 (xfr#5, ir-chk=1020/1119)
2TB_1/plex/anime/Attack on Titan/Attack_on_Titan-s01e15-Special_Operations_Squad.mkv
     21,594,112   3%    4.99MB/s    0:01:57  ^C
rsync error: received SIGINT, SIGTERM, or SIGHUP (code 20) at rsync.c(636) [sender=3.1.2]
rsync error: received SIGINT, SIGTERM, or SIGHUP (code 20) at io.c(504) [generator=3.1.2]

For the first file, where it only shows a 50MB/s average, it started out slow (about 12MB/s), and ramped up to 100MB/s. As you can see, the speed dropped down again after only 30 seconds, which is about the same amount of time the first transfer lasted. The first transfer got more data in though. Any ideas? Thanks in advance.

[Frank1940]

Post up your diagnostics file.  It looks like your transfers are slowly down after the RAM cache fills up. 

[JonathanM]

5 hours ago, sarahbau said:

I'm trying to copy from my ext4 drives installed in the server to an xfs drive I set up in unRAID.

 

5 hours ago, sarahbau said:

The source drive is a lowly 2TB WD Green, but the destination is a 4 drive hardware RAID5 on an LSI RAID card with WD RE drives.

Wait, what exactly are you doing?

 

In the first part of the post, you say you are copying to unraid. In the second part you say you are using hardware RAID5.

 

Can you explain a little more about your unraid server? I'm not sure you are using it as intended, or something got lost in translation.

[sarahbau]

7 hours ago, Frank1940 said:

Post up your diagnostics file.  It looks like your transfers are slowly down after the RAM cache fills up. 

That was my first thought as well, but would it even use a cache for a local file copy? Also, the RAM didn't seem to be used (stayed at 7% use out of 16GB).

oort-cloud-diagnostics-20170416-1539.zip

[sarahbau]

4 hours ago, jonathanm said:

 

Wait, what exactly are you doing?

 

In the first part of the post, you say you are copying to unraid. In the second part you say you are using hardware RAID5.

 

Can you explain a little more about your unraid server? I'm not sure you are using it as intended, or something got lost in translation.

 

From what I've read, it doesn't seem uncommon for people to use RAID0 for a cache drive. Since I already have the RAID5 set up, I figured I'd use that one as cache. The rest of the server is JBOD though.

 

Current setup:

500GB RAID1 boot drive

4x 1TB RAID5 (previously used for things that required the speed. Lately just used as a backup drive)

2TB drive for plex content (getting full)

2TB drive for music, ISOs, and other random stuff

 

There are a few reasons I'm thinking about switching to unRAID:

I can use a variety of sizes while still having the protection of parity. One of the reasons I haven't upgraded my RAID5 in so long is it's expensive to buy four drives at a time. I like the idea of having a cache, so I can quickly write files that don't necessarily need to be read quickly (Plex movies, for example). My husband and I are both building new computers that will only have SSDs in them, so we will need more network storage, and unRAID seemed like a better way to do it than JBOD, and a cheaper way (possibly) than upgrading the whole RAID5 at once.

 

New setup (planned)

RAID5 cache (I might split it into a 1TB cache and 2TB drive for fast storage in the array)

Parity drive (maybe 4TB)

Array (two current 2TB drives, plus maybe another 4TB)

[JonathanM]

Sorry, but I'm still confused. What configuration is the machine that you are using to test unraid? You list a current setup, and a new planned setup, but neither seems to match what is happening in your test.

[sarahbau]

Just now, jonathanm said:

Sorry, but I'm still confused. What configuration is the machine that you are using to test unraid? You list a current setup, and a new planned setup, but neither seems to match what is happening in your test.

The "current setup" was referring to the Debian setup I've been using as a fileserver, not how unRAID is currently set up.

 

I have a 3TB RAID drive, and two 2TB single drives. Since unRAID doesn't seem to be able to read existing drives, I had to format one of the drives to add it to unRAID. Since the RAID had the least data on it, I formatted it as xfs and added it. I want it as the cache drive, but unraid doesn't let you have a cache without drives in the array, so I temporarily had to set it as a drive in the array. I added the plugin "Unassigned Devices" so I could mount the 2TB drives to copy data into the unRAID array. Simply copying from one of those drives to the RAID slows down after 30 seconds.

[sarahbau]

Just to test, I reformatted the drive as btrfs, and it still slows down (though now it goes to 1.6MB/s instead of 5)

[sarahbau]

More tests:

Copying from 2TB_1 to RAID (what I was doing last night) starts fast and slows down

Copying from 2TB_2 to RAID starts fast and slows down

Copying from 2TB_2 to 2TB_1 starts fast and slows down

Copying from 2TB_1 to 2TB_2 starts fast and slows down

Copying from RAID to RAID starts fast (over 300MB/s), and slows down

 

Thinking maybe it was something with rsync, I timed a simple cp from RAID to RAID:

root@Oort-Cloud:/mnt/disk1/unraidtest# du -hs 2TB_1 
3.1G	2TB_1
root@Oort-Cloud:/mnt/disk1/unraidtest# time cp -r 2TB_1 2TB_1_copy

real	8m49.791s
user	0m1.352s
sys	0m2.164s

That comes out to 6MB/s

[JorgeB]

You're getting constant controller errors:
 

Apr 16 05:46:34 Oort-Cloud kernel: 3w-9xxx: scsi1: ERROR: (0x03:0x0101): Invalid command opcode:opcode=0x85.
Apr 16 05:46:34 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
Apr 16 05:46:34 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 Sense Key : 0x5 [current]
Apr 16 05:46:34 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 ASC=0x20 ASCQ=0x0
Apr 16 05:46:34 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 CDB: opcode=0x85 85 06 20 00 00 00 00 00 00 00 00 00 00 40 e5 00
Apr 16 05:46:35 Oort-Cloud kernel: 3w-9xxx: scsi1: ERROR: (0x03:0x0101): Invalid command opcode:opcode=0x85.
Apr 16 05:46:35 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
Apr 16 05:46:35 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 Sense Key : 0x5 [current]
Apr 16 05:46:35 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 ASC=0x20 ASCQ=0x0
Apr 16 05:46:35 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 CDB: opcode=0x85 85 06 20 00 00 00 00 00 00 00 00 00 00 40 98 00
Apr 16 05:46:36 Oort-Cloud kernel: 3w-9xxx: scsi1: ERROR: (0x03:0x0101): Invalid command opcode:opcode=0x85.
Apr 16 05:46:36 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
Apr 16 05:46:36 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 Sense Key : 0x5 [current]
Apr 16 05:46:36 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 ASC=0x20 ASCQ=0x0
Apr 16 05:46:36 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 CDB: opcode=0x85 85 06 20 00 00 00 00 00 00 00 00 00 00 40 e5 00
Apr 16 05:46:37 Oort-Cloud kernel: 3w-9xxx: scsi1: ERROR: (0x03:0x0101): Invalid command opcode:opcode=0x85.
Apr 16 05:46:37 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
Apr 16 05:46:37 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 Sense Key : 0x5 [current]
Apr 16 05:46:37 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 ASC=0x20 ASCQ=0x0
Apr 16 05:46:37 Oort-Cloud kernel: sd 1:0:0:0: [sdd] tag#0 CDB: opcode=0x85 85 06 20 00 00 00 00 00 00 00 00 00 00 40 98 00

 

Try without using the 3ware controller, use the onboard ports only.

[sarahbau]

Apparently that error can (supposedly) be safely ignored. From what I've found, it's when it's trying to ask for the temperature of the drive, but the controller doesn't have a temp. In any case, I'll try without it

[sarahbau]

I tested with the RAID controller completely removed (RAID drives were still in but connected to nothing but power), and get the same thing when copying from one drive to another. Now I'm trying to reboot into  Debian to make sure this isn't a problem that recently came up with the hardware that I just didn't notice. Of course it doesn't want to cooperate. I'll post results once I get it back up.

[sarahbau]

So I think there's something wrong with my Debian boot drive, but I was able to boot to a Lubuntu live CD to test. I'm able to copy from 2TB_1 to 2TB_2 at around 50-80MB/s. It  did occasionally slow down to ~10 due to periodic CD-spinup, but not the 5MB/s I was seeing on unRAID. It doesn't seem to like the RAID5 though, as it only seems to write to it at 20MB/s (though was still able to read from it at 374MB/s)