6.5.0 crashing on readynas 314

[wittynethandle]

I have a readynas 314 with and expansion chasis, and recently (since the 6.5.0 update) it has been crashing every 1-2 weeks or so.  The logs don't indicate anything.  Any tips on trying to troubleshoot this?  Is it possible to go back to 6.4?  It may be an old version, but at least it was stable.

Thu Jun 16 2016 22:26:40

System: ReadyNASOS background service started.

Thu Jun 16 2016 22:26:37

System: ReadyNASOS service or process was restarted.

Thu Jun 16 2016 0:14:15

snapshot: Snapshot prune worker successfully deleted snapshot 2016_05_19__00_00_39 from share or LUN Data.

[wittynethandle]

I don't see an edit button, so...

Digging around kernel.log in the downloaded logs, I see a lot of:

Jun 16 21:09:43 MordorNAS kernel: [572374.151548] ------------[ cut here ]------------
Jun 16 21:09:43 MordorNAS kernel: [572374.151568] WARNING: CPU: 1 PID: 848 at drivers/ata/libata-eh.c:3985 ata_eh_finish+0xbb/0xc0()
Jun 16 21:09:43 MordorNAS kernel: [572374.151575] Modules linked in: vpd(PO)
Jun 16 21:09:43 MordorNAS kernel: [572374.151587] CPU: 1 PID: 848 Comm: scsi_eh_4 Tainted: P        W  O    4.1.21.x86_64.1 #1
Jun 16 21:09:43 MordorNAS kernel: [572374.151592] Hardware name: NETGEAR ReadyNAS 314/To be filled by O.E.M., BIOS 4.6.5 11/05/2013
Jun 16 21:09:43 MordorNAS kernel: [572374.151596]  0000000000000000 ffff88007e6efbf8 ffffffff889b0fe5 0000000000000000
Jun 16 21:09:43 MordorNAS kernel: [572374.151604]  ffffffff88c577de ffff88007e6efc38 ffffffff8806867d ffff88007e6efc38
Jun 16 21:09:43 MordorNAS kernel: [572374.151610]  0000000000000020 ffff88007b9a0000 0000000000000000 ffff88007b9a0000
Jun 16 21:09:43 MordorNAS kernel: [572374.151618] Call Trace:
Jun 16 21:09:43 MordorNAS kernel: [572374.151630]  [<ffffffff889b0fe5>] dump_stack+0x4d/0x63
Jun 16 21:09:43 MordorNAS kernel: [572374.151639]  [<ffffffff8806867d>] warn_slowpath_common+0x8d/0xd0
Jun 16 21:09:43 MordorNAS kernel: [572374.151645]  [<ffffffff880686d5>] warn_slowpath_null+0x15/0x20
Jun 16 21:09:43 MordorNAS kernel: [572374.151652]  [<ffffffff885f064b>] ata_eh_finish+0xbb/0xc0
Jun 16 21:09:43 MordorNAS kernel: [572374.151659]  [<ffffffff885f3073>] sata_pmp_error_handler+0x673/0xb00
Jun 16 21:09:43 MordorNAS kernel: [572374.151665]  [<ffffffff885e55b0>] ? sata_std_hardreset+0x40/0x40
Jun 16 21:09:43 MordorNAS kernel: [572374.151673]  [<ffffffff885f9750>] ? ahci_pmp_retry_softreset+0xf0/0xf0
Jun 16 21:09:43 MordorNAS kernel: [572374.151679]  [<ffffffff885f8620>] ? ahci_dev_classify+0x50/0x50
Jun 16 21:09:43 MordorNAS kernel: [572374.151685]  [<ffffffff885f7820>] ? ahci_pmp_attach+0x80/0x80
Jun 16 21:09:43 MordorNAS kernel: [572374.151692]  [<ffffffff885f856c>] ahci_error_handler+0x2c/0x90
Jun 16 21:09:43 MordorNAS kernel: [572374.151699]  [<ffffffff885f0b60>] ata_scsi_port_error_handler+0x510/0x8c0
Jun 16 21:09:43 MordorNAS kernel: [572374.151706]  [<ffffffff885f0fa3>] ata_scsi_error+0x93/0xd0
Jun 16 21:09:43 MordorNAS kernel: [572374.151715]  [<ffffffff885a0754>] scsi_error_handler+0xb4/0x560
Jun 16 21:09:43 MordorNAS kernel: [572374.151722]  [<ffffffff885a06a0>] ? scsi_eh_get_sense+0x180/0x180
Jun 16 21:09:43 MordorNAS kernel: [572374.151728]  [<ffffffff885a06a0>] ? scsi_eh_get_sense+0x180/0x180
Jun 16 21:09:43 MordorNAS kernel: [572374.151736]  [<ffffffff88082624>] kthread+0xc4/0xe0
Jun 16 21:09:43 MordorNAS kernel: [572374.151743]  [<ffffffff88082560>] ? __kthread_parkme+0x80/0x80
Jun 16 21:09:43 MordorNAS kernel: [572374.151751]  [<ffffffff889b9012>] ret_from_fork+0x42/0x70
Jun 16 21:09:43 MordorNAS kernel: [572374.151757]  [<ffffffff88082560>] ? __kthread_parkme+0x80/0x80
Jun 16 21:09:43 MordorNAS kernel: [572374.151762] ---[ end trace 52a6b8b807344481 ]---

I don't understand what it means and the last instance was over an hour before the NAS crashed, but it a warning and a stack trace don't sound good.

[mdgm-ntgr]

Downgrades from 6.5.0 are not supported.

Have you contacted support? Can you send in your logs (see the Sending Logs link in my sig)?

[wittynethandle]

I've generally had such poor support from official support (ha!) channels (no experience with Netgear, but just overall) that I didn't even think about it.  I'll contact them.  In the meantime, logs from a little after the latest crash have been sent.

[Danthem]

Came across your case and had a look through the logs.

Probably the cable between EDA and NAS acting up, looks like the NAS loses connection to all of the EDA disks at the same time and then tries to hard-reset the link for all of them at the same time, eventually it crashes. 

Jun 16 21:09:40 MordorNAS kernel: [572371.575654] ata5.00: failed to read SCR 1 (Emask=0x40)
Jun 16 21:09:40 MordorNAS kernel: [572371.575664] ata5.01: failed to read SCR 1 (Emask=0x40)
Jun 16 21:09:40 MordorNAS kernel: [572371.575670] ata5.02: failed to read SCR 1 (Emask=0x40)
Jun 16 21:09:40 MordorNAS kernel: [572371.575674] ata5.03: failed to read SCR 1 (Emask=0x40)
Jun 16 21:09:40 MordorNAS kernel: [572371.575680] ata5.04: failed to read SCR 1 (Emask=0x40)
Jun 16 21:09:40 MordorNAS kernel: [572371.575684] ata5.05: failed to read SCR 1 (Emask=0x40)

Jun 16 21:09:40 MordorNAS kernel: [572371.575693] ata5.15: exception Emask 0x4 SAct 0x0 SErr 0x0 action 0x6 frozen
Jun 16 21:09:41 MordorNAS kernel: [572371.575699] ata5.00: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
Jun 16 21:09:41 MordorNAS kernel: [572371.575705] ata5.01: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
Jun 16 21:09:41 MordorNAS kernel: [572371.575711] ata5.02: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
Jun 16 21:09:41 MordorNAS kernel: [572371.575717] ata5.03: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
Jun 16 21:09:41 MordorNAS kernel: [572371.575722] ata5.03: failed command: READ DMA EXT
Jun 16 21:09:41 MordorNAS kernel: [572371.575732] ata5.03: cmd 25/00:40:80:25:62/00:05:d1:01:00/e0 tag 5 dma 688128 in
Jun 16 21:09:41 MordorNAS kernel: [572371.575732]          res 40/00:01:00:4f:c2/00:00:00:00:00/00 Emask 0x4 (timeout)
Jun 16 21:09:41 MordorNAS kernel: [572371.575738] ata5.03: status: { DRDY }
Jun 16 21:09:41 MordorNAS kernel: [572371.575743] ata5.04: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
Jun 16 21:09:41 MordorNAS kernel: [572371.575749] ata5.05: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen

Either cable or expansion chassis, I'd try to replace the cable myself first.. Just a standard eSATA cable. If that doesn't help it may come down to an RMA of the EDA.

Edit: Actually first of all make sure the cable is properly seated hehe

[wittynethandle]

Thanks. The support case I opened at the suggestion of mdgm has led to the same suggestion.  I've ordered a new cable, so it will be a little bit of a wait to see if that fixes the problem.

[wittynethandle]

So this isn't left unresolved, here is the final answer such as it is. Swapping cables and EDA units did not fix the issue. Eventually support was able to reproduce the crash, but they could not give me an estimate as to when a fix would be issued. At the point where I gave up waiting and started migration to an alternate system, I was on 6.5.1.