9回复
1年前
【赏金25元】Linux OOM-Killer Java进程分析求助？
测试环境的一台机器 Java 进程运行了6天，被 Linux OOM-Killer了。Java 进程是运行在容器中的，整个容器限制为4G，这里面是不是会有memory leak ?
使用的JVM 版本
openjdk version "11.0.14" 2022-01-18
OpenJDK Runtime Environment (build 11.0.14+9-post-Debian-1deb11u1)
OpenJDK 64-Bit Server VM (build 11.0.14+9-post-Debian-1deb11u1, mixed mode, sharing)
其中Java 运行参数如下：
-Xss256k -XX:+UseContainerSupport -XX:MaxRAM=4G -XX:InitialRAMPercentage=65.0 -XX:MaxRAMPercentage=65.0 -XX:ReservedCodeCacheSize=128m -XX:MaxMetaspaceSize=192m -XX:MetaspaceSize=192m -XX:+PrintCommandLineFlags -Xlog:gc*,gc+ref=debug,gc+heap=debug,gc+age=trace:file=/var/log/cdc/process/gc-gateway-%t.log:tags,uptime,time,level:filecount=10,filesize=200m -XX:+UnlockDiagnosticVMOptions -XX:+PrintNMTStatistics -XX:NativeMemoryTracking=detail
Linux OOM-Kill 日志：
[Tue May 23 13:48:53 2023] https-jsse-nio- invoked oom-killer: gfp_mask=0xcc0(GFP_KERNEL), order=0, oom_score_adj=0
[Tue May 23 13:48:53 2023] CPU: 6 PID: 2396177 Comm: https-jsse-nio- Tainted: G E 5.10.121-cip9 #1
[Tue May 23 13:48:53 2023] Hardware name: VMware, Inc. VMware7,1/440BX Desktop Reference Platform, BIOS VMW71.00V.16707776.B64.2008070230 08/07/2020
[Tue May 23 13:48:53 2023] Call Trace:
[Tue May 23 13:48:53 2023] dump_stack+0x6b/0x83
[Tue May 23 13:48:53 2023] dump_header+0x4a/0x1f0
[Tue May 23 13:48:53 2023] oom_kill_process.cold+0xb/0x10
[Tue May 23 13:48:53 2023] out_of_memory+0x1bd/0x4e0
[Tue May 23 13:48:53 2023] mem_cgroup_out_of_memory+0x134/0x150
[Tue May 23 13:48:53 2023] try_charge+0x75e/0x7d0
[Tue May 23 13:48:53 2023] ? __switch_to_xtra+0x10a/0x500
[Tue May 23 13:48:53 2023] ? current_time+0x2b/0xf0
[Tue May 23 13:48:53 2023] __memcg_kmem_charge+0x31/0xe0
[Tue May 23 13:48:53 2023] obj_cgroup_charge+0xb3/0x160
[Tue May 23 13:48:53 2023] slab_pre_alloc_hook.constprop.0+0x68/0xd0
[Tue May 23 13:48:53 2023] ? do_epoll_ctl+0x3d1/0xd80
[Tue May 23 13:48:53 2023] kmem_cache_alloc+0x45/0x1f0
[Tue May 23 13:48:53 2023] ? __fget_files+0x79/0xb0
[Tue May 23 13:48:53 2023] do_epoll_ctl+0x3d1/0xd80
[Tue May 23 13:48:53 2023] __x64_sys_epoll_ctl+0x5d/0x90
[Tue May 23 13:48:53 2023] do_syscall_64+0x33/0x80
[Tue May 23 13:48:53 2023] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Tue May 23 13:48:53 2023] RIP: 0033:0x7f884996686a
[Tue May 23 13:48:53 2023] Code: 48 8b 0d 29 f6 0b 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 49 89 ca b8 e9 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d f6 f5 0b 00 f7 d8 64 89 01 48
[Tue May 23 13:48:53 2023] RSP: 002b:00007f874132e7a8 EFLAGS: 00000202 ORIG_RAX: 00000000000000e9
[Tue May 23 13:48:53 2023] RAX: ffffffffffffffda RBX: 0000000000000007 RCX: 00007f884996686a
[Tue May 23 13:48:53 2023] RDX: 0000000000004d67 RSI: 0000000000000001 RDI: 0000000000000160
[Tue May 23 13:48:53 2023] RBP: 00007f874132e7c0 R08: 0000000000004d67 R09: 0000000000000001
[Tue May 23 13:48:53 2023] R10: 00007f874132e7b4 R11: 0000000000000202 R12: 0000000000000000
[Tue May 23 13:48:53 2023] R13: 00000007b02b5f00 R14: 00007f874132e800 R15: 00007f8846718800
[Tue May 23 13:48:53 2023] memory: usage 4188756kB, limit 4194304kB, failcnt 1520884
[Tue May 23 13:48:53 2023] swap: usage 0kB, limit 4194304kB, failcnt 0
[Tue May 23 13:48:53 2023] Memory cgroup stats for /system.slice/docker-3150b01457a68d1d0fc9f428bf5f6651d35741e7043caee8cb7670041b177432.scope:
[Tue May 23 13:48:53 2023] anon 4049170432
file 0
kernel_stack 2506752
percpu 0
sock 159518720
shmem 0
file_mapped 135168
file_dirty 0
file_writeback 0
anon_thp 3598712832
inactive_anon 4049297408
active_anon 0
inactive_file 0
active_file 131072
unevictable 0
slab_reclaimable 55283616
slab_unreclaimable 12817328
slab 68100944
workingset_refault_anon 0
workingset_refault_file 207702
workingset_activate_anon 0
workingset_activate_file 41910
workingset_restore_anon 0
workingset_restore_file 1188
workingset_nodereclaim 0
pgfault 973896
pgmajfault 891
pgrefill 17091
pgscan 3961189
pgsteal 3950043
pgactivate 13233
pgdeactivate 16535
pglazyfree 0
pglazyfreed 0
thp_fault_alloc 1320
thp_collapse_alloc 330
[Tue May 23 13:48:53 2023] Tasks state (memory values in pages):
[Tue May 23 13:48:53 2023] [ pid ] uid tgid total_vm rss pgtables_bytes swapents oom_score_adj name
[Tue May 23 13:48:53 2023] [2392434] 1000 2392434 1965141 991264 8785920 0 0 java
[Tue May 23 13:48:53 2023] oom-kill:constraint=CONSTRAINT_MEMCG,nodemask=(null),cpuset=docker-3150b01457a68d1d0fc9f428bf5f6651d35741e7043caee8cb7670041b177432.scope,mems_allowed=0,oom_memcg=/system.slice/docker-3150b01457a68d1d0fc9f428bf5f6651d35741e7043caee8cb7670041b177432.scope,task_memcg=/system.slice/docker-3150b01457a68d1d0fc9f428bf5f6651d35741e7043caee8cb7670041b177432.scope,task=java,pid=2392434,uid=1000
[Tue May 23 13:48:53 2023] Memory cgroup out of memory: Killed process 2392434 (java) total-vm:7860564kB, anon-rss:3947332kB, file-rss:17724kB, shmem-rss:0kB, UID:1000 pgtables:8580kB oom_score_adj:0
Java GC 日志：
[2023-05-23T13:48:46.764+0800][97553.233s][info ][gc,start ] GC(65017) Pause Cleanup
[2023-05-23T13:48:46.766+0800][97553.235s][info ][gc ] GC(65017) Pause Cleanup 1423M->1423M(2664M) 1.820ms
[2023-05-23T13:48:46.766+0800][97553.235s][info ][gc,cpu ] GC(65017) User=0.00s Sys=0.00s Real=0.00s
[2023-05-23T13:48:46.766+0800][97553.235s][info ][gc,marking ] GC(65017) Concurrent Cleanup for Next Mark
[2023-05-23T13:48:46.770+0800][97553.239s][info ][gc,marking ] GC(65017) Concurrent Cleanup for Next Mark 3.630ms
[2023-05-23T13:48:46.770+0800][97553.239s][info ][gc ] GC(65017) Concurrent Cycle 1647.075ms
[2023-05-23T13:48:51.400+0800][97557.869s][debug][gc,heap ] GC(65020) Heap before GC invocations=65020 (full 0): garbage-first heap total 2727936K, used 2366003K [0x0000000759800000, 0x0000000800000000)
[2023-05-23T13:48:51.400+0800][97557.869s][debug][gc,heap ] GC(65020) region size 1024K, 946 young (968704K), 6 survivors (6144K)
[2023-05-23T13:48:51.400+0800][97557.869s][debug][gc,heap ] GC(65020) Metaspace used 178660K, capacity 183325K, committed 183680K, reserved 350208K
[2023-05-23T13:48:51.400+0800][97557.869s][debug][gc,heap ] GC(65020) class space used 20130K, capacity 22016K, committed 22144K, reserved 188416K
[2023-05-23T13:48:51.400+0800][97557.869s][info ][gc,start ] GC(65020) Pause Young (Prepare Mixed) (G1 Evacuation Pause)
[2023-05-23T13:48:51.400+0800][97557.869s][info ][gc,task ] GC(65020) Using 8 workers of 8 for evacuation
[2023-05-23T13:48:51.400+0800][97557.869s][debug][gc,age ] GC(65020) Desired survivor size 62390272 bytes, new threshold 15 (max threshold 15)
[2023-05-23T13:48:51.426+0800][97557.894s][debug][gc,ref ] GC(65020) Skipped phase1 of Reference Processing due to unavailable references
[2023-05-23T13:48:51.426+0800][97557.895s][debug][gc,ref ] GC(65020) Skipped phase3 of Reference Processing due to unavailable references
[2023-05-23T13:48:51.426+0800][97557.895s][trace][gc,age ] GC(65020) Age table with threshold 15 (max threshold 15)
[2023-05-23T13:48:51.426+0800][97557.895s][trace][gc,age ] GC(65020) - age 1: 4063632 bytes, 4063632 total
[2023-05-23T13:48:51.426+0800][97557.895s][trace][gc,age ] GC(65020) - age 2: 653320 bytes, 4716952 total
[2023-05-23T13:48:51.426+0800][97557.895s][trace][gc,age ] GC(65020) - age 3: 530656 bytes, 5247608 total
[2023-05-23T13:48:51.426+0800][97557.895s][trace][gc,age ] GC(65020) - age 4: 3852584 bytes, 9100192 total
[2023-05-23T13:48:51.426+0800][97557.895s][trace][gc,age ] GC(65020) - age 5: 432960 bytes, 9533152 total
[2023-05-23T13:48:51.427+0800][97557.896s][info ][gc,phases ] GC(65020) Pre Evacuate Collection Set: 0.1ms
[2023-05-23T13:48:51.427+0800][97557.896s][info ][gc,phases ] GC(65020) Evacuate Collection Set: 23.9ms
[2023-05-23T13:48:51.427+0800][97557.896s][info ][gc,phases ] GC(65020) Post Evacuate Collection Set: 1.4ms
[2023-05-23T13:48:51.427+0800][97557.896s][info ][gc,phases ] GC(65020) Other: 1.1ms
[2023-05-23T13:48:51.427+0800][97557.896s][info ][gc,heap ] GC(65020) Eden regions: 940->0(123)
[2023-05-23T13:48:51.427+0800][97557.896s][info ][gc,heap ] GC(65020) Survivor regions: 6->10(119)
[2023-05-23T13:48:51.427+0800][97557.896s][info ][gc,heap ] GC(65020) Old regions: 1364->1364
[2023-05-23T13:48:51.427+0800][97557.896s][info ][gc,heap ] GC(65020) Humongous regions: 3->3
[2023-05-23T13:48:51.427+0800][97557.896s][info ][gc,metaspace ] GC(65020) Metaspace: 178660K->178660K(350208K)
[2023-05-23T13:48:51.427+0800][97557.896s][debug][gc,heap ] GC(65020) Heap after GC invocations=65021 (full 0): garbage-first heap total 2727936K, used 1408241K [0x0000000759800000, 0x0000000800000000)
[2023-05-23T13:48:51.427+0800][97557.896s][debug][gc,heap ] GC(65020) region size 1024K, 10 young (10240K), 10 survivors (10240K)
[2023-05-23T13:48:51.427+0800][97557.896s][debug][gc,heap ] GC(65020) Metaspace used 178660K, capacity 183325K, committed 183680K, reserved 350208K
[2023-05-23T13:48:51.427+0800][97557.896s][debug][gc,heap ] GC(65020) class space used 20130K, capacity 22016K, committed 22144K, reserved 188416K
[2023-05-23T13:48:51.427+0800][97557.896s][info ][gc ] GC(65020) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 2311M->1375M(2664M) 26.531ms
[2023-05-23T13:48:51.427+0800][97557.896s][info ][gc,cpu ] GC(65020) User=0.10s Sys=0.00s Real=0.03s
[2023-05-23T13:48:52.082+0800][97558.551s][debug][gc,heap ] GC(65021) Heap before GC invocations=65021 (full 0): garbage-first heap total 2727936K, used 1533169K [0x0000000759800000, 0x0000000800000000)
[2023-05-23T13:48:52.082+0800][97558.551s][debug][gc,heap ] GC(65021) region size 1024K, 133 young (136192K), 10 survivors (10240K)
[2023-05-23T13:48:52.082+0800][97558.551s][debug][gc,heap ] GC(65021) Metaspace used 178660K, capacity 183325K, committed 183680K, reserved 350208K
[2023-05-23T13:48:52.082+0800][97558.551s][debug][gc,heap ] GC(65021) class space used 20130K, capacity 22016K, committed 22144K, reserved 188416K
[2023-05-23T13:48:52.082+0800][97558.551s][info ][gc,start ] GC(65021) Pause Young (Mixed) (G1 Evacuation Pause)
[2023-05-23T13:48:52.082+0800][97558.551s][info ][gc,task ] GC(65021) Using 8 workers of 8 for evacuation
[2023-05-23T13:48:52.082+0800][97558.551s][debug][gc,age ] GC(65021) Desired survivor size 8912896 bytes, new threshold 4 (max threshold 15)
[2023-05-23T13:48:52.091+0800][97558.560s][debug][gc,ref ] GC(65021) Skipped phase1 of Reference Processing due to unavailable references
[2023-05-23T13:48:52.091+0800][97558.560s][debug][gc,ref ] GC(65021) Skipped phase2 of Reference Processing due to unavailable references
[2023-05-23T13:48:52.092+0800][97558.560s][debug][gc,ref ] GC(65021) Skipped phase3 of Reference Processing due to unavailable references
[2023-05-23T13:48:52.092+0800][97558.561s][trace][gc,age ] GC(65021) Age table with threshold 4 (max threshold 15)
[2023-05-23T13:48:52.092+0800][97558.561s][trace][gc,age ] GC(65021) - age 1: 638960 bytes, 638960 total
[2023-05-23T13:48:52.092+0800][97558.561s][trace][gc,age ] GC(65021) - age 2: 3983080 bytes, 4622040 total
[2023-05-23T13:48:52.092+0800][97558.561s][trace][gc,age ] GC(65021) - age 3: 653320 bytes, 5275360 total
[2023-05-23T13:48:52.092+0800][97558.561s][trace][gc,age ] GC(65021) - age 4: 530656 bytes, 5806016 total
[2023-05-23T13:48:52.093+0800][97558.562s][info ][gc,phases ] GC(65021) Pre Evacuate Collection Set: 0.1ms
[2023-05-23T13:48:52.093+0800][97558.562s][info ][gc,phases ] GC(65021) Evacuate Collection Set: 8.8ms
[2023-05-23T13:48:52.093+0800][97558.562s][info ][gc,phases ] GC(65021) Post Evacuate Collection Set: 0.8ms
[2023-05-23T13:48:52.093+0800][97558.562s][info ][gc,phases ] GC(65021) Other: 1.3ms
[2023-05-23T13:48:52.093+0800][97558.562s][info ][gc,heap ] GC(65021) Eden regions: 123->0(956)
[2023-05-23T13:48:52.093+0800][97558.562s][info ][gc,heap ] GC(65021) Survivor regions: 10->7(17)
[2023-05-23T13:48:52.093+0800][97558.562s][info ][gc,heap ] GC(65021) Old regions: 1364->1350
[2023-05-23T13:48:52.093+0800][97558.562s][info ][gc,heap ] GC(65021) Humongous regions: 3->3
[2023-05-23T13:48:52.093+0800][97558.562s][info ][gc,metaspace ] GC(65021) Metaspace: 178660K->178660K(350208K)
[2023-05-23T13:48:52.093+0800][97558.562s][debug][gc,heap ] GC(65021) Heap after GC invocations=65022 (full 0): garbage-first heap total 2727936K, used 1390875K [0x0000000759800000, 0x0000000800000000)
[2023-05-23T13:48:52.093+0800][97558.562s][debug][gc,heap ] GC(65021) region size 1024K, 7 young (7168K), 7 survivors (7168K)
[2023-05-23T13:48:52.093+0800][97558.562s][debug][gc,heap ] GC(65021) Metaspace used 178660K, capacity 183325K, committed 183680K, reserved 350208K
[2023-05-23T13:48:52.093+0800][97558.562s][debug][gc,heap ] GC(65021) class space used 20130K, capacity 22016K, committed 22144K, reserved 188416K
[2023-05-23T13:48:52.093+0800][97558.562s][info ][gc ] GC(65021) Pause Young (Mixed) (G1 Evacuation Pause) 1498M->1358M(2664M) 11.065ms
[2023-05-23T13:48:52.093+0800][97558.562s][info ][gc,cpu ] GC(65021) User=0.04s Sys=0.00s Real=0.00s
1754 阅读
