micronaut-projects / micronaut-core

Micronaut Application Framework
http://micronaut.io
Apache License 2.0
6.07k stars 1.07k forks source link

Memory Consumption Increase For Each Request #6623

Closed JasonTypesCodes closed 2 years ago

JasonTypesCodes commented 2 years ago

Expected Behavior

Memory footprint should not drastically increase with each request

Actual Behaviour

As reported by @mraible on Twitter:

Prompted by a comment on the post, I also tested memory used after 5 requests. I discovered that micronautfw seems to increase the memory used by 20 MB with each request. Quarkus and Spring Boot only increased by 1-2 MB.

https://twitter.com/mraible/status/1468994218190413828

Steps To Reproduce

Matt described his process in this blog post: https://developer.okta.com/blog/2021/06/18/native-java-framework-comparison

Environment Information

No response

Example Application

https://github.com/oktadev/native-java-examples

Version

3.2.1

JasonTypesCodes commented 2 years ago

Suspect this is related to: https://github.com/micronaut-projects/micronaut-core/issues/6619

ilopmar commented 2 years ago

I'm able to reproduce this with our basic-app that only uses Netty and returns a POJO converted to json.

To get the memory consumption from Linux I run (which is not the same command that Matt runs on Mac):

ps eo user,pid,vsz,rss $(pgrep -f 'basic-app') | awk '{$4=int($4/1024)"M";}{ print;}'

After creating the native image from that repository I execute curl -s localhost:8080/hello/Micronaut multiple times and after every request I get the memory with the previous ps command.

This is the result (the last column is the RSS)

USER PID VSZ RSS
ivan 37877 1147508 49M
ivan 37877 1241724 56M
ivan 37877 1334916 59M
ivan 37877 1428108 62M
ivan 37877 1521300 65M
ivan 37877 1614492 68M
ivan 37877 1707684 70M
ivan 37877 1800876 73M
ivan 37877 1894068 76M
ivan 37877 1987260 79M
ivan 37877 2080452 82M
ivan 37877 2260692 85M
ivan 37877 2353884 88M
ivan 37877 2447076 91M
yawkat commented 2 years ago

(paraphrasing from slack)

I think the premise here is wrong. Constantly increasing RSS is expected before the maximum heap size is reached, because the JVM will just do bump pointer allocation without GC. Since the Xmx is unset, the max heap size is by default fairly high, so this is expected behavior. It doesn't imply a memory leak, it could simply be caused by many short-lived objects.

I've done two tests:

       bytes  percent  samples  top
  ----------  -------  -------  ---
  1245242544    8.61%     8015  java.util.Optional
  1087103464    7.52%     6921  byte[]
  1019227512    7.05%     6556  java.lang.Object[]
   935257632    6.47%     5979  io.micronaut.http.server.context.ServerRequestContextInvocationInstrumenter$$Lambda$437
   633216256    4.38%     4013  java.util.ArrayList
   630461456    4.36%     3980  java.lang.String
   510886808    3.53%     3285  int[]
   375637760    2.60%     2382  java.util.LinkedHashMap
   359142648    2.48%     2256  io.micronaut.reactive.reactor.instrument.ReactorSubscriber
   353286856    2.44%     2267  reactor.core.publisher.FluxFlatMap$FlatMapMain
   334002864    2.31%     2125  io.netty.handler.codec.DefaultHeaders$HeaderEntry
   285203800    1.97%     1809  java.util.HashMap$Node[]
   248689008    1.72%     1581  io.micronaut.core.type.DefaultArgument
   236365960    1.64%     1510  io.micronaut.http.server.context.ServerRequestContextInvocationInstrumenter
   235672328    1.63%     1548  java.util.regex.Matcher
   219186424    1.52%     1376  java.lang.String[]
   203684544    1.41%     1269  java.util.LinkedHashMap$Entry
   198913728    1.38%     1244  io.micronaut.core.convert.DefaultArgumentConversionContext
   191924720    1.33%     1286  reactor.core.publisher.FluxLift
   188668200    1.31%     1338  java.lang.Integer
   171575032    1.19%     1078  java.lang.StringBuilder
   171165320    1.18%     1118  reactor.core.publisher.FluxFlatMap$FlatMapInner
   169466464    1.17%     1117  io.netty.handler.codec.DefaultHeaders$ValueIterator
   166400720    1.15%     1064  char[]
   162368632    1.12%     1061  reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber
   161509656    1.12%     1041  reactor.core.publisher.FluxFlatMap
   151654336    1.05%      970  reactor.core.publisher.FluxLiftFuseable
   139629200    0.97%      896  reactor.core.publisher.Operators$ScalarSubscription
   139128152    0.96%      905  io.netty.handler.codec.DefaultHeaders$HeaderEntry[]
   136826024    0.95%      864  java.util.HashMap$Node
   109886960    0.76%      688  reactor.core.publisher.FluxFlatMap$FlatMapInner[]
   106816192    0.74%      681  java.util.LinkedList
    95213296    0.66%      616  sun.util.calendar.ZoneInfo
    85708336    0.59%      552  io.micronaut.http.server.netty.NettyHttpRequest
    85632840    0.59%      550  com.fasterxml.jackson.core.json.JsonWriteContext
    81028784    0.56%      498  reactor.core.publisher.FluxOnErrorResume
    80444232    0.56%      511  java.util.LinkedHashMap$LinkedEntryIterator
    75324528    0.52%      467  java.net.URI
    74019784    0.51%      481  com.fasterxml.jackson.core.json.UTF8JsonGenerator
    65020944    0.45%      428  io.netty.handler.codec.DefaultHeadersImpl
    63045448    0.44%      398  io.micronaut.core.convert.DefaultConversionService$ConvertiblePair
    62780768    0.43%      399  com.fasterxml.jackson.databind.ser.DefaultSerializerProvider$Impl
    59294648    0.41%      361  java.util.concurrent.ConcurrentHashMap
    59223520    0.41%      364  java.util.concurrent.ConcurrentHashMap$Node
    59073688    0.41%      376  java.util.regex.IntHashSet[]
    56279528    0.39%      350  reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber
    54270488    0.38%      327  io.micronaut.web.router.DefaultUriRouteMatch
    53072056    0.37%      326  reactor.core.publisher.FluxJust
    51522232    0.36%      332  java.util.ArrayList$Itr
    47749416    0.33%      315  io.micronaut.http.netty.NettyMutableHttpResponse
    47236696    0.33%      296  com.fasterxml.jackson.core.io.IOContext
    46802160    0.32%      284  java.time.ZonedDateTime
    46041168    0.32%      270  reactor.core.publisher.StrictSubscriber
    45563424    0.32%      292  java.time.LocalDateTime
    44101744    0.31%      265  java.util.HashMap
    42977176    0.30%      283  java.util.concurrent.ConcurrentHashMap$Node[]
    42806504    0.30%      281  reactor.core.publisher.MonoLiftFuseable
    39884040    0.28%      265  java.time.Instant
    39837176    0.28%      264  io.micronaut.core.convert.value.MutableConvertibleValuesMap
    39448480    0.27%      253  io.micronaut.http.server.RouteExecutor$3
    39180888    0.27%      257  java.util.LinkedList$Node
    38875088    0.27%      239  reactor.core.publisher.FluxHide$SuppressFuseableSubscriber
    38853392    0.27%      256  reactor.core.publisher.FluxPeek
    37910152    0.26%      240  io.netty.channel.DefaultChannelPromise
    36994736    0.26%      239  io.micronaut.http.netty.NettyHttpHeaders
    36338344    0.25%      244  java.time.LocalTime
    33791008    0.23%      216  io.netty.handler.codec.http.DefaultFullHttpResponse
    32092864    0.22%      194  io.micronaut.http.server.RouteExecutor$$Lambda$443
    31784632    0.22%      197  java.util.Collections$UnmodifiableMap
    31677688    0.22%      192  io.micronaut.http.server.RouteExecutor$$Lambda$424
    31525296    0.22%      204  io.netty.buffer.ByteBufOutputStream
    31355392    0.22%      189  reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber
    30366432    0.21%      195  io.micronaut.http.server.netty.NettyHttpRequest$$Lambda$487
    30260552    0.21%      211  java.time.LocalDate
    29958800    0.21%      177  io.micronaut.http.server.RouteExecutor$$Lambda$438
    29599144    0.20%      195  io.micronaut.http.server.netty.RoutingInBoundHandler$2
    28832584    0.20%      177  io.micronaut.web.router.DefaultRouter$$Lambda$412
    28369376    0.20%      187  java.net.URI$Parser
    27653224    0.19%      189  io.micronaut.http.server.RouteExecutor$$Lambda$442
    25256312    0.17%      162  reactor.core.publisher.FluxPeek$PeekSubscriber
    25069784    0.17%      165  io.netty.handler.codec.http.DefaultHttpHeaders
    24288728    0.17%      149  io.micronaut.http.server.RouteExecutor$$Lambda$441
    24260344    0.17%      148  io.micronaut.http.uri.UriMatchTemplate$DefaultUriMatchInfo
    24208528    0.17%      159  io.netty.handler.codec.http.DefaultHttpRequest
    24084240    0.17%      165  io.micronaut.http.server.RouteExecutor$$Lambda$440
    23287512    0.16%      136  reactor.core.publisher.FluxSwitchIfEmpty
    23045688    0.16%      145  io.micronaut.http.server.netty.RoutingInBoundHandler$$Lambda$488
    22616408    0.16%      141  reactor.util.context.Context1
    22300600    0.15%      134  long[]
    22251520    0.15%      134  io.micronaut.http.server.RouteExecutor$$Lambda$435
    21864432    0.15%      149  reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber
    21564856    0.15%      138  io.micronaut.http.netty.NettyMutableHttpResponse$1
    21199120    0.15%      135  io.micronaut.http.server.netty.NettyHttpRequest$1
    21195064    0.15%      119  io.micronaut.http.server.RouteExecutor$$Lambda$417
    21156504    0.15%      126  io.micronaut.http.server.netty.RoutingInBoundHandler$$Lambda$486
    20878408    0.14%      132  java.lang.Long
    20805400    0.14%      134  java.util.Arrays$ArrayItr
    20665312    0.14%      141  io.netty.handler.codec.DefaultHeaders$HeaderIterator
    20524208    0.14%      133  io.micronaut.http.server.RouteExecutor$$Lambda$425
    20467056    0.14%      128  java.time.format.DateTimePrintContext
    20041336    0.14%      131  io.netty.handler.codec.http.HttpMessageDecoderResult
    19632496    0.14%      127  io.micronaut.http.server.RouteExecutor$$Lambda$434
    19309296    0.13%      132  io.micronaut.http.server.netty.decoders.HttpRequestDecoder$$Lambda$407
    19160040    0.13%      123  reactor.core.publisher.FluxContextWrite
    19064392    0.13%      126  java.util.Collections$UnmodifiableRandomAccessList
    19026120    0.13%      115  io.micronaut.core.util.SupplierUtil$2
    17087384    0.12%      122  io.micronaut.http.netty.stream.EmptyHttpRequest
    16839504    0.12%      113  io.micronaut.http.context.event.HttpRequestTerminatedEvent
    16155624    0.11%      106  io.netty.handler.stream.ChunkedWriteHandler$PendingWrite
    16137560    0.11%      106  reactor.core.publisher.FluxMapFuseable
    15850808    0.11%      107  io.micronaut.http.context.event.HttpRequestReceivedEvent
    15784056    0.11%      105  reactor.core.publisher.MonoJust
    15634864    0.11%       99  reactor.core.publisher.FluxDefer
    14856024    0.10%       98  io.micronaut.http.server.RouteExecutor$$Lambda$452
    14462208    0.10%       98  reactor.core.publisher.FluxSourceMonoFuseable
    14447248    0.10%       86  io.micronaut.web.router.DefaultRouter$$Lambda$433
    13402072    0.09%       80  io.micronaut.http.server.netty.NettyHttpRequest$$Lambda$406
    13339544    0.09%       78  io.micronaut.http.server.netty.RoutingInBoundHandler$$Lambda$436
    12988496    0.09%       79  io.micronaut.core.util.SupplierUtil$2$$Lambda$282
    12549704    0.09%       86  java.util.concurrent.atomic.AtomicReference
    12514096    0.09%       83  io.micronaut.http.netty.NettyMutableHttpResponse$$Lambda$447
    12189872    0.08%       82  java.util.concurrent.atomic.AtomicBoolean
    11899120    0.08%       82  reactor.core.publisher.MonoSupplier
    11611336    0.08%       78  java.util.HashMap$Values
    11405736    0.08%       78  java.util.concurrent.atomic.AtomicInteger
    10504608    0.07%       68  java.util.LinkedHashMap$LinkedValues
    10317176    0.07%       73  example.micronaut.basic.Greeting
    10272632    0.07%       71  reactor.core.publisher.FluxDeferContextual
     8955096    0.06%       55  io.micronaut.core.value.MapValueResolver
     8752152    0.06%       56  short[]
     1155200    0.01%        7  io.netty.buffer.SimpleLeakAwareByteBuf
      953488    0.01%        7  io.netty.util.ResourceLeakDetector$TraceRecord
      759336    0.01%        7  io.netty.util.ResourceLeakDetector$DefaultResourceLeak

This looks to me like there are many small allocations all over the place, and no single cause or memory leak.

So, I would say this is expected behavior.

yawkat commented 2 years ago

Okay I've taken a look at the RSS for basic-app. I wanted to validate whether the excess memory use we're seeing is actually caused by the heap. For this, I ran the basic-app and performed two requests to the REST endpoint. In between, I did pmap -x to see in which regions additional resident memory was used. At the end, I did a core dump and looked at those regions in ghidra.

pmaps:

43751:   build/native/nativeCompile/basic-app
Address           Kbytes     RSS   Dirty Mode  Mapping
000055830aee8000    2856    2856       0 r---- basic-app
000055830b1b2000   26036   13432       0 r-x-- basic-app
000055830cb1f000   27764    3620    3540 r---- basic-app
000055830e63c000      20      20      20 r---- basic-app
000055830e641000      16      16      16 rw--- basic-app
000055830ef8f000     616     196     196 rw---   [ anon ]
00007f3698000000     132       4       4 rw---   [ anon ]
00007f3698021000   65404       0       0 -----   [ anon ]
00007f36a0000000     132       4       4 rw---   [ anon ]
00007f36a0021000   65404       0       0 -----   [ anon ]
00007f36a4000000     132       4       4 rw---   [ anon ]
00007f36a4021000   65404       0       0 -----   [ anon ]
00007f36a8000000     132       4       4 rw---   [ anon ]
00007f36a8021000   65404       0       0 -----   [ anon ]
00007f36ac000000     132       4       4 rw---   [ anon ]
00007f36ac021000   65404       0       0 -----   [ anon ]
00007f36b37ff000       4       0       0 -----   [ anon ]
00007f36b3800000    8192       8       8 rw---   [ anon ]
00007f36b4000000     132       4       4 rw---   [ anon ]
00007f36b4021000   65404       0       0 -----   [ anon ]
00007f36b8000000    1024     100     100 rw---   [ anon ]
00007f36b8200000    1024       8       8 rw---   [ anon ]
00007f36b83ff000       4       0       0 -----   [ anon ]
00007f36b8400000    9216     616     616 rw---   [ anon ]
00007f36b8e00000    1024    1024    1024 rw---   [ anon ]
00007f36b9000000    1024    1020    1020 rw---   [ anon ]
00007f36b9200000    1024    1024    1024 rw---   [ anon ]
00007f36b9400000    1024    1024    1024 rw---   [ anon ]
00007f36b9600000    1024      72      72 rw---   [ anon ]
00007f36b9800000    1024     188     188 rw---   [ anon ]
00007f36b9a00000    1024      72      72 rw---   [ anon ]
00007f36b9bfe000       4       0       0 -----   [ anon ]
00007f36b9bff000    8192      12      12 rw---   [ anon ]
00007f36ba3ff000       4       0       0 -----   [ anon ]
00007f36ba400000    9216      92      92 rw---   [ anon ]
00007f36badfe000       4       0       0 -----   [ anon ]
00007f36badff000    8192       8       8 rw---   [ anon ]
00007f36bb600000    1024      80      80 rw---   [ anon ]
00007f36bb7ff000       4       0       0 -----   [ anon ]
00007f36bb800000    8192       8       8 rw---   [ anon ]
00007f36bc000000     132       4       4 rw---   [ anon ]
00007f36bc021000   65404       0       0 -----   [ anon ]
00007f36c0000000     132       4       4 rw---   [ anon ]
00007f36c0021000   65404       0       0 -----   [ anon ]
00007f36c4000000     132       4       4 rw---   [ anon ]
00007f36c4021000   65404       0       0 -----   [ anon ]
00007f36c8000000     132       4       4 rw---   [ anon ]
00007f36c8021000   65404       0       0 -----   [ anon ]
00007f36cc000000     132       4       4 rw---   [ anon ]
00007f36cc021000   65404       0       0 -----   [ anon ]
00007f36d0000000     132       4       4 rw---   [ anon ]
00007f36d0021000   65404       0       0 -----   [ anon ]
00007f36d4100000    1024     212     212 rw---   [ anon ]
00007f36d4300000    1024      92      92 rw---   [ anon ]
00007f36d4500000    1024      72      72 rw---   [ anon ]
00007f36d46fd000       4       0       0 -----   [ anon ]
00007f36d46fe000    8192       8       8 rw---   [ anon ]
00007f36d4efe000       4       0       0 -----   [ anon ]
00007f36d4eff000    8192       8       8 rw---   [ anon ]
00007f36d56ff000       4       0       0 -----   [ anon ]
00007f36d5700000    9216     104     104 rw---   [ anon ]
00007f36d60fe000       4       0       0 -----   [ anon ]
00007f36d60ff000    8192       8       8 rw---   [ anon ]
00007f36d68ff000       4       0       0 -----   [ anon ]
00007f36d6900000    9216     104     104 rw---   [ anon ]
00007f36d72ff000       4       0       0 -----   [ anon ]
00007f36d7300000    9216    1036    1036 rw---   [ anon ]
00007f36d7d00000    6384    5808       0 r---- basic-app
00007f36d833c000    2832    2832    2832 r----   [ anon ]
00007f36d8600000     720     720     720 rw---   [ anon ]
00007f36d86b4000    9520    6412     612 rw--- basic-app
00007f36d9000000    8192    3904       0 r---- basic-app
00007f36d98eb000       4       4       0 r---- libnss_mdns4_minimal.so.2
00007f36d98ec000       8       8       0 r-x-- libnss_mdns4_minimal.so.2
00007f36d98ee000       4       4       0 r---- libnss_mdns4_minimal.so.2
00007f36d98ef000       4       4       4 r---- libnss_mdns4_minimal.so.2
00007f36d98f0000       4       4       4 rw--- libnss_mdns4_minimal.so.2
00007f36d98f1000     208     204     204 rw---   [ anon ]
00007f36d9925000     176     176       0 r---- libc.so.6
00007f36d9951000    1616    1248       0 r-x-- libc.so.6
00007f36d9ae5000     336     168       0 r---- libc.so.6
00007f36d9b39000       4       0       0 ----- libc.so.6
00007f36d9b3a000      12      12      12 r---- libc.so.6
00007f36d9b3d000      12      12      12 rw--- libc.so.6
00007f36d9b40000      60      28      28 rw---   [ anon ]
00007f36d9b65000       4       4       0 r---- ld-linux-x86-64.so.2
00007f36d9b66000     160     160       0 r-x-- ld-linux-x86-64.so.2
00007f36d9b8e000      40      40       0 r---- ld-linux-x86-64.so.2
00007f36d9b98000       8       8       8 r---- ld-linux-x86-64.so.2
00007f36d9b9a000       8       8       8 rw--- ld-linux-x86-64.so.2
00007ffc2367a000     136      24      24 rw---   [ stack ]
00007ffc236b3000      16       0       0 r----   [ anon ]
00007ffc236b7000       8       4       0 r-x--   [ anon ]
ffffffffff600000       4       0       0 --x--   [ anon ]
---------------- ------- ------- ------- 
total kB          991004   48984   15288
43751:   build/native/nativeCompile/basic-app
Address           Kbytes     RSS   Dirty Mode  Mapping
000055830aee8000    2856    2856       0 r---- basic-app
000055830b1b2000   26036   16632       0 r-x-- basic-app
000055830cb1f000   27764    3620    3540 r---- basic-app
000055830e63c000      20      20      20 r---- basic-app
000055830e641000      16      16      16 rw--- basic-app
000055830ef8f000     616     196     196 rw---   [ anon ]
00007f3698000000     132       4       4 rw---   [ anon ]
00007f3698021000   65404       0       0 -----   [ anon ]
00007f369c000000     132       8       8 rw---   [ anon ]
00007f369c021000   65404       0       0 -----   [ anon ]
00007f36a0000000     132       4       4 rw---   [ anon ]
00007f36a0021000   65404       0       0 -----   [ anon ]
00007f36a4000000     132       4       4 rw---   [ anon ]
00007f36a4021000   65404       0       0 -----   [ anon ]
00007f36a8000000     132       4       4 rw---   [ anon ]
00007f36a8021000   65404       0       0 -----   [ anon ]
00007f36ac000000     132       4       4 rw---   [ anon ]
00007f36ac021000   65404       0       0 -----   [ anon ]
00007f36b1800000    1024     176     176 rw---   [ anon ]
00007f36b19ff000   17412   17412   17412 rw---   [ anon ]
00007f36b2c00000    1024    1024    1024 rw---   [ anon ]
00007f36b2e00000    1024    1024    1024 rw---   [ anon ]
00007f36b2ffe000       4       0       0 -----   [ anon ]
00007f36b2fff000    8192      20      20 rw---   [ anon ]
00007f36b37ff000       4       0       0 -----   [ anon ]
00007f36b3800000    8192       8       8 rw---   [ anon ]
00007f36b4000000     132       4       4 rw---   [ anon ]
00007f36b4021000   65404       0       0 -----   [ anon ]
00007f36b8000000    1024     508     508 rw---   [ anon ]
00007f36b8200000    1024       8       8 rw---   [ anon ]
00007f36b83ff000       4       0       0 -----   [ anon ]
00007f36b8400000    9216     616     616 rw---   [ anon ]
00007f36b8e00000    1024    1024    1024 rw---   [ anon ]
00007f36b9000000    1024    1020    1020 rw---   [ anon ]
00007f36b9200000    1024    1024    1024 rw---   [ anon ]
00007f36b9400000    1024    1024    1024 rw---   [ anon ]
00007f36b9600000    1024      72      72 rw---   [ anon ]
00007f36b9800000    1024     188     188 rw---   [ anon ]
00007f36b9a00000    1024      72      72 rw---   [ anon ]
00007f36b9bfe000       4       0       0 -----   [ anon ]
00007f36b9bff000    8192      12      12 rw---   [ anon ]
00007f36ba3ff000       4       0       0 -----   [ anon ]
00007f36ba400000    9216      92      92 rw---   [ anon ]
00007f36badfe000       4       0       0 -----   [ anon ]
00007f36badff000    8192       8       8 rw---   [ anon ]
00007f36bb600000    1024      80      80 rw---   [ anon ]
00007f36bb7ff000       4       0       0 -----   [ anon ]
00007f36bb800000    8192       8       8 rw---   [ anon ]
00007f36bc000000     132       4       4 rw---   [ anon ]
00007f36bc021000   65404       0       0 -----   [ anon ]
00007f36c0000000     132       4       4 rw---   [ anon ]
00007f36c0021000   65404       0       0 -----   [ anon ]
00007f36c4000000     132       4       4 rw---   [ anon ]
00007f36c4021000   65404       0       0 -----   [ anon ]
00007f36c8000000     132       4       4 rw---   [ anon ]
00007f36c8021000   65404       0       0 -----   [ anon ]
00007f36cc000000     132       4       4 rw---   [ anon ]
00007f36cc021000   65404       0       0 -----   [ anon ]
00007f36d0000000     132       4       4 rw---   [ anon ]
00007f36d0021000   65404       0       0 -----   [ anon ]
00007f36d4100000    1024     212     212 rw---   [ anon ]
00007f36d4300000    1024      92      92 rw---   [ anon ]
00007f36d4500000    1024      72      72 rw---   [ anon ]
00007f36d46fd000       4       0       0 -----   [ anon ]
00007f36d46fe000    8192       8       8 rw---   [ anon ]
00007f36d4efe000       4       0       0 -----   [ anon ]
00007f36d4eff000    8192       8       8 rw---   [ anon ]
00007f36d56ff000       4       0       0 -----   [ anon ]
00007f36d5700000    9216     104     104 rw---   [ anon ]
00007f36d60fe000       4       0       0 -----   [ anon ]
00007f36d60ff000    8192       8       8 rw---   [ anon ]
00007f36d68ff000       4       0       0 -----   [ anon ]
00007f36d6900000    9216     104     104 rw---   [ anon ]
00007f36d72ff000       4       0       0 -----   [ anon ]
00007f36d7300000    9216    1036    1036 rw---   [ anon ]
00007f36d7d00000    6384    5808       0 r---- basic-app
00007f36d833c000    2832    2832    2832 r----   [ anon ]
00007f36d8600000     720     720     720 rw---   [ anon ]
00007f36d86b4000    9520    6988     676 rw--- basic-app
00007f36d9000000    8192    4096       0 r---- basic-app
00007f36d98eb000       4       4       0 r---- libnss_mdns4_minimal.so.2
00007f36d98ec000       8       8       0 r-x-- libnss_mdns4_minimal.so.2
00007f36d98ee000       4       4       0 r---- libnss_mdns4_minimal.so.2
00007f36d98ef000       4       4       4 r---- libnss_mdns4_minimal.so.2
00007f36d98f0000       4       4       4 rw--- libnss_mdns4_minimal.so.2
00007f36d98f1000     208     204     204 rw---   [ anon ]
00007f36d9925000     176     176       0 r---- libc.so.6
00007f36d9951000    1616    1248       0 r-x-- libc.so.6
00007f36d9ae5000     336     168       0 r---- libc.so.6
00007f36d9b39000       4       0       0 ----- libc.so.6
00007f36d9b3a000      12      12      12 r---- libc.so.6
00007f36d9b3d000      12      12      12 rw--- libc.so.6
00007f36d9b40000      60      28      28 rw---   [ anon ]
00007f36d9b65000       4       4       0 r---- ld-linux-x86-64.so.2
00007f36d9b66000     160     160       0 r-x-- ld-linux-x86-64.so.2
00007f36d9b8e000      40      40       0 r---- ld-linux-x86-64.so.2
00007f36d9b98000       8       8       8 r---- ld-linux-x86-64.so.2
00007f36d9b9a000       8       8       8 rw--- ld-linux-x86-64.so.2
00007ffc2367a000     136      24      24 rw---   [ stack ]
00007ffc236b3000      16       0       0 r----   [ anon ]
00007ffc236b7000       8       4       0 r-x--   [ anon ]
ffffffffff600000       4       0       0 --x--   [ anon ]
---------------- ------- ------- ------- 
total kB         1085220   73024   35424
43751:   build/native/nativeCompile/basic-app
Address           Kbytes     RSS   Dirty Mode  Mapping
000055830aee8000    2856    2856       0 r---- basic-app
000055830b1b2000   26036   16632       0 r-x-- basic-app
000055830cb1f000   27764    3620    3540 r---- basic-app
000055830e63c000      20      20      20 r---- basic-app
000055830e641000      16      16      16 rw--- basic-app
000055830ef8f000     616     196     196 rw---   [ anon ]
00007f3690000000     132       4       4 rw---   [ anon ]
00007f3690021000   65404       0       0 -----   [ anon ]
00007f3696fff000   16388   16388   16388 rw---   [ anon ]
00007f3698000000     132       8       8 rw---   [ anon ]
00007f3698021000   65404       0       0 -----   [ anon ]
00007f369c000000     132       8       8 rw---   [ anon ]
00007f369c021000   65404       0       0 -----   [ anon ]
00007f36a0000000     132       4       4 rw---   [ anon ]
00007f36a0021000   65404       0       0 -----   [ anon ]
00007f36a4000000     132       4       4 rw---   [ anon ]
00007f36a4021000   65404       0       0 -----   [ anon ]
00007f36a8000000     132       4       4 rw---   [ anon ]
00007f36a8021000   65404       0       0 -----   [ anon ]
00007f36ac000000     132       4       4 rw---   [ anon ]
00007f36ac021000   65404       0       0 -----   [ anon ]
00007f36b0a00000    1024     912     912 rw---   [ anon ]
00007f36b0c00000    1024    1024    1024 rw---   [ anon ]
00007f36b0e00000    1024    1024    1024 rw---   [ anon ]
00007f36b0fff000       4       0       0 -----   [ anon ]
00007f36b1000000    9216     192     192 rw---   [ anon ]
00007f36b19ff000   17412   17412   17412 rw---   [ anon ]
00007f36b2c00000    1024    1024    1024 rw---   [ anon ]
00007f36b2e00000    1024    1024    1024 rw---   [ anon ]
00007f36b2ffe000       4       0       0 -----   [ anon ]
00007f36b2fff000    8192      20      20 rw---   [ anon ]
00007f36b37ff000       4       0       0 -----   [ anon ]
00007f36b3800000    8192       8       8 rw---   [ anon ]
00007f36b4000000     132       4       4 rw---   [ anon ]
00007f36b4021000   65404       0       0 -----   [ anon ]
00007f36b8000000    1024     512     512 rw---   [ anon ]
00007f36b8200000    1024       8       8 rw---   [ anon ]
00007f36b83ff000       4       0       0 -----   [ anon ]
00007f36b8400000    9216     616     616 rw---   [ anon ]
00007f36b8e00000    1024    1024    1024 rw---   [ anon ]
00007f36b9000000    1024    1020    1020 rw---   [ anon ]
00007f36b9200000    1024    1024    1024 rw---   [ anon ]
00007f36b9400000    1024    1024    1024 rw---   [ anon ]
00007f36b9600000    1024      72      72 rw---   [ anon ]
00007f36b9800000    1024     188     188 rw---   [ anon ]
00007f36b9a00000    1024      72      72 rw---   [ anon ]
00007f36b9bfe000       4       0       0 -----   [ anon ]
00007f36b9bff000    8192      12      12 rw---   [ anon ]
00007f36ba3ff000       4       0       0 -----   [ anon ]
00007f36ba400000    9216      92      92 rw---   [ anon ]
00007f36badfe000       4       0       0 -----   [ anon ]
00007f36badff000    8192       8       8 rw---   [ anon ]
00007f36bb600000    1024      80      80 rw---   [ anon ]
00007f36bb7ff000       4       0       0 -----   [ anon ]
00007f36bb800000    8192       8       8 rw---   [ anon ]
00007f36bc000000     132       4       4 rw---   [ anon ]
00007f36bc021000   65404       0       0 -----   [ anon ]
00007f36c0000000     132       4       4 rw---   [ anon ]
00007f36c0021000   65404       0       0 -----   [ anon ]
00007f36c4000000     132       4       4 rw---   [ anon ]
00007f36c4021000   65404       0       0 -----   [ anon ]
00007f36c8000000     132       4       4 rw---   [ anon ]
00007f36c8021000   65404       0       0 -----   [ anon ]
00007f36cc000000     132       4       4 rw---   [ anon ]
00007f36cc021000   65404       0       0 -----   [ anon ]
00007f36d0000000     132       4       4 rw---   [ anon ]
00007f36d0021000   65404       0       0 -----   [ anon ]
00007f36d4100000    1024     212     212 rw---   [ anon ]
00007f36d4300000    1024      92      92 rw---   [ anon ]
00007f36d4500000    1024      72      72 rw---   [ anon ]
00007f36d46fd000       4       0       0 -----   [ anon ]
00007f36d46fe000    8192       8       8 rw---   [ anon ]
00007f36d4efe000       4       0       0 -----   [ anon ]
00007f36d4eff000    8192       8       8 rw---   [ anon ]
00007f36d56ff000       4       0       0 -----   [ anon ]
00007f36d5700000    9216     104     104 rw---   [ anon ]
00007f36d60fe000       4       0       0 -----   [ anon ]
00007f36d60ff000    8192       8       8 rw---   [ anon ]
00007f36d68ff000       4       0       0 -----   [ anon ]
00007f36d6900000    9216     104     104 rw---   [ anon ]
00007f36d72ff000       4       0       0 -----   [ anon ]
00007f36d7300000    9216    1036    1036 rw---   [ anon ]
00007f36d7d00000    6384    5808       0 r---- basic-app
00007f36d833c000    2832    2832    2832 r----   [ anon ]
00007f36d8600000     720     720     720 rw---   [ anon ]
00007f36d86b4000    9520    6988     676 rw--- basic-app
00007f36d9000000    8192    4096       0 r---- basic-app
00007f36d98eb000       4       4       0 r---- libnss_mdns4_minimal.so.2
00007f36d98ec000       8       8       0 r-x-- libnss_mdns4_minimal.so.2
00007f36d98ee000       4       4       0 r---- libnss_mdns4_minimal.so.2
00007f36d98ef000       4       4       4 r---- libnss_mdns4_minimal.so.2
00007f36d98f0000       4       4       4 rw--- libnss_mdns4_minimal.so.2
00007f36d98f1000     208     204     204 rw---   [ anon ]
00007f36d9925000     176     176       0 r---- libc.so.6
00007f36d9951000    1616    1248       0 r-x-- libc.so.6
00007f36d9ae5000     336     168       0 r---- libc.so.6
00007f36d9b39000       4       0       0 ----- libc.so.6
00007f36d9b3a000      12      12      12 r---- libc.so.6
00007f36d9b3d000      12      12      12 rw--- libc.so.6
00007f36d9b40000      60      28      28 rw---   [ anon ]
00007f36d9b65000       4       4       0 r---- ld-linux-x86-64.so.2
00007f36d9b66000     160     160       0 r-x-- ld-linux-x86-64.so.2
00007f36d9b8e000      40      40       0 r---- ld-linux-x86-64.so.2
00007f36d9b98000       8       8       8 r---- ld-linux-x86-64.so.2
00007f36d9b9a000       8       8       8 rw--- ld-linux-x86-64.so.2
00007ffc2367a000     136      24      24 rw---   [ stack ]
00007ffc236b3000      16       0       0 r----   [ anon ]
00007ffc236b7000       8       4       0 r-x--   [ anon ]
ffffffffff600000       4       0       0 --x--   [ anon ]
---------------- ------- ------- ------- 
total kB         1178412   92400   54800

The diff between 1st and 2nd is:

--- <unnamed>
+++ <unnamed>
@@ -1,13 +1,15 @@
 43751:   build/native/nativeCompile/basic-app
 Address           Kbytes     RSS   Dirty Mode  Mapping
 000055830aee8000    2856    2856       0 r---- basic-app
-000055830b1b2000   26036   13432       0 r-x-- basic-app
+000055830b1b2000   26036   16632       0 r-x-- basic-app
 000055830cb1f000   27764    3620    3540 r---- basic-app
 000055830e63c000      20      20      20 r---- basic-app
 000055830e641000      16      16      16 rw--- basic-app
 000055830ef8f000     616     196     196 rw---   [ anon ]
 00007f3698000000     132       4       4 rw---   [ anon ]
 00007f3698021000   65404       0       0 -----   [ anon ]
+00007f369c000000     132       8       8 rw---   [ anon ]
+00007f369c021000   65404       0       0 -----   [ anon ]
 00007f36a0000000     132       4       4 rw---   [ anon ]
 00007f36a0021000   65404       0       0 -----   [ anon ]
 00007f36a4000000     132       4       4 rw---   [ anon ]
@@ -16,11 +18,17 @@
 00007f36a8021000   65404       0       0 -----   [ anon ]
 00007f36ac000000     132       4       4 rw---   [ anon ]
 00007f36ac021000   65404       0       0 -----   [ anon ]
+00007f36b1800000    1024     176     176 rw---   [ anon ]
+00007f36b19ff000   17412   17412   17412 rw---   [ anon ]
+00007f36b2c00000    1024    1024    1024 rw---   [ anon ]
+00007f36b2e00000    1024    1024    1024 rw---   [ anon ]
+00007f36b2ffe000       4       0       0 -----   [ anon ]
+00007f36b2fff000    8192      20      20 rw---   [ anon ]
 00007f36b37ff000       4       0       0 -----   [ anon ]
 00007f36b3800000    8192       8       8 rw---   [ anon ]
 00007f36b4000000     132       4       4 rw---   [ anon ]
 00007f36b4021000   65404       0       0 -----   [ anon ]
-00007f36b8000000    1024     100     100 rw---   [ anon ]
+00007f36b8000000    1024     508     508 rw---   [ anon ]
 00007f36b8200000    1024       8       8 rw---   [ anon ]
 00007f36b83ff000       4       0       0 -----   [ anon ]
 00007f36b8400000    9216     616     616 rw---   [ anon ]
@@ -70,8 +78,8 @@
 00007f36d7d00000    6384    5808       0 r---- basic-app
 00007f36d833c000    2832    2832    2832 r----   [ anon ]
 00007f36d8600000     720     720     720 rw---   [ anon ]
-00007f36d86b4000    9520    6412     612 rw--- basic-app
-00007f36d9000000    8192    3904       0 r---- basic-app
+00007f36d86b4000    9520    6988     676 rw--- basic-app
+00007f36d9000000    8192    4096       0 r---- basic-app
 00007f36d98eb000       4       4       0 r---- libnss_mdns4_minimal.so.2
 00007f36d98ec000       8       8       0 r-x-- libnss_mdns4_minimal.so.2
 00007f36d98ee000       4       4       0 r---- libnss_mdns4_minimal.so.2
@@ -95,4 +103,4 @@
 00007ffc236b7000       8       4       0 r-x--   [ anon ]
 ffffffffff600000       4       0       0 --x--   [ anon ]
 ---------------- ------- ------- ------- 
-total kB          991004   48984   15288
+total kB         1085220   73024   35424

2nd and 3rd:

--- <unnamed>
+++ <unnamed>
@@ -6,7 +6,10 @@
 000055830e63c000      20      20      20 r---- basic-app
 000055830e641000      16      16      16 rw--- basic-app
 000055830ef8f000     616     196     196 rw---   [ anon ]
-00007f3698000000     132       4       4 rw---   [ anon ]
+00007f3690000000     132       4       4 rw---   [ anon ]
+00007f3690021000   65404       0       0 -----   [ anon ]
+00007f3696fff000   16388   16388   16388 rw---   [ anon ]
+00007f3698000000     132       8       8 rw---   [ anon ]
 00007f3698021000   65404       0       0 -----   [ anon ]
 00007f369c000000     132       8       8 rw---   [ anon ]
 00007f369c021000   65404       0       0 -----   [ anon ]
@@ -18,7 +21,11 @@
 00007f36a8021000   65404       0       0 -----   [ anon ]
 00007f36ac000000     132       4       4 rw---   [ anon ]
 00007f36ac021000   65404       0       0 -----   [ anon ]
-00007f36b1800000    1024     176     176 rw---   [ anon ]
+00007f36b0a00000    1024     912     912 rw---   [ anon ]
+00007f36b0c00000    1024    1024    1024 rw---   [ anon ]
+00007f36b0e00000    1024    1024    1024 rw---   [ anon ]
+00007f36b0fff000       4       0       0 -----   [ anon ]
+00007f36b1000000    9216     192     192 rw---   [ anon ]
 00007f36b19ff000   17412   17412   17412 rw---   [ anon ]
 00007f36b2c00000    1024    1024    1024 rw---   [ anon ]
 00007f36b2e00000    1024    1024    1024 rw---   [ anon ]
@@ -28,7 +35,7 @@
 00007f36b3800000    8192       8       8 rw---   [ anon ]
 00007f36b4000000     132       4       4 rw---   [ anon ]
 00007f36b4021000   65404       0       0 -----   [ anon ]
-00007f36b8000000    1024     508     508 rw---   [ anon ]
+00007f36b8000000    1024     512     512 rw---   [ anon ]
 00007f36b8200000    1024       8       8 rw---   [ anon ]
 00007f36b83ff000       4       0       0 -----   [ anon ]
 00007f36b8400000    9216     616     616 rw---   [ anon ]
@@ -103,4 +110,4 @@
 00007ffc236b7000       8       4       0 r-x--   [ anon ]
 ffffffffff600000       4       0       0 --x--   [ anon ]
 ---------------- ------- ------- ------- 
-total kB         1085220   73024   35424
+total kB         1178412   92400   54800

As you can see, the additional memory use is dominated by two factors: The ~3M from additional resident size in the basic-app r-x region after the first request (probably from code that is loaded when the first request is processed), and new ~16M rw- regions for each request. I've looked at the core dump using ghidra, and the 16M regions both look similar:

00000000  00 00 00 00 00 00 00 00  02 10 00 01 00 00 00 00  |................|
00000010  47 45 54 20 2f 68 65 6c  6c 6f 2f 4d 69 63 72 6f  |GET /hello/Micro|
00000020  6e 61 75 74 20 48 54 54  50 2f 31 2e 31 0d 0a 48  |naut HTTP/1.1..H|
00000030  6f 73 74 3a 20 6c 6f 63  61 6c 68 6f 73 74 3a 38  |ost: localhost:8|
00000040  30 38 30 0d 0a 55 73 65  72 2d 41 67 65 6e 74 3a  |080..User-Agent:|
00000050  20 63 75 72 6c 2f 37 2e  37 34 2e 30 0d 0a 41 63  | curl/7.74.0..Ac|
00000060  63 65 70 74 3a 20 2a 2f  2a 0d 0a 0d 0a 00 00 00  |cept: */*.......|

This looks to me like direct memory, not java heap – there's no object headers or anything. So my guess is this comes from netty.

I've dug a bit in the netty pool alloc code. The buffer pool operates on "chunks" that are sized according to platform parameters. The highest default chunk size is 16M, which is exactly what we're seeing.

So, my conclusion is that for native-image and basic-app, most of the memory per request appears because with every request, netty decides to allocate one more chunk of the direct memory it expects to be allowed to use. On my machine, the direct memory limit that netty decided on was >14GB (!), again because of lack of configured memory limits (no Xmx). So this is caused by normal netty behavior.

lost22git commented 2 years ago

I have found this problem in micronaut before, and the solution of quarkus seems to be to set -Dio.netty.allocator.maxOrder=3 to reduce memory

@see https://github.com/quarkusio/quarkus/pull/16967

zdegner commented 2 years ago

Just a heads up, setting this value too low (maxOrder=1) can cause assertation failures during Netty chunk allocation. I've witnessed this while running tests against Micronaut services with maxOrder=1. The chunk size is calculated as follows:

8192 << MAX ORDER bytes

So for example a max order of 6 would give a chunk size of 524288 bytes. I'm not quite sure what the magic number is, but I've read suggestions of values between 3-7.

netty:
  default:
    allocator:
      max-order: 6

One other interesting tip -- this memory allocation problem only affects the Hotspot JVM, I've never seen the same native memory leak behavior using IBM Semeru (OpenJ9 JVM).

graemerocher commented 2 years ago

@zdegner for new apps we recommend a value of 3 https://micronaut.io/launch?type=DEFAULT&name=demo&package=com.example&javaVersion=JDK_11&lang=JAVA&build=GRADLE&test=JUNIT&version=3.3.0&activity=preview&showing=/src/main/resources/application.yml

yawkat commented 2 years ago

@zdegner And FYI this is not a memory leak, this is simply netty lazily allocating the memory it expects to be allowed to use. If you want to limit netty allocator pool size, there are also other knobs to turn, such as the JVM direct memory limit

MaximeFrancoeur commented 2 years ago

Any news about this problem? https://github.com/micronaut-projects/micronaut-core/pull/6661#issuecomment-1034078024

lost22git commented 2 years ago

Netty has a new adjustment for this parameter:

https://github.com/netty/netty/commit/f650303911e308dfdf10761273c2b8e4436ea0a4