RN102 - readynasd (loadavg) runaway cpu usage?

[BrianTopp]

My ReadyNAS 102, running firmware 6.10.3, is currently thrashing its cpu.

Here's the output from top:

top - 18:50:39 up 16 days, 22:11,  1 user,  load average: 1.87, 1.86, 1.89
Tasks: 143 total,   1 running, 142 sleeping,   0 stopped,   0 zombie
%Cpu(s): 99.7 us,  0.3 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem:    508660 total,   473804 used,    34856 free,    21716 buffers
KiB Swap:   523964 total,      336 used,   523628 free.   192664 cached Mem

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND      
 2171 root      19  -1  215996  39504  12488 S 97.4  7.8   2762:53 readynasd

And here's top in threads mode:

top - 18:51:00 up 16 days, 22:12,  1 user,  load average: 1.62, 1.81, 1.87
Threads: 175 total,   3 running, 171 sleeping,   0 stopped,   1 zombie
%Cpu(s): 96.9 us,  2.7 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.4 si,  0.0 st
KiB Mem:    508660 total,   473588 used,    35072 free,    21764 buffers
KiB Swap:   523964 total,      336 used,   523628 free.   192664 cached Mem

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND      
 2312 root      19  -1  215996  39504  12488 R 67.6  7.8   2707:10 loadavg

It seems the "loadavg" thread is (ironically?) taking all the cpu.

I don't see any errors in the logs on the admin interface, nor in the journal messages for readynasd. The only thing I notice is that the loadavg.log ends with an entry showing the uptime at 14 days, where now the uptime is 16 days, and so maybe loadavg has been stuck for a couple of days now?

Can anyone help me fix this? I'm loathe to just reboot and hope, as this is about the 3rd or 4th time in the last couple of months. Previously I had a USB backup disk become full and so put the problems down to that, but I removed it for this boot. I thought the problem was fixed, until I noticed it again today.

Thanks in advance,

Bri

[Sandshark]

Is the NAS currently doing a scrub or other intensive process?  I have seen even more powerful NAS models have readynasd run amuck during those processes, eating up to 100% of the CPU time.  It has been reported to Netghear by myself and others, but to no avail.  My suspicion is that some I/O process gets locked and readynasd just keeps trying it over and over again.  Maybe you've identified that process.

[BrianTopp]

Thanks for the info.

Nothing else seems to be using significant resources, either now or when I first noticed the problem yesterday. I've never asked for a scrub/defrag/balance/test, and the 'Volume Schedule' is empty (and has always been so, AFAIK). I haven't touched the admin interface for at least a week, so wasn't using it at the time the problem started.

I don't think I ever have the NAS do anything intensive, though I do run a couple of services in a non-official way (syncthing & logitech media server). It's conceivable they could cause a high load at times, I suppose.

Anyone have any other ideas? Should I just reboot, or is there something I should try before that which could help us understand the problem?

[BrianTopp]

Shortly after my last message, I restarted the `readynasd` service, and everything seemed to be working fine. It continued to work fine until today (21 days later), when again the load spiked. `readynasd` and its `loadavg` thread was the culprit again. Entries stopped being written into the `/var/readynasd/loadavg.dat` file again.

I can't see anything interesting in any logs near the time of onset, and I wasn't making any particular use of the NAS at that time. I've restarted the `readynasd` service and things have returned to normal. I'd still appreciate any ideas of things to check or look out for when this next happens.

[BrianTopp]

Today I had a repeat of the problem, coming up to 25 days since I last restarted readynasd.

Anyone have any ideas?

[combathero32]

I have RN104 and having same problem when netgear updated the NAS to the latest version.  Hoping Netgear needs to release an update to fix the issue.

[BrianTopp]

Sorry to hear that @combathero32 . Likewise, I'm hoping for a fix, but in the meantime I'm working around the issue with a cron job. It runs every 15 mins and checks the time of the last entry in /var/readynasd/loadavg.dat. If that entry is older than 16 mins it emails me, so that I can I log in to restart the `readynasd` service. Coincidentally, it tripped for the first time in over a week just this morning.

[combathero32]

Thanks for the inputs @BrianTopp. I added shell script on cron.hourly directory to check loadavg updates and if it is outdated for an hour then the script will restart readynasd until Netgear found the fix for this one.

#!/bin/sh

if [ $(( $(date +%s) - $(stat -c "%Y" /var/readynasd/loadavg.dat) )) -gt 3600 ]; then
/bin/systemctl restart readynasd
fi

[Sandshark]

I never thought to look at a thread view when readynasd hit 100% during a scrub, but I now wonder if that's not also caused by loadavg that, once something holds it up too long from doing what it wants to, it just starts using more and more CPU stacking up pending operations.  I no longer run a NAS on which I have seen that issue, so I can't check.  But maybe this is the clue Netgear needs to finally find and fix the problem.

Unfortunately, though, I see no replies at all from a Netgear person.

[DSTMalo]

I'm bumping this thread in order to communicate that the problem still exists.

I am having this problem as well.

My firmware version is 6.10.3.

I can confirm that restarting readynasd with "service readynasd restart" will clear the problem without having to reboot the system.

[BrianTopp]

Another bump to report a runaway this morning. This was the first one on 6.10.4.

[combathero32]

I confirmed it as well the issue still persist even on the latest version 6.10.4