NETGEAR is aware of a growing number of phone and online scams. To learn how to stay safe click here.

Forum Discussion

Tinyhorns's avatar
Tinyhorns
Apprentice
May 31, 2017

Strange things in dmesg, but not in the logs.

Hi, I have notieced some strange stuff in my logs, that does not look good at all.

Firmware version is 6.7.3

 

The normal logs looks fine

 

Seen it 9 times since last reboot on the 25th of may.

dmesg -T |grep -c ata_scsi_port_error_handler
9

 

[Wed May 31 21:08:53 2017] ------------[ cut here ]------------
[Wed May 31 21:08:53 2017] WARNING: CPU: 3 PID: 923 at drivers/ata/libata-eh.c:3993 ata_eh_finish+0xcd/0xd0()
[Wed May 31 21:08:53 2017] Modules linked in: sx8635(O) vpd(PO)
[Wed May 31 21:08:53 2017] CPU: 3 PID: 923 Comm: scsi_eh_6 Tainted: P W O 4.4.68.x86_64.1 #1
[Wed May 31 21:08:53 2017] Hardware name: NETGEAR ReadyNAS 316 /ReadyNAS 316 , BIOS 4.6.5 03/23/2013
[Wed May 31 21:08:53 2017] 0000000000000000 ffff88007be17c40 ffffffff883d3e78 0000000000000000
[Wed May 31 21:08:53 2017] ffffffff88d32e85 ffff88007be17c78 ffffffff8806b27c ffff88007bcedd40
[Wed May 31 21:08:53 2017] ffff88007bcedd40 ffff88007bcec000 ffff88007bcec000 ffff88007bcef480
[Wed May 31 21:08:53 2017] Call Trace:
[Wed May 31 21:08:53 2017] [<ffffffff883d3e78>] dump_stack+0x4d/0x65
[Wed May 31 21:08:53 2017] [<ffffffff8806b27c>] warn_slowpath_common+0x7c/0xb0
[Wed May 31 21:08:53 2017] [<ffffffff8806b365>] warn_slowpath_null+0x15/0x20
[Wed May 31 21:08:53 2017] [<ffffffff8861df4d>] ata_eh_finish+0xcd/0xd0
[Wed May 31 21:08:53 2017] [<ffffffff88620710>] sata_pmp_error_handler+0x630/0xa20
[Wed May 31 21:08:53 2017] [<ffffffff88613930>] ? ata_phys_link_offline+0x30/0x30
[Wed May 31 21:08:53 2017] [<ffffffff88627e00>] ? sil24_pmp_attach+0x70/0x70
[Wed May 31 21:08:53 2017] [<ffffffff88627480>] ? sil24_pmp_hardreset+0x60/0x60
[Wed May 31 21:08:53 2017] [<ffffffff886137d0>] ? ata_phys_link_online+0x30/0x30
[Wed May 31 21:08:53 2017] [<ffffffff8809613c>] ? set_next_entity+0x6c/0x7d0
[Wed May 31 21:08:53 2017] [<ffffffff8862740a>] sil24_error_handler+0x2a/0x40
[Wed May 31 21:08:53 2017] [<ffffffff8861e380>] ata_scsi_port_error_handler+0x430/0x770
[Wed May 31 21:08:53 2017] [<ffffffff8861e74c>] ata_scsi_error+0x8c/0xc0
[Wed May 31 21:08:53 2017] [<ffffffff885c3166>] scsi_error_handler+0xa6/0x530
[Wed May 31 21:08:53 2017] [<ffffffff88a4d164>] ? __schedule+0x244/0x6f0
[Wed May 31 21:08:53 2017] [<ffffffff885c30c0>] ? scsi_eh_get_sense+0x150/0x150
[Wed May 31 21:08:53 2017] [<ffffffff885c30c0>] ? scsi_eh_get_sense+0x150/0x150
[Wed May 31 21:08:53 2017] [<ffffffff88085096>] kthread+0xe6/0x100
[Wed May 31 21:08:53 2017] [<ffffffff88084fb0>] ? kthread_create_on_node+0x170/0x170
[Wed May 31 21:08:53 2017] [<ffffffff88a5095f>] ret_from_fork+0x3f/0x70
[Wed May 31 21:08:53 2017] [<ffffffff88084fb0>] ? kthread_create_on_node+0x170/0x170
[Wed May 31 21:08:53 2017] ---[ end trace a4240c3bd081b390 ]---
[Wed May 31 21:08:53 2017] ata7: EH complete

Other Discussions

3 Replies

Replies have been turned off for this discussion
  • JennC's avatar
    JennC
    NETGEAR Employee Retired
    Jun 07, 2017

    Hello Tinyhorns,

     

    Have you checked if you get the same when updated to FW 6.7.4?

     

    Regards,

    • Tinyhorns's avatar
      Tinyhorns
      Apprentice
      Jun 08, 2017

      Hi JennC

      I do see the same thing after a fw-upgrade.

       

      [Wed Jun  7 12:48:59 2017] ------------[ cut here ]------------
      [Wed Jun  7 12:48:59 2017] WARNING: CPU: 1 PID: 924 at drivers/ata/libata-eh.c:3993 ata_eh_finish+0xcd/0xd0()
      [Wed Jun  7 12:48:59 2017] Modules linked in: sx8635(O) vpd(PO)
      [Wed Jun  7 12:48:59 2017] CPU: 1 PID: 924 Comm: scsi_eh_6 Tainted: P        W  O    4.4.68.x86_64.1 #1
      [Wed Jun  7 12:48:59 2017] Hardware name: NETGEAR ReadyNAS 316          /ReadyNAS 316          , BIOS 4.6.5 03/23/2013
      [Wed Jun  7 12:48:59 2017]  0000000000000000 ffff88007bcdfc40 ffffffff883d3e98 0000000000000000
      [Wed Jun  7 12:48:59 2017]  ffffffff88d32e85 ffff88007bcdfc78 ffffffff8806b27c ffff88007e72dd40
      [Wed Jun  7 12:48:59 2017]  ffff88007e72dd40 ffff88007e72c000 ffff88007e72c000 ffff88007e72f480
      [Wed Jun  7 12:48:59 2017] Call Trace:
      [Wed Jun  7 12:48:59 2017]  [<ffffffff883d3e98>] dump_stack+0x4d/0x65
      [Wed Jun  7 12:48:59 2017]  [<ffffffff8806b27c>] warn_slowpath_common+0x7c/0xb0
      [Wed Jun  7 12:48:59 2017]  [<ffffffff8806b365>] warn_slowpath_null+0x15/0x20
      [Wed Jun  7 12:48:59 2017]  [<ffffffff8861df6d>] ata_eh_finish+0xcd/0xd0
      [Wed Jun  7 12:48:59 2017]  [<ffffffff88620730>] sata_pmp_error_handler+0x630/0xa20
      [Wed Jun  7 12:48:59 2017]  [<ffffffff88613950>] ? ata_phys_link_offline+0x30/0x30
      [Wed Jun  7 12:48:59 2017]  [<ffffffff88627e20>] ? sil24_pmp_attach+0x70/0x70
      [Wed Jun  7 12:48:59 2017]  [<ffffffff886274a0>] ? sil24_pmp_hardreset+0x60/0x60
      [Wed Jun  7 12:48:59 2017]  [<ffffffff886137f0>] ? ata_phys_link_online+0x30/0x30
      [Wed Jun  7 12:48:59 2017]  [<ffffffff8809613c>] ? set_next_entity+0x6c/0x7d0
      [Wed Jun  7 12:48:59 2017]  [<ffffffff8862742a>] sil24_error_handler+0x2a/0x40
      [Wed Jun  7 12:48:59 2017]  [<ffffffff8861e3a0>] ata_scsi_port_error_handler+0x430/0x770
      [Wed Jun  7 12:48:59 2017]  [<ffffffff8861e76c>] ata_scsi_error+0x8c/0xc0
      [Wed Jun  7 12:48:59 2017]  [<ffffffff885c3186>] scsi_error_handler+0xa6/0x530
      [Wed Jun  7 12:48:59 2017]  [<ffffffff88a4d184>] ? __schedule+0x244/0x6f0
      [Wed Jun  7 12:48:59 2017]  [<ffffffff885c30e0>] ? scsi_eh_get_sense+0x150/0x150
      [Wed Jun  7 12:48:59 2017]  [<ffffffff885c30e0>] ? scsi_eh_get_sense+0x150/0x150
      [Wed Jun  7 12:48:59 2017]  [<ffffffff88085096>] kthread+0xe6/0x100
      [Wed Jun  7 12:48:59 2017]  [<ffffffff88084fb0>] ? kthread_create_on_node+0x170/0x170
      [Wed Jun  7 12:48:59 2017]  [<ffffffff88a5095f>] ret_from_fork+0x3f/0x70
      [Wed Jun  7 12:48:59 2017]  [<ffffffff88084fb0>] ? kthread_create_on_node+0x170/0x170
      [Wed Jun  7 12:48:59 2017] ---[ end trace dd154e7b97731a7b ]---

       

      // T

      • ggl's avatar
        ggl
        Aspirant
        Jun 09, 2017

        Having the same messages on a ReadyNAS 516 (with one EDA500) running latest firmware (6.7.4). Here's the full dmesg context:

         

        [Jun 9 15:28] ata9: illegal qc_active transition (00000000->00000002)
[ +0.009918] ata9.00: failed to read SCR 1 (Emask=0x40)
[ +0.000003] ata9.01: failed to read SCR 1 (Emask=0x40)
[ +0.000001] ata9.02: failed to read SCR 1 (Emask=0x40)
[ +0.000001] ata9.03: failed to read SCR 1 (Emask=0x40)
[ +0.000001] ata9.04: failed to read SCR 1 (Emask=0x40)
[ +0.000001] ata9.05: failed to read SCR 1 (Emask=0x40)
[ +0.000005] ata9.15: exception Emask 0x2 SAct 0x0 SErr 0x0 action 0x6 frozen
[ +0.000001] ata9.00: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
[ +0.000002] ata9.01: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
[ +0.000001] ata9.02: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
[ +0.000001] ata9.02: failed command: WRITE DMA EXT
[ +0.000003] ata9.02: cmd 35/00:80:40:52:f7/00:00:91:00:00/e0 tag 1 dma 65536 out
res 50/00:00:bf:52:f7/00:00:91:00:00/e0 Emask 0x100 (unknown error)
[ +0.000002] ata9.02: status: { DRDY }
[ +0.000001] ata9.03: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
[ +0.000001] ata9.04: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
[ +0.000001] ata9.04: failed command: WRITE DMA EXT
[ +0.000003] ata9.04: cmd 35/00:80:c0:17:f7/00:00:91:00:00/e0 tag 0 dma 65536 out
res 50/00:00:3f:18:f7/00:00:91:00:00/e0 Emask 0x100 (unknown error)
[ +0.000001] ata9.04: status: { DRDY }
[ +0.000001] ata9.05: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
[ +0.000003] ata9.15: hard resetting link
[ +2.120968] ata9.15: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
[ +0.000006] ata9.15: PMP revalidation failed (errno=-19)
[ +4.999743] ata9.15: hard resetting link
[ +2.132041] ata9.15: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
[ +0.000577] ata9.00: hard resetting link
[ +0.304716] ata9.00: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[ +0.000031] ata9.01: hard resetting link
[ +0.304933] ata9.01: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ +0.000031] ata9.02: hard resetting link
[ +0.305354] ata9.02: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ +0.000074] ata9.03: hard resetting link
[ +0.305745] ata9.03: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ +0.000057] ata9.04: hard resetting link
[ +0.304861] ata9.04: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ +0.000031] ata9.05: hard resetting link
[ +0.304778] ata9.05: SATA link up 1.5 Gbps (SStatus 113 SControl 320)
[ +0.010022] ata9.00: configured for UDMA/100
[ +0.009711] ata9.01: configured for UDMA/100
[ +0.009050] ata9.02: configured for UDMA/100
[ +0.007537] ata9.03: configured for UDMA/100
[ +0.009999] ata9.04: configured for UDMA/100
[ +0.000074] ------------[ cut here ]------------
[ +0.000005] WARNING: CPU: 3 PID: 1051 at drivers/ata/libata-eh.c:3993 ata_eh_finish+0xcd/0xd0()
[ +0.000001] Modules linked in: sx8635(O) vpd(PO)
[ +0.000004] CPU: 3 PID: 1051 Comm: scsi_eh_8 Tainted: P W O 4.4.68.x86_64.1 #1
[ +0.000001] Hardware name: NETGEAR ReadyNAS 516/ReadyNAS 516, BIOS 4.6.5 04/16/2013
[ +0.000001] 0000000000000000 ffff8800d5153c40 ffffffff883d3e98 0000000000000000
[ +0.000002] ffffffff88d32e85 ffff8800d5153c78 ffffffff8806b27c ffff880119df5d40
[ +0.000001] ffff880119df5d40 ffff880119df4000 ffff880119df4000 ffff880119df7480
[ +0.000001] Call Trace:
[ +0.000003] [<ffffffff883d3e98>] dump_stack+0x4d/0x65
[ +0.000002] [<ffffffff8806b27c>] warn_slowpath_common+0x7c/0xb0
[ +0.000002] [<ffffffff8806b365>] warn_slowpath_null+0x15/0x20
[ +0.000001] [<ffffffff8861df6d>] ata_eh_finish+0xcd/0xd0
[ +0.000002] [<ffffffff88620730>] sata_pmp_error_handler+0x630/0xa20
[ +0.000001] [<ffffffff88613950>] ? ata_phys_link_offline+0x30/0x30
[ +0.000002] [<ffffffff88627e20>] ? sil24_pmp_attach+0x70/0x70
[ +0.000002] [<ffffffff886274a0>] ? sil24_pmp_hardreset+0x60/0x60
[ +0.000001] [<ffffffff886137f0>] ? ata_phys_link_online+0x30/0x30
[ +0.000002] [<ffffffff8809613c>] ? set_next_entity+0x6c/0x7d0
[ +0.000002] [<ffffffff8862742a>] sil24_error_handler+0x2a/0x40
[ +0.000002] [<ffffffff8861e3a0>] ata_scsi_port_error_handler+0x430/0x770
[ +0.000001] [<ffffffff8861e76c>] ata_scsi_error+0x8c/0xc0
[ +0.000003] [<ffffffff885c3186>] scsi_error_handler+0xa6/0x530
[ +0.000002] [<ffffffff88a4d184>] ? __schedule+0x244/0x6f0
[ +0.000001] [<ffffffff885c30e0>] ? scsi_eh_get_sense+0x150/0x150
[ +0.000002] [<ffffffff885c30e0>] ? scsi_eh_get_sense+0x150/0x150
[ +0.000002] [<ffffffff88085096>] kthread+0xe6/0x100
[ +0.000002] [<ffffffff88084fb0>] ? kthread_create_on_node+0x170/0x170
[ +0.000002] [<ffffffff88a5095f>] ret_from_fork+0x3f/0x70
[ +0.000001] [<ffffffff88084fb0>] ? kthread_create_on_node+0x170/0x170
[ +0.000001] ---[ end trace b98d4729235a7b6e ]---
[ +0.000006] ata9: EH complete

        I don't remember seing those before a few days ago, I believe (but don't take my word for it).

         

        Cheers.

         

NETGEAR Academy

Boost your skills with the Netgear Academy - Get trained, certified and stay ahead with the latest Netgear technology! 

Join Us!

ProSupport for Business

Comprehensive support plans for maximum network uptime and business peace of mind.

 

Learn More