Same Call Trace as in 6.5.0 diagnostics attached

Adding this link for reference:

https://www.spinics.net/lists/netdev/msg488986.html

 

I emailed the developer with full stack trace, let's see if he replies.

Got a reply:

Quote

Known problem, patch was submitted last week.

https://patchwork.ozlabs.org/patch/886324/

This should reach stable versions soon.

 

A kernel patch release (4.14.29)  was published today but this patch is not yet included.  Let's give it a couple more days.

I'll stay on 6.4.1 until it comes out. 

How do I know when the patch will be implemented in unRAID? It will be included in the next rc?

 

Thank You.

You'll know when this report gets marked 'solved'.

Reading that link about the patch...

 

The linux guys introduced at some point a patch to purge the TCP write queue when a TCP session is reset (RST), but forgot to reset the send part, which can result in a NULL pointer dereference.

 

Sending a TCP RST command is quite common to restart a TCP session, can happen when for instance both parties get out of sync due to heavy and/or missing traffic and decide to start over again. Perhaps people experiencing the call traces see this happening when heavy downloading/uploading is taking place?

 

Amazing how easy it is to introduce bugs in s/w that's been in use forever.

Happened to me this morning with the Plex docker.  One local stream, so not particularly heavy traffic.  No other downloads/uploads from my other services.

 

burns-diagnostics-20180322-0744.zip

6 hours ago, Bobat said:

One local stream, so not particularly heavy traffic.

 

Which browser are you using the view Plex streams?

 

Microsoft browers are known to use RST (reset) quite often when something goes wrong in the communication, e.g. missing packet. Perhaps viewing with a different browser gives better results?

The client was a Roku box hooked up to my TV, so no browser involved.

I've used firefox and chrome yesterday. It crashed while using the Samsung TV.

However as I mentioned there are users experiencing this without even having plex installed.

19 minutes ago, Bobat said:

The client was a Roku box hooked up to my TV, so no browser involved.

 

It was a short in the dark, didn't know what client you were using.

11 minutes ago, andreidelait said:

I've used firefox and chrome yesterday. It crashed while using the Samsung TV.

However as I mentioned there are users experiencing this without even having plex installed.

 

It is also my believe that the issue is not related to a specific application, but a general communication issue (lots of applications use TCP to communicate).

 

Yeah, on my server it's Emby and privoxy which are affected. Sometimes when the call trace shows up in the log everything is working like it should, other times it crashes and I have to restart the container to get it to work again.

Its caused weird situations to the Emby container in my case. the EmbyServer process is left stuck in the D state (waiting for I/O) and impossible to kill - I gave it +12hours idle time and it still didn't unblock and unRAID had to force reboot itself in the end. This happened to me twice. So I rolled back to 6.4.1

in my case im not using Plex in Docker, but Tvheadend and same issue I was forced to back to 6.4.1

Edited March 23, 2018 by piotrasd

This should be solved, we'll re-open if not.

Changed Status to Solved

Changed Version to 6.5.1-rc2

Changed Priority to Minor

On 3/23/2018 at 8:41 PM, limetech said:

Changed Status to Solved

Changed Version to 6.5.1-rc2

Changed Priority to Minor

Thanks I haven't had a single call trace for Emby Server since 6.5.1-rc2

Apr 12 13:26:15 husky kernel: emhttpd: page allocation stalls for 16951ms, order:0, mode:0x14200ca(GFP_HIGHUSER_MOVABLE), nodemask=(null)
Apr 12 13:26:15 husky kernel: emhttpd cpuset=/ mems_allowed=0
Apr 12 13:26:15 husky kernel: CPU: 2 PID: 7250 Comm: emhttpd Not tainted 4.14.31-unRAID #1
Apr 12 13:26:15 husky kernel: Hardware name: MSI MS-7752/Z77A-G45 (MS-7752), BIOS V2.12 09/29/2013
Apr 12 13:26:15 husky kernel: Call Trace:
Apr 12 13:26:15 husky kernel: dump_stack+0x5d/0x79
Apr 12 13:26:15 husky kernel: warn_alloc+0xdf/0x160
Apr 12 13:26:15 husky kernel: ? wakeup_kswapd+0x2c/0xb2
Apr 12 13:26:15 husky kernel: __alloc_pages_nodemask+0x578/0xb03
Apr 12 13:26:15 husky kernel: ? kmem_cache_alloc+0xde/0xea
Apr 12 13:26:15 husky kernel: alloc_pages_vma+0x146/0x16d
Apr 12 13:26:15 husky kernel: shmem_alloc_page+0x60/0x7e
Apr 12 13:26:15 husky kernel: ? get_mem_cgroup_from_mm+0x82/0x88
Apr 12 13:26:15 husky kernel: ? memcg_kmem_get_cache+0x55/0x170
Apr 12 13:26:15 husky kernel: ? kmem_cache_alloc+0xde/0xea
Apr 12 13:26:15 husky kernel: ? put_dec+0x24/0x64
Apr 12 13:26:15 husky kernel: ? number+0x135/0x230
Apr 12 13:26:15 husky kernel: ? attach_recursive_mnt+0x1eb/0x251
Apr 12 13:26:15 husky kernel: ? __percpu_counter_compare+0x23/0x69
Apr 12 13:26:15 husky kernel: shmem_alloc_and_acct_page+0xf4/0x17e
Apr 12 13:26:15 husky kernel: shmem_getpage_gfp.isra.5+0x485/0x9c4
Apr 12 13:26:15 husky kernel: ? seq_put_decimal_ull+0x72/0x88
Apr 12 13:26:15 husky kernel: ? xattr_resolve_name+0xb/0x99
Apr 12 13:26:15 husky kernel: shmem_getpage+0x15/0x17
Apr 12 13:26:15 husky kernel: generic_perform_write+0xa4/0x170
Apr 12 13:26:15 husky kernel: ? file_update_time+0x31/0xc3
Apr 12 13:26:15 husky kernel: __generic_file_write_iter+0x12c/0x16c
Apr 12 13:26:15 husky kernel: generic_file_write_iter+0x11a/0x15c
Apr 12 13:26:15 husky kernel: __vfs_write+0xe1/0x109
Apr 12 13:26:15 husky kernel: vfs_write+0xc3/0x166
Apr 12 13:26:15 husky kernel: SyS_write+0x48/0x81
Apr 12 13:26:15 husky kernel: do_syscall_64+0x6d/0xfe
Apr 12 13:26:15 husky kernel: entry_SYSCALL_64_after_hwframe+0x3d/0xa2
Apr 12 13:26:15 husky kernel: RIP: 0033:0x147183160447
Apr 12 13:26:15 husky kernel: RSP: 002b:0000147182834d80 EFLAGS: 00000293 ORIG_RAX: 0000000000000001
Apr 12 13:26:15 husky kernel: RAX: ffffffffffffffda RBX: 0000000000000007 RCX: 0000147183160447
Apr 12 13:26:15 husky kernel: RDX: 0000000000000071 RSI: 0000147174001500 RDI: 0000000000000007
Apr 12 13:26:15 husky kernel: RBP: 0000147174001500 R08: 0000000000000000 R09: 0000147174002870
Apr 12 13:26:15 husky kernel: R10: 000014717400127e R11: 0000000000000293 R12: 0000000000000071
Apr 12 13:26:15 husky kernel: R13: 0000000000000071 R14: 00001471834352a0 R15: 0000147183434760
Apr 12 13:26:15 husky kernel: Mem-Info:
Apr 12 13:26:15 husky kernel: active_anon:146319 inactive_anon:7863 isolated_anon:0
Apr 12 13:26:15 husky kernel: active_file:13839 inactive_file:701452 isolated_file:0
Apr 12 13:26:15 husky kernel: unevictable:0 dirty:16760 writeback:0 unstable:0
Apr 12 13:26:15 husky kernel: slab_reclaimable:30044 slab_unreclaimable:12300
Apr 12 13:26:15 husky kernel: mapped:26197 shmem:114087 pagetables:2431 bounce:0
Apr 12 13:26:15 husky kernel: free:35904 free_pcp:567 free_cma:0
Apr 12 13:26:15 husky kernel: Node 0 active_anon:585276kB inactive_anon:31452kB active_file:55356kB inactive_file:2805808kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:104788kB dirty:67040kB writeback:0kB shmem:456348kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 81920kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
Apr 12 13:26:15 husky kernel: Node 0 DMA free:15456kB min:556kB low:692kB high:828kB active_anon:0kB inactive_anon:0kB active_file:16kB inactive_file:412kB unevictable:0kB writepending:0kB present:15984kB managed:15900kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
Apr 12 13:26:15 husky kernel: lowmem_reserve[]: 0 3296 3733 3733
Apr 12 13:26:15 husky kernel: Node 0 DMA32 free:116112kB min:118856kB low:148568kB high:178280kB active_anon:230368kB inactive_anon:23304kB active_file:52060kB inactive_file:2786896kB unevictable:0kB writepending:65568kB present:3540548kB managed:3461600kB mlocked:0kB kernel_stack:3312kB pagetables:5848kB bounce:0kB free_pcp:2136kB local_pcp:672kB free_cma:0kB
Apr 12 13:26:15 husky kernel: lowmem_reserve[]: 0 0 436 436
Apr 12 13:26:15 husky kernel: Node 0 Normal free:12048kB min:15748kB low:19684kB high:23620kB active_anon:354908kB inactive_anon:8148kB active_file:3280kB inactive_file:19180kB unevictable:0kB writepending:1472kB present:514048kB managed:447296kB mlocked:0kB kernel_stack:1536kB pagetables:3876kB bounce:0kB free_pcp:176kB local_pcp:12kB free_cma:0kB
Apr 12 13:26:15 husky kernel: lowmem_reserve[]: 0 0 0 0
Apr 12 13:26:15 husky kernel: Node 0 DMA: 2*4kB (UM) 1*8kB (U) 1*16kB (E) 2*32kB (ME) 4*64kB (UME) 2*128kB (UE) 2*256kB (UE) 2*512kB (ME) 3*1024kB (UME) 3*2048kB (UME) 1*4096kB (M) = 15456kB
Apr 12 13:26:15 husky kernel: Node 0 DMA32: 919*4kB (UME) 1348*8kB (UME) 1819*16kB (UME) 920*32kB (UME) 448*64kB (UME) 107*128kB (UME) 7*256kB (UM) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 117164kB
Apr 12 13:26:15 husky kernel: Node 0 Normal: 217*4kB (UMEH) 118*8kB (UEH) 54*16kB (UEH) 18*32kB (UMEH) 15*64kB (MEH) 10*128kB (UM) 6*256kB (UM) 4*512kB (UME) 1*1024kB (M) 1*2048kB (M) 0*4096kB = 12148kB
Apr 12 13:26:15 husky kernel: 829306 total pagecache pages
Apr 12 13:26:15 husky kernel: 0 pages in swap cache
Apr 12 13:26:15 husky kernel: Swap cache stats: add 0, delete 0, find 0/0
Apr 12 13:26:15 husky kernel: Free swap  = 0kB
Apr 12 13:26:15 husky kernel: Total swap = 0kB
Apr 12 13:26:15 husky kernel: 1017645 pages RAM
Apr 12 13:26:15 husky kernel: 0 pages HighMem/MovableOnly
Apr 12 13:26:15 husky kernel: 36446 pages reserved
Apr 12 13:26:15 husky kernel: 0 pages cma reserved

currently on 6.5.1-rc3  and saw this pop up after 11 days of uptime.

husky-diagnostics-20180413-0103.zip

Edited April 13, 2018 by zoggy