6.9.3 rc1 kernel errors, won't shutdowns, resyncs

TeknoJnky · ‎2018-02-15

Ok, I did *not* experience any (known) issues with this again on t223, but since installing rc1 it has has happened again twice.

load averages goes 20+, can't seem to write to shares, device won't fully shutdown and reboot properly, resync after power off/power on.

Below is a couple days dmesg log capture, and I have downloaded all logs and sending to nsbu along with full log of partial below

I recently replaced a drive that failed with no advance errors or warnings. While I guess it may be possible another drive is failing the same manner, it is very suspicous.

Since I am apparently the only one posting on this issue, I guess it could be specific to my system.

I don't know if plex is a contributer or cause (plex dvr & transcoding relatively heavy workloads), or perhaps recently installled zerotier.

I do have another spare drive ready, if something actually identifies another failing drive.

Eitherw way; Potentially failing drive, or bad app, the system is not handling it very well.

[Feb14 22:23] Initializing cgroup subsys cpuset
[  +0.000000] Initializing cgroup subsys cpu

full dmsesg log attached
[  +0.568063] Process accounting resumed
[  +0.860147] ixgbe 0000:03:00.0 eth0: NIC Link is Up 1 Gbps, Flow Control: RX/TX
[  +0.077971] bond0: link status definitely up for interface eth0, 1000 Mbps full duplex
[  +0.000009] bond0: now running without any active interface!
[  +0.100045] IPv6: ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready
[  +1.196409] ixgbe 0000:03:00.1 eth1: NIC Link is Up 1 Gbps, Flow Control: RX/TX
[  +0.003615] bond0: link status definitely up for interface eth1, 1000 Mbps full duplex
[  +5.097762] traps: leafp2p[6511] general protection ip:7f90bd04bc04 sp:7f90bb563bd8 error:0 in libc-2.19.so[7f90bcfb5000+1a1000]
[Feb14 22:26] traps: leafp2p[6878] general protection ip:7f90bd04bc04 sp:7f90bb563bd8 error:0 in libc-2.19.so[7f90bcfb5000+1a1000]
[  +5.024358] traps: leafp2p[6950] general protection ip:7f90bd04bc04 sp:7f90bb563bd8 error:0 in libc-2.19.so[7f90bcfb5000+1a1000]
[  +3.214354] nfsd: last server has exited, flushing export cache
[  +0.144560] NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory
[  +0.000025] NFSD: starting 90-second grace period (net ffffffff88f2f680)
[  +6.649802] traps: leafp2p[8543] general protection ip:7f90bd04bc04 sp:7f90bb563bd8 error:0 in libc-2.19.so[7f90bcfb5000+1a1000]
[Feb15 00:00] Process accounting resumed
[Feb15 18:52] BUG: unable to handle kernel NULL pointer dereference at           (null)
[  +0.008421] IP: [<ffffffff883b3944>] async_memcpy+0x1b4/0x350
[  +0.006222] PGD 8000000400740067 PUD 400741067 PMD 0 
[  +0.005554] Oops: 0002 [#1] SMP 
[  +0.065336] Modules linked in: vpd(PO)
[  +0.004103] CPU: 0 PID: 2509 Comm: md126_raid6 Tainted: P           O    4.4.112.x86_64.1 #1
[  +0.009113] Hardware name: NETGEAR ReadyNAS 528X/ReadyNAS 528X, BIOS RN528v21 10/14/2016
[  +0.008556] task: ffff88046cf34680 ti: ffff880465560000 task.ti: ffff880465560000
[  +0.007802] RIP: 0010:[<ffffffff883b3944>]  [<ffffffff883b3944>] async_memcpy+0x1b4/0x350
[  +0.008486] RSP: 0018:ffff880465563a10  EFLAGS: 00010246
[  +0.005556] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  +0.007343] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000000000000a
[  +0.007254] RBP: ffff880465563a60 R08: 0000000000001000 R09: ffff880465563aa0
[  +0.007394] R10: 0000000000000000 R11: 0000000000001000 R12: 0000000000001000
[  +0.007393] R13: ffff880465563aa0 R14: 0000000000000000 R15: 00000000000000c7
[  +0.007452] FS:  0000000000000000(0000) GS:ffff88047fc00000(0000) knlGS:0000000000000000
[  +0.008404] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  +0.006002] CR2: 0000000000000000 CR3: 00000003ffeb2000 CR4: 0000000000360670
[  +0.007366] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  +0.007428] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[  +0.007443] Stack:
[  +0.002049]  0000000000000000 ffffea00045a8cc0 ffffea001162bc40 0000000000000000
[  +0.007790]  0000000000000000 0000000000001000 0000000000039000 0000000000000000
[  +0.007828]  00000000000000c7 00000000000000c7 ffff880465563af0 ffffffff88882218
[  +0.007816] Call Trace:
[  +0.002563]  [<ffffffff88882218>] async_copy_data.isra.45+0x138/0x290
[  +0.006624]  [<ffffffff8888551c>] raid_run_ops+0x74c/0x1540
[  +0.005764]  [<ffffffff8887fb12>] ? ops_run_io+0x32/0x7f0
[  +0.005683]  [<ffffffff888898b4>] handle_stripe+0xa74/0x2630
[  +0.005893]  [<ffffffff8809655d>] ? pick_next_entity+0xad/0x190
[  +0.006227]  [<ffffffff8888b5df>] handle_active_stripes.isra.55+0x16f/0x460
[  +0.007286]  [<ffffffff880a362f>] ? __wake_up+0x3f/0x50
[  +0.005478]  [<ffffffff8888bce9>] raid5d+0x419/0x6a0
[  +0.005128]  [<ffffffff88a7199c>] ? schedule_timeout+0x13c/0x1a0
[  +0.006238]  [<ffffffff88892936>] md_thread+0x126/0x130
[  +0.005393]  [<ffffffff880a3ad0>] ? wait_woken+0x80/0x80
[  +0.005603]  [<ffffffff88892810>] ? md_wait_for_blocked_rdev+0x100/0x100
[  +0.006909]  [<ffffffff88089356>] kthread+0xe6/0x100
[  +0.005190]  [<ffffffff88089270>] ? kthread_create_on_node+0x170/0x170
[  +0.006849]  [<ffffffff88a72a7f>] ret_from_fork+0x3f/0x70
[  +0.005668]  [<ffffffff88089270>] ? kthread_create_on_node+0x170/0x170
[  +0.006804] Code: 00 00 d3 e0 83 e8 01 09 da 48 98 4c 09 e2 48 85 c2 0f 84 d2 fe ff ff 8b 45 d0 48 89 45 d0 f6 05 d4 9f b9 00 04 0f 85 44 01 00 00 <49> 8d 7d 08 e8 23 fd ff ff 65 48 8b 04 25 80 d5 00 00 83 80 6c 
[  +0.021446] RIP  [<ffffffff883b3944>] async_memcpy+0x1b4/0x350
[  +0.006123]  RSP <ffff880465563a10>
[  +0.003638] CR2: 0000000000000000
[  +0.003498] ---[ end trace bc7e8dd9cd6d8a0d ]---
[  +0.004782] ------------[ cut here ]------------
[  +0.004834] WARNING: CPU: 0 PID: 2509 at kernel/exit.c:661 do_exit+0x43/0xaa0()
[  +0.007597] Modules linked in: vpd(PO)
[  +0.003922] CPU: 0 PID: 2509 Comm: md126_raid6 Tainted: P      D    O    4.4.112.x86_64.1 #1
[  +0.008754] Hardware name: NETGEAR ReadyNAS 528X/ReadyNAS 528X, BIOS RN528v21 10/14/2016
[  +0.008412]  0000000000000000 ffff880465563758 ffffffff883ec2a8 0000000000000000
[  +0.007811]  ffffffff88cff2e6 ffff880465563790 ffffffff8806f3ac ffff88046cf34680
[  +0.007763]  0000000000000009 0000000000000046 ffff88046cf34680 0000000000000000
[  +0.007803] Call Trace:
[  +0.002562]  [<ffffffff883ec2a8>] dump_stack+0x4d/0x65
[  +0.005302]  [<ffffffff8806f3ac>] warn_slowpath_common+0x7c/0xb0
[  +0.006269]  [<ffffffff8806f495>] warn_slowpath_null+0x15/0x20
[  +0.006119]  [<ffffffff880715e3>] do_exit+0x43/0xaa0
[  +0.005175]  [<ffffffff88007284>] oops_end+0x84/0xc0
[  +0.005209]  [<ffffffff8803b00d>] no_context+0x11d/0x2f0
[  +0.005562]  [<ffffffff88097491>] ? update_curr+0xa1/0xd0
[  +0.005644]  [<ffffffff8803b2fb>] __bad_area_nosemaphore+0x11b/0x230
[  +0.006615]  [<ffffffff88132e60>] ? unfreeze_partials.isra.61+0x50/0x190
[  +0.006918]  [<ffffffff8803b41e>] bad_area_nosemaphore+0xe/0x10
[  +0.006132]  [<ffffffff8803b663>] __do_page_fault+0x73/0x350
[  +0.005880]  [<ffffffff8803b97c>] do_page_fault+0xc/0x10
[  +0.005580]  [<ffffffff88a74172>] page_fault+0x22/0x30
[  +0.005347]  [<ffffffff883b3944>] ? async_memcpy+0x1b4/0x350
[  +0.005962]  [<ffffffff88882218>] async_copy_data.isra.45+0x138/0x290
[  +0.006713]  [<ffffffff8888551c>] raid_run_ops+0x74c/0x1540
[  +0.005761]  [<ffffffff8887fb12>] ? ops_run_io+0x32/0x7f0
[  +0.005542]  [<ffffffff888898b4>] handle_stripe+0xa74/0x2630
[  +0.005899]  [<ffffffff8809655d>] ? pick_next_entity+0xad/0x190
[  +0.006189]  [<ffffffff8888b5df>] handle_active_stripes.isra.55+0x16f/0x460
[  +0.007252]  [<ffffffff880a362f>] ? __wake_up+0x3f/0x50
[  +0.005452]  [<ffffffff8888bce9>] raid5d+0x419/0x6a0
[  +0.005200]  [<ffffffff88a7199c>] ? schedule_timeout+0x13c/0x1a0
[  +0.006270]  [<ffffffff88892936>] md_thread+0x126/0x130
[  +0.005421]  [<ffffffff880a3ad0>] ? wait_woken+0x80/0x80
[  +0.005516]  [<ffffffff88892810>] ? md_wait_for_blocked_rdev+0x100/0x100
[  +0.006915]  [<ffffffff88089356>] kthread+0xe6/0x100
[  +0.005229]  [<ffffffff88089270>] ? kthread_create_on_node+0x170/0x170
[  +0.006760]  [<ffffffff88a72a7f>] ret_from_fork+0x3f/0x70
[  +0.005641]  [<ffffffff88089270>] ? kthread_create_on_node+0x170/0x170
[  +0.006825] ---[ end trace bc7e8dd9cd6d8a0e ]---
[Feb15 19:09] nfsd: last server has exited, flushing export cache
[Feb15 19:12] systemd[1]: systemd-journald.service: Main process exited, code=killed, status=6/ABRT
[  +0.009202] systemd[1]: systemd-journald.service: Unit entered failed state.
[  +0.007129] systemd[1]: systemd-journald.service: Failed with result 'signal'.
[  +0.007690] systemd[1]: systemd-journald.service: Service has no hold-off time, scheduling restart.
[Feb15 19:15] systemd[1]: fvapp-plexpy.service: Processes still around after SIGKILL. Ignoring.
[Feb15 19:19] systemd[1]: fvapp-plexpy.service: State 'stop-final-sigterm' timed out. Killing.
[Feb15 19:22] systemd[1]: fvapp-plexpy.service: Processes still around after final SIGKILL. Entering failed mode.
[  +0.010216] systemd[1]: Stopped Service for plexpy app.
[  +0.011385] systemd[1]: fvapp-plexpy.service: Unit entered failed state.
[  +0.006723] systemd[1]: fvapp-plexpy.service: Failed with result 'timeout'.
[  +0.007050] systemd[1]: Stopped target Basic System.
[  +0.011322] systemd[1]: Stopped target Paths.
[  +0.009119] systemd[1]: Stopped Forward Password Requests to Wall Directory Watch.
[  +0.014940] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.
[  +0.016974] systemd[1]: Stopped target Slices.
[  +0.009052] systemd[1]: Removed slice User and Session Slice.
[  +0.011979] systemd[1]: Stopped target Sockets.
[  +0.009000] systemd[1]: Closed Avahi mDNS/DNS-SD Stack Activation Socket.
[  +0.013905] systemd[1]: Closed RPCbind Server Activation Socket.
[  +0.012024] systemd[1]: Closed D-Bus System Message Bus Socket.
[  +0.012023] systemd[1]: Stopped target System Initialization.
[  +0.012638] systemd[1]: Stopped Apply Kernel Variables.
[  +0.011441] systemd[1]: Stopped target Encrypted Volumes.
[  +0.012661] systemd[1]: Stopped Load Kernel Modules.
[  +0.011697] systemd[1]: Stopped Create Volatile Files and Directories.
[  +0.014028] systemd[1]: Stopped Flush Journal to Persistent Storage.
[  +0.013484] systemd[1]: Stopping Flush Journal to Persistent Storage...
[  +0.013088] systemd[1]: Stopped Journal Service.
[  +0.014027] systemd[1]: Starting Journal Service...
[  +0.010002] systemd[1]: Stopped target Local File Systems.
[  +0.020037] systemd[1]: Unmounting /run/nfs4/data/securitycam...
[  +0.012285] systemd[1]: Unmounting /data...
[  +0.007962] systemd[1]: Unmounting /run/nfs4/home...
[  +0.010000] systemd[1]: Unmounting /var/ftp/securitycam...
[  +0.011271] systemd[1]: Stopped Rebuild Hardware Database.
[  +0.023437] systemd[1]: Stopping Load/Save Random Seed...
[  +0.009919] systemd[1]: Stopped target Swap.
[  +0.018985] systemd[1]: Deactivating swap md1...
[  +0.011412] systemd[1]: Unmounted /run/nfs4/data/securitycam.
[  +0.011710] systemd[1]: data.mount: Mount process exited, code=exited status=32
[  +0.007389] systemd[1]: Failed unmounting /data.
[  +0.009790] systemd[1]: Unmounted /run/nfs4/home.
[  +0.009962] systemd[1]: Unmounted /var/ftp/securitycam.
[  +0.012381] systemd[1]: Stopped Load/Save Random Seed.
[  +0.011735] systemd[1]: Deactivated swap md1.
[  +0.009053] systemd[1]: Deactivated swap /dev/md/1.
[  +0.010737] systemd[1]: Deactivated swap /dev/disk/by-uuid/b04e9029-acbd-4f3d-a001-e957dd302a60.
[  +0.017861] systemd[1]: Deactivated swap /dev/disk/by-label/swap.
[  +0.012008] systemd[1]: Deactivated swap /dev/disk/by-id/md-uuid-ced94d60:2cdec2d6:48e474e8:f9577416.
[  +0.018050] systemd[1]: Deactivated swap /dev/disk/by-id/md-name-2fe75b38:1.
[  +0.018250] systemd[1]: Reached target Unmount All Filesystems.
[  +0.011656] systemd[1]: Stopped target Local File Systems (Pre).
[  +0.012538] systemd[1]: Stopped Remount Root and Kernel File Systems.
[  +0.014241] systemd[1]: Stopped Create Static Device Nodes in /dev.
[  +0.014254] systemd[1]: Reached target Shutdown.
[  +0.009039] systemd[1]: Reached target Final Step.
[  +0.012031] systemd[1]: Starting Reboot...
[  +0.008826] systemd[1]: Shutting down.

StephenB · ‎2018-02-16

Is this happening on the RN528, or is it happening on legacy x86 ReadyNAS?

TeknoJnky · ‎2018-02-16

528

OOM-9 · ‎2018-02-20

I did not see the logs. Can you resend them, or let me know if there was a different subject that you might have used?

Did you have AV enabled by chance? There were some odd behavior that we are working to resolve in RC2 that is related to AV.

TeknoJnky · ‎2018-02-20

Hi Thanks, I resent with updated for this thread subject (previously sent with older thread subject).

was not using AV

thanks for the time to check.

OOM-9 · ‎2018-02-21

We are looking into the logs to see if there we are able to narrow down where this issue might be coming from.

There is a kernel update that we made that may make a difference in RC2. In the meantime, you can try that version to see if it helps.

6.9.3 rc1 kernel errors, won't shutdowns, resyncs

6.9.3 rc1 kernel errors, won't shutdowns, resyncs

Re: 6.9.3 rc1 kernel errors, won't shutdowns, resyncs

Re: 6.9.3 rc1 kernel errors, won't shutdowns, resyncs

Re: 6.9.3 rc1 kernel errors, won't shutdowns, resyncs

Re: 6.9.3 rc1 kernel errors, won't shutdowns, resyncs

Re: 6.9.3 rc1 kernel errors, won't shutdowns, resyncs