Server Version#:
1.31.2.6810-7000
Player Version#:
N/A. Server is crashing from a variety of Player-clients
Hi there,
I’m getting an daily error on Synology
“SYSTEM: [Plex Media Serv] stopped running because the system is out of memory”
This has been happening for ~2 weeks, andI have:
Synology ‘Log Center’ show nothing else causing issues.
Has anyone seen this before?
How much memory is installed in the system?
Which other apps/services are running?
6GB (6144mb) of RAM
I run lots of apps and some Docker images, but have not changed anything in the previous ~3 months that should cause this.
I’ve also been running Plex Server on Synology since ~2015, and never seen anything like this.
Is there a way to get more advanced logs out of DSM?
Also to note: Plex is the only DSM app that force crashes, and needs to be manually., The other ~35 continue as normal with no crashing.
About the only thing you can do is look at /var/log/messages from the Synology command line.
Also
Also, if this is at all predictable, run Resource Monitor and see if you can monitor memory usage…
Lastly, this one-line command sequence shows free memory every 5 seconds.
You’ll see DSM kill PMS when both free memory and swap memory are nearing exhaustion.
while true; do free -m; echo ' '; sleep 5; done
This will run until stopped (control C).
You can embellish as you wish between the ‘do’ and ‘done’. don’t forget to separate commands with ‘;’ (semicolon)
Log Section 1:
[1804995.870926] Out of memory: Kill process 14391 (Plex Media Serv) score 655 or sacrifice child
[1804995.880574] Killed process 16917 (Plex Tuner Serv) total-vm:22672kB, anon-rss:256kB, file-rss:0kB
[1804996.059449] syno-cloud-sync invoked oom-killer: gfp_mask=0x2420848, order=0, oom_score_adj=0
[1804996.074957] CPU: 0 PID: 29476 Comm: syno-cloud-sync Tainted: P O 4.4.180+ #42962
[1804996.084674] Hardware name: Synology DS418play/DS418play, BIOS M.319 11/11/2019
[1804996.092931] 0000000000000000 ffff8801c356f818 ffffffff812f2dbd ffff8801768444c0
[1804996.101397] 0000000000000000 ffff8801c356f850 ffffffff81185e4b ffff8801c356f980
[1804996.109865] 0000000000000000 ffff8801768444c0 ffffffff81724fc3 000000000000028f
[1804996.118333] Call Trace:
[1804996.121260] [<ffffffff812f2dbd>] dump_stack+0x4d/0x70
[1804996.127194] [<ffffffff81185e4b>] dump_header.isra.13+0x4b/0x164
[1804996.134098] [<ffffffff81185f79>] oom_kill_process.cold.19+0x15/0x35d
[1804996.141487] [<ffffffff81134660>] out_of_memory+0xf0/0x2c0
[1804996.147804] [<ffffffff81138da8>] __alloc_pages_nodemask+0x928/0xb50
[1804996.155094] [<ffffffff81130229>] ? find_get_entry.part.44+0x19/0x90
[1804996.162377] [<ffffffff81130fc4>] pagecache_get_page+0x94/0x1c0
[1804996.169184] [<ffffffff811cb57c>] __getblk_slow+0xcc/0x240
[1804996.175503] [<ffffffff811cb72d>] __getblk_gfp+0x3d/0x50
[1804996.181626] [<ffffffff8121d666>] __ext4_get_inode_loc+0xf6/0x3f0
[1804996.188619] [<ffffffff8121fcbd>] ext4_iget+0x6d/0xd80
[1804996.194549] [<ffffffff811a0045>] ? path_openat+0xc75/0x1bd0
[1804996.201049] [<ffffffff812209fa>] ext4_iget_normal+0x2a/0x30
[1804996.207546] [<ffffffff8122c49f>] ext4_lookup+0x18f/0x230
[1804996.213763] [<ffffffff81198450>] lookup_real+0x20/0x60
[1804996.219785] [<ffffffff8119877f>] __lookup_hash+0x2f/0x40
[1804996.226003] [<ffffffff8119b8c3>] walk_component+0x243/0x350
[1804996.232516] [<ffffffff8119c834>] path_lookupat.isra.41+0xb4/0x230
[1804996.239597] [<ffffffff811a20aa>] filename_lookup.part.57+0x8a/0xf0
[1804996.246784] [<ffffffff8114df44>] ? __inc_zone_page_state+0x24/0x30
[1804996.253967] [<ffffffff81167fbe>] ? page_add_file_rmap+0x4e/0x60
[1804996.260866] [<ffffffff811a1de3>] ? getname_flags+0x53/0x190
[1804996.267376] [<ffffffff811a21db>] user_path_at_empty+0x3b/0x50
[1804996.274082] [<ffffffff81193891>] vfs_fstatat+0x51/0xa0
[1804996.280108] [<ffffffff81193a0a>] SYSC_newstat+0x3a/0x60
[1804996.286222] [<ffffffff8103f1c0>] ? __do_page_fault+0x190/0x3f0
[1804996.293023] [<ffffffff81194159>] SyS_newstat+0x9/0x10
[1804996.298951] [<ffffffff8157f08a>] entry_SYSCALL_64_fastpath+0x1e/0x8e
[1804996.306459] Mem-Info:
[1804996.309225] active_anon:777083 inactive_anon:264564 isolated_anon:29
[1804996.348559] DMA free:15796kB min:172kB low:212kB high:252kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15888kB managed:15796kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
[1804996.394572] lowmem_reserve[]: 0 1777 5764 5764
[1804996.399782] DMA32 free:36136kB min:20204kB low:25252kB high:30300kB active_anon:954776kB inactive_anon:357836kB active_file:296kB inactive_file:332kB unevictable:35360kB isolated(anon):0kB isolated(file):148kB present:1901328kB managed:1826744kB mlocked:35360kB dirty:0kB writeback:8kB mapped:23916kB shmem:2480kB slab_reclaimable:39772kB slab_unreclaimable:44444kB kernel_stack:11920kB pagetables:49028kB unstable:0kB bounce:0kB free_pcp:120kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[1804996.451609] lowmem_reserve[]: 0 0 3986 3986
[1804996.456519] Normal free:49176kB min:45156kB low:56444kB high:67732kB active_anon:2153556kB inactive_anon:700420kB active_file:2448kB inactive_file:2660kB unevictable:65808kB isolated(anon):116kB isolated(file):260kB present:4194304kB managed:4082532kB mlocked:65808kB dirty:0kB writeback:4kB mapped:58284kB shmem:10276kB slab_reclaimable:91384kB slab_unreclaimable:95564kB kernel_stack:23088kB pagetables:103824kB unstable:0kB bounce:0kB free_pcp:120kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:2588 all_unreclaimable? no
[1804996.509421] lowmem_reserve[]: 0 0 0 0
[1804996.513718] DMA: 3*4kB (U) 3*8kB (U) 1*16kB (U) 2*32kB (U) 3*64kB (U) 1*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (U) 3*4096kB (M) = 15796kB
[1804996.528761] DMA32: 187*4kB (UME) 1818*8kB (UME) 1294*16kB (UM) 6*32kB (M) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 36188kB
[1804996.543231] Normal: 3137*4kB (UME) 3077*8kB (UME) 500*16kB (UME) 4*32kB (EH) 3*64kB (H) 1*128kB (H) 2*256kB (H) 0*512kB 1*1024kB (H) 1*2048kB (H) 0*4096kB = 49196kB
[1804996.559932] 28511 total pagecache pages
[1804996.564407] 6004 pages in swap cache
[1804996.568593] Swap cache stats: add 28080317, delete 28074304, find 111117268/114623609
[1804996.577536] Free swap = 0kB
[1804996.580946] Total swap = 5652404kB
[1804996.584934] 1527880 pages RAM
[1804996.588437] 0 pages HighMem/MovableOnly
[1804996.592910] 46612 pages reserved
Log Section 2:
[1805000.847037] Out of memory: Kill process 14391 (Plex Media Serv) score 655 or sacrifice child
[1805000.856675] Killed process 8938 (EasyAudioEncode) total-vm:2564kB, anon-rss:4kB, file-rss:0kB
[1805001.190494] synorelayd invoked oom-killer: gfp_mask=0x24201ca, order=0, oom_score_adj=0
[1805001.205338] CPU: 1 PID: 15264 Comm: synorelayd Tainted: P O 4.4.180+ #42962
[1805001.214564] Hardware name: Synology DS418play/DS418play, BIOS M.319 11/11/2019
[1805001.222822] 0000000000000000 ffff8801a1ebbb60 ffffffff812f2dbd ffff8801768444c0
[1805001.231283] 0000000000000000 ffff8801a1ebbb98 ffffffff81185e4b ffff8801a1ebbcc8
[1805001.239745] 0000000000000000 ffff8801768444c0 ffffffff81724fc3 000000000000028f
[1805001.248207] Call Trace:
[1805001.251134] [<ffffffff812f2dbd>] dump_stack+0x4d/0x70
[1805001.257064] [<ffffffff81185e4b>] dump_header.isra.13+0x4b/0x164
[1805001.263963] [<ffffffff81185f79>] oom_kill_process.cold.19+0x15/0x35d
[1805001.271348] [<ffffffff81134660>] out_of_memory+0xf0/0x2c0
[1805001.277662] [<ffffffff81138f5f>] __alloc_pages_nodemask+0xadf/0xb50
[1805001.284949] [<ffffffff811329c1>] filemap_fault+0x2f1/0x410
[1805001.291365] [<ffffffff81226513>] ext4_filemap_fault+0x33/0x50
[1805001.298065] [<ffffffff8115ab96>] __do_fault+0x66/0xb0
[1805001.303992] [<ffffffff8115f545>] handle_mm_fault+0xf45/0x1530
[1805001.310697] [<ffffffff811b0d25>] ? __fget_light+0x55/0x60
[1805001.317013] [<ffffffff8103f1a0>] __do_page_fault+0x170/0x3f0
[1805001.323608] [<ffffffff8103f42c>] do_page_fault+0xc/0x10
[1805001.329729] [<ffffffff81580e92>] page_fault+0x22/0x30
[1805001.335795] Mem-Info:
[1805001.339327] active_anon:776994 inactive_anon:264539 isolated_anon:14
[1805001.378911] DMA free:15796kB min:172kB low:212kB high:252kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15888kB managed:15796kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
[1805001.425416] lowmem_reserve[]: 0 1777 5764 5764
[1805001.430697] DMA32 free:41164kB min:20204kB low:25252kB high:30300kB active_anon:954656kB inactive_anon:357780kB active_file:4800kB inactive_file:22252kB unevictable:35360kB isolated(anon):0kB isolated(file):1108kB present:1901328kB managed:1826744kB mlocked:35360kB dirty:0kB writeback:0kB mapped:24868kB shmem:2484kB slab_reclaimable:39772kB slab_unreclaimable:44596kB kernel_stack:11920kB pagetables:49024kB unstable:0kB bounce:0kB free_pcp:1008kB local_pcp:656kB free_cma:0kB writeback_tmp:0kB pages_scanned:176788 all_unreclaimable? yes
[1805001.483850] lowmem_reserve[]: 0 0 3986 3986
[1805001.488982] Normal free:60596kB min:45156kB low:56444kB high:67732kB active_anon:2153320kB inactive_anon:700376kB active_file:3800kB inactive_file:21552kB unevictable:65808kB isolated(anon):56kB isolated(file):552kB present:4194304kB managed:4082532kB mlocked:65808kB dirty:0kB writeback:0kB mapped:58132kB shmem:10276kB slab_reclaimable:91368kB slab_unreclaimable:95736kB kernel_stack:23104kB pagetables:103768kB unstable:0kB bounce:0kB free_pcp:940kB local_pcp:320kB free_cma:0kB writeback_tmp:0kB pages_scanned:1652 all_unreclaimable? no
[1805001.542117] lowmem_reserve[]: 0 0 0 0
[1805001.546536] DMA: 3*4kB (U) 3*8kB (U) 1*16kB (U) 2*32kB (U) 3*64kB (U) 1*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (U) 3*4096kB (M) = 15796kB
[1805001.561763] DMA32: 1542*4kB (UME) 1293*8kB (UME) 931*16kB (UM) 467*32kB (UME) 89*64kB (UME) 7*128kB (U) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 52944kB
[1805001.577866] Normal: 4244*4kB (UME) 3102*8kB (UME) 386*16kB (UME) 393*32kB (UMEH) 4*64kB (EH) 1*128kB (H) 2*256kB (H) 0*512kB 1*1024kB (H) 1*2048kB (H) 0*4096kB = 64512kB
[1805001.595375] 42156 total pagecache pages
[1805001.599890] 5897 pages in swap cache
[1805001.604103] Swap cache stats: add 28080358, delete 28074452, find 111117278/114623630
[1805001.613079] Free swap = 0kB
[1805001.616493] Total swap = 5652404kB
[1805001.620510] 1527880 pages RAM
[1805001.624164] 0 pages HighMem/MovableOnly
[1805001.628658] 46612 pages reserved
Things stand out.
Do you have the version prior to this (SPK file) available?
EITHER —
If you opt to change Plex
Continue to monitor.
This is very unusual. I’ve not seen the tuner service do this.
I’m also very suspicious of the Synology Cloud Sync app starting up.
It’s what forces PMS to terminate (your log excerpts show this)
We’ve had several reports of problems with it this past week. Definitely a bug or two in it.
@ChuckPa Thank you for your help!!
Here’s a dump of the full log from that time period:
There were no logs ~45 mins before, or after that except.
(Will delete the log URL once you view, in case of anything sensitive)
How many containers are you running? I see a fair amount of memory used up.
Also, have you had a chance to run my little command line scriptlet ?
7 containers, but 1.88GB / 6GB used by Docker.
If you look at the screenshot in my first post, overall ~40% of RAM is being used consistently, with Plex taking ~1%
I didn’t leave the command as this occurs every ~24/48 hours with no predictability or seeming pattern.
This one is really bothering me, as I need to manually start the PMS app manually in DMS Package Center, there’s no ‘restart on exit’ option available
40% vs 1% is what I thought you were showing me.
When DSM stops Plex, there is no auto restart. We’re killed and disabled until you click “Runt” (even if rebooted)
Would you mind, as an experiment, leaving Cloud Sync turned off for 48-72 hours but have PMS running ?
If PMS is the cause, it’ll occur again. If not, well then we know the cause (?)
Sure just disabled it, will let you know if the issue comes back up.
I use CloudSync, but can burn the install + rebuild if it turns out to be the root cause.
Interestingly the latest CloudSync version (what I’ve installed) came out in 2022-09, so not sure why this issue only started for me recently:
https://archive.synology.com/download/Package/CloudSync/2.6.1-2286
I haven’t had time to learn Syno Cloud Sync. (probably won’t have time to)
The case recently reported was it (current version) complains about the files I placed in PlexMediaServer and AppData which are long names which end with a period (.) and those names aren’t compatible with syncing.
In general , I’m suspicious of the app now until more is known.
@ChuckPa it’s still happening with CloudSync disabled.
PMS LibUpdater invoked oom-killer: gfp_mask=0x24201ca, order=0, oom_score_adj=0
kernel: [1853235.125868] Out of memory: Kill process 17418 (Plex Media Serv) score 673 or sacrifice child
kernel: [1853235.135536] Killed process 19173 (Plex Script Hos) total-vm:89020kB, anon-rss:20736kB, file-rss:0kB
Latest log is here:
https://docs.google.com/document/d/1xfNnHh741COT2lnw_98gWMRPvddlkLIgpOSGzg3JhrU/edit
Grab the PMS logs please and attach here.
PMS LibUpdater is very stable code. There’s something seriously wrong.
After you do this, would you consider creating a ‘Test’ (new) server, and still preserving your existing server metadata, so we can figure out if it’s the database (deep corruption) or something else ?
Let me know and I’ll provide instructions if you’re interested.
Sure thing @ChuckPa
Logs are attached:
Plex Media Server Logs_2023-03-23_23-16-49.zip (3.5 MB)
Happy to help troubleshoot in any way I can, to get this resolved.
Thanks again for your help!!
Here’s what we do.
Now,
Create one section and let it finish. Let’s see where we stand.
Looking through your logs, I don’t see where ‘use hardware acceleration when available’ is checked in Settings - Server - Transcoder.
Mar 23, 2023 22:17:29.982 [0x7efd3a179b38] DEBUG - [Req#b7/Transcode] [Universal] Using local file path instead of URL: /volume1/MEDIA/TV Shows/Ted Lasso/Season 03/ted.lasso.s03e01.1080p.web.h264-ggwp.mkv
Mar 23, 2023 22:17:29.982 [0x7efd3a179b38] DEBUG - [Req#b7/Transcode] TPU: hardware transcoding: final decoder: , final encoder:
Mar 23, 2023 22:17:29.984 [0x7efd3a179b38] DEBUG - [Req#b7/Transcode/JobRunner] Job running: EAE_ROOT=/var/packages/PlexMediaServer/shares/PlexMediaServer/AppData/tmp/pms-7f3e72bf-2af5-40c8-b00b-a3f26e8c07cb/EasyAudioEncoder FFMPEG_EXTERNAL_LIBS='/var/packages/PlexMediaServer/shares/PlexMediaServer/AppData/Plex\ Media\ Server/Codecs/2584b51-4483-linux-x86_64/' X_PLEX_TOKEN=xxxxxxxxxxxxxxxxxxxx4fe1-b69f-82e5b18fe169 "/volume1/@appstore/PlexMediaServer/Plex Transcoder" -codec:0 h264 -codec:1 eac3_eae -eae_prefix:1 wxdb0ft1cgxjzdpq3xv657ho_ -noaccurate_seek -analyzeduration 20000000 -probesize 20000000 -i "/volume1/MEDIA/TV Shows/Ted Lasso/Season 03/ted.lasso.s03e01.1080p.web.h264-ggwp.mkv" -map 0:0 -metadata:s:0 language=eng -codec:0 copy -filter_complex "[0:1] aresample=async=1:ochl='stereo':rematrix_maxval=0.000000dB:osr=48000[0]" -map "[0]" -metadata:s:1 language=eng -codec:1 aac -b:1 256k -f dash -seg_duration 5 -dash_segment_type mp4 -init_seg_name 'init-stream$RepresentationID$.m4s' -media_seg_name 'chunk-stream$RepresentationID$-$Number%05d$.m4s' -window_size 5 -delete_removed false -skip_to_segment 1 -time_delta 0.0625 -manifest_name "http://127.0.0.1:32400/video/:/transcode/session/wxdb0ft1cgxjzdpq3xv657ho/b4c47c47-34d1-4af5-8f96-5c75e9181982/manifest?X-Plex-Http-Pipeline=infinite" -avoid_negative_ts disabled -map_metadata -1 -map_chapters -1 dash -start_at_zero -copyts -vsync cfr -y -nostats -loglevel quiet -loglevel_plex error -progressurl http://127.0.0.1:32400/video/:/transcode/session/wxdb0ft1cgxjzdpq3xv657ho/b4c47c47-34d1-4af5-8f96-5c75e9181982/progress
It’s trying to transcode without hardware assist.
This NAS can’t transcode UHD HDR but it can to 4K SDR and all 1080p content.
@ChuckPa That’s odd, as Hardware Transcoding is enabled:
I will recreate the PMS setup later today, and let you know if there’s still issues.
@ChuckPa followed your steps, but once I sign in after the new AppData folder is created, I get the following screen:
Any ideas?
This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.
