[SERVER-39980] mongod process killed by oom-killer Created: 06/Mar/19  Updated: 06/Mar/19  Resolved: 06/Mar/19

Status: Closed
Project: Core Server
Component/s: MMAPv1, Performance
Affects Version/s: 3.6.5
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Moshe Youdkovich Assignee: Eric Sedor
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Operating System: ALL
Participants:

 Description   

hi,

our mongodb database crashed. we are using version 3.6.5 and MMAPv1 engine.

 

oom log :

Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.189449] conn285149496 invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.198296] conn285149496 cpuset=/ mems_allowed=0
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.203342] CPU: 15 PID: 119455 Comm: conn285149496 Tainted: G E 4.1.17-22.30.amzn1.x86_64 #1
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.207710] Hardware name: Xen HVM domU, BIOS 4.2.amazon 08/24/2006
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.210686] 0000000000000000 ffff880039763928 ffffffff814dc8db 00000000000068e6
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.214970] ffff8800355c9980 ffff8800397639d8 ffffffff814da092 ffff880039763988
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.219682] ffffffff811c0f37 01ff880039763948 ffff8800397639d8 ffff880039763988
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.226578] Call Trace:
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.228291] [<ffffffff814dc8db>] dump_stack+0x45/0x57
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.231021] [<ffffffff814da092>] dump_header+0x7f/0x1fe
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.233650] [<ffffffff811c0f37>] ? mem_cgroup_iter+0x137/0x3d0
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.236652] [<ffffffff811c5b31>] ? vmpressure+0x21/0x90
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.239177] [<ffffffff8115e78c>] oom_kill_process+0x1cc/0x3b0
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.242171] [<ffffffff8115ecee>] __out_of_memory+0x31e/0x530
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.245369] [<ffffffff8115f09b>] out_of_memory+0x5b/0x80
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.250636] [<ffffffff811640f9>] __alloc_pages_nodemask+0x8a9/0x8d0
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.253799] [<ffffffff811a5f3a>] alloc_page_interleave+0x3a/0x90
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.257101] [<ffffffff811a6795>] alloc_pages_current+0xe5/0x100
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.260419] [<ffffffff8115af5f>] __page_cache_alloc+0x9f/0xc0
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.263846] [<ffffffff8115d30d>] filemap_fault+0x19d/0x420
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.266795] [<ffffffff81184bbd>] __do_fault+0x3d/0x70
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.270288] [<ffffffff81189217>] handle_mm_fault+0xef7/0x1770
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.273669] [<ffffffff8109d509>] ? pick_next_entity+0xa9/0x190
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.277354] [<ffffffff8105daec>] __do_page_fault+0x17c/0x420
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.280195] [<ffffffff8105ddb2>] do_page_fault+0x22/0x30
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.282743] [<ffffffff814e5358>] page_fault+0x28/0x30
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.285263] Mem-Info:
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.286642] active_anon:5996230 inactive_anon:15 isolated_anon:0
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.286642] active_file:1361 inactive_file:1834 isolated_file:44
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.286642] unevictable:1 dirty:0 writeback:0 unstable:0
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.286642] slab_reclaimable:113525 slab_unreclaimable:41918
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.286642] mapped:2084 shmem:19 pagetables:1407837 bounce:0
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.286642] free:36506 free_pcp:983 free_cma:0
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.302453] Node 0 DMA free:15896kB min:8kB low:8kB high:12kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isol
ated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:8kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB u
nstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.321574] lowmem_reserve[]: 0 3746 30128 30128
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.324733] Node 0 DMA32 free:108252kB min:2756kB low:3444kB high:4132kB active_anon:2500732kB inactive_anon:0kB active_file:1536kB inactive_file:2536
kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:3915776kB managed:3840284kB mlocked:0kB dirty:0kB writeback:0kB mapped:2564kB shmem:4kB slab_reclaimable:281540kB slab_unreclaimable:10
5728kB kernel_stack:175312kB pagetables:532900kB unstable:0kB bounce:0kB free_pcp:948kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:4 all_unreclaimable? no
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.344976] lowmem_reserve[]: 0 0 26382 26382
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.347604] Node 0 Normal free:19276kB min:19412kB low:24264kB high:29116kB active_anon:21484188kB inactive_anon:60kB active_file:6272kB inactive_file
:6476kB unevictable:4kB isolated(anon):0kB isolated(file):48kB present:27525120kB managed:27015300kB mlocked:4kB dirty:0kB writeback:0kB mapped:10804kB shmem:72kB slab_reclaimable:172552kB slab_unrecl
aimable:61944kB kernel_stack:6672kB pagetables:5098448kB unstable:0kB bounce:0kB free_pcp:1416kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.367794] lowmem_reserve[]: 0 0 0 0
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.370207] Node 0 DMA: 0*4kB 1*8kB (E) 1*16kB (E) 2*32kB (UE) 3*64kB (UE) 2*128kB (UE) 2*256kB (UE) 1*512kB (E) 2*1024kB (UE) 2*2048kB (ER) 2*4096kB
(M) = 15896kB
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.379333] Node 0 DMA32: 7072*4kB (UEM) 6354*8kB (UEM) 1825*16kB (UEM) 3*32kB (R) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 108416k
B
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.387798] Node 0 Normal: 5064*4kB (UEM) 5*8kB (M) 0*16kB 2*32kB (R) 1*64kB (R) 0*128kB 1*256kB (R) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 20680kB
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.395312] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.398926] 4966 total pagecache pages
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.400895] 0 pages in swap cache
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.402595] Swap cache stats: add 0, delete 0, find 0/0
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.405327] Free swap = 0kB
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.406979] Total swap = 0kB
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.408383] 7864221 pages RAM
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.409745] 0 pages HighMem/MovableOnly
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.411411] 146349 pages reserved
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.412877] [ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.416331] [ 2554] 0 2554 2830 200 11 3 0 -1000 udevd
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.419838] [ 2703] 0 2703 2800 173 10 3 0 -1000 udevd
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.423380] [ 2705] 0 2705 2800 171 10 3 0 -1000 udevd
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.426872] [ 3216] 0 3216 2340 124 9 3 0 0 dhclient
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.430500] [ 3257] 0 3257 28022 116 23 3 0 -1000 auditd
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.434041] [ 3275] 0 3275 82608 4549 39 3 0 0 rsyslogd
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.437692] [ 3287] 0 3287 3494 319 10 3 0 0 irqbalance
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.441367] [ 3293] 0 3293 1095 37 7 3 0 0 rngd
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.444766] [ 3307] 32 3307 8823 98 22 4 0 0 rpcbind
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.448344] [ 3324] 29 3324 9965 199 24 3 0 0 rpc.statd
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.451965] [ 3347] 81 3347 5448 59 16 3 0 0 dbus-daemon
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.455624] [ 3408] 496 3408 56201 5381 59 4 0 0 ruby
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.459156] [ 3411] 496 3411 66087 8878 87 4 0 0 ruby
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.462603] [ 3480] 0 3480 19454 202 40 4 0 -1000 sshd
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.466033] [ 3649] 38 3649 7321 142 20 3 0 0 ntpd
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.469503] [ 3664] 0 3664 21722 539 44 3 0 0 sendmail
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.473068] [ 3672] 51 3672 19587 364 39 3 0 0 sendmail
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.476619] [ 3680] 0 3680 29880 146 15 3 0 0 crond
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.480112] [ 3709] 0 3709 38851 1791 30 3 0 0 munin-node
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.483679] [ 4014] 0 4014 4267 40 13 4 0 0 atd
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.487061] [ 4038] 0 4038 1078 23 8 3 0 0 mingetty
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.490702] [ 4040] 0 4040 1615 30 9 3 0 0 agetty
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.494290] [ 4043] 0 4043 1078 22 7 3 0 0 mingetty
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.497814] [ 4046] 0 4046 1078 22 8 3 0 0 mingetty
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.501396] [ 4048] 0 4048 1078 24 8 3 0 0 mingetty
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.504975] [ 4050] 0 4050 1078 24 7 4 0 0 mingetty
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.508548] [ 4052] 0 4052 1078 24 8 3 0 0 mingetty
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.512157] [25879] 500 25879 190517 4740 64 21 0 0 mongo
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.515595] [113059] 500 113059 193563 11421 74 25 0 0 mongo
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.519176] [38014] 497 38014 323312 14201 117 6 0 0 mongodb-mms-aut
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.523035] [38166] 497 38166 284379 13065 83 6 0 0 mongodb-mms-mon
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.526806] [101679] 497 101679 2138300613 5908765 1406771 6332 0 0 mongod
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.530513] [49889] 0 49889 29446 270 61 3 0 0 sshd
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.533929] [50107] 500 50107 29446 268 58 3 0 0 sshd
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.537376] [50258] 500 50258 28869 123 12 3 0 0 bash
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.540830] Out of memory: Kill process 101679 (mongod) score 948 or sacrifice child
Mar 6 09:14:48 trax-mongodb-prod01 kernel: [37744867.545724] Killed process 101679 (mongod) total-vm:8553202452kB, anon-rss:23635060kB, file-rss:0kB
Mar 6 09:15:51 trax-mongodb-prod01 kernel: [37744931.073457] TCP: request_sock_TCP: Possible SYN flooding on port 27000. Sending cookies. Check SNMP counters.



 Comments   
Comment by Eric Sedor [ 06/Mar/19 ]

Initially, we're not seeing anything to indicate a bug in MongoDB, as the memory use of the deployment appears to be associated with unindexed queries, queued ops, and consequently high disk utilization.

You should be able to get performance guidance from the mongodb-user group. Another option is to post on Stack Overflow with the mongodb tag.

Comment by Eric Sedor [ 06/Mar/19 ]

Thank you! We will investigate.

Comment by Moshe Youdkovich [ 06/Mar/19 ]

hi, 

I'm re-uploading the files to the secure portal.

 

thanks,

Moshe

Comment by Eric Sedor [ 06/Mar/19 ]

Thanks for asking. Yes they would be public on this ticket.

However, there is a secure option: I've created a secure upload portal for you. Files uploaded to this portal are visible only to MongoDB employees and are routinely deleted after some time.

Comment by Moshe Youdkovich [ 06/Mar/19 ]

hi,

about adding the logs - will my logs be publicly available? 

Comment by Moshe Youdkovich [ 06/Mar/19 ]

hi,

I have attached the requested files.

 

thanks,

Moshe

Comment by Eric Sedor [ 06/Mar/19 ]

Thanks for writing. Would you please archive (tar or zip) the MongoDB $dbpath/diagnostic.data directory and attach it to this ticket along with the server logs leading up to the invocation of the OOM killer?

Sincerely,
Eric

Generated at Thu Feb 08 04:53:41 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.