Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

cygwin: stats.mapped is constantly increasing #1040

Closed
j0t opened this issue Oct 2, 2017 · 20 comments
Closed

cygwin: stats.mapped is constantly increasing #1040

j0t opened this issue Oct 2, 2017 · 20 comments

Comments

@j0t
Copy link

j0t commented Oct 2, 2017

Hello, I've trying to utilize jemalloc with some project under Cygwin which uses memory in a quite intense manner in multi-threaded environment. It loads a number of data in memory, aggregates them in parallel, then frees all and then proceeds with next portion. While it shows an excellent CPU utilization due to the fact that each thread works inside its own arena, the process commit size exhibits a constantly increasing trend (Please see the statistics below).
g
It can be seen that stats.allocated and stats.resident are deviating in an expected way while stats.mapped behaves weirdly (at the end my swap file grows up to 160Gb while RAM usage is limited to some reasonable fixed amount). Could someone explain what is happening here? Since there are no trend in stats.allocated and stats.resident, I wouldn't suspect the process for a memory leaks. Is it a signs of an intense memory fragmentation? Or something else? If it helps, I would provide an additional statistics.
PS:

  1. Have built jemalloc using make EXTRA_CFLAGS=-D_WIN32, so it makes a direct calls to WinAPI for memory management from the Cygwin environment.
  2. Compiling in POSIX (i.e. just via invoking make) makes the process run a little bit slower, but the effects are the same.
  3. The similar behavior is seen in a single thread mode also.
@davidtgoldblatt
Copy link
Member

I think Cygwin might be a fundamentally screwy case for something like jemalloc, since our environment detection can get tricked into thinking we're unix-y in some cases, and windows-y in others.

I don't know a ton about the environment; are you able to build jemalloc as a straight-windows .dll and link against it from your cygwin binary? (Is this your case 2?)? If so, it seems like this is an allocation pattern that can happen in a pure-windows environment, so that there's a problem with our Windows handling in general.

@j0t
Copy link
Author

j0t commented Oct 2, 2017

Hello, David! Thank you for a quick response. Yes, I admit, Cygwin probably isn't a good choice, but...

Anyway, let me elaborate the things further:
Cases 1 and 2 are differs only by preprocessor macro _WIN32, in both cases, there is an .dll in output (say, cygjemalloc.dll), which is built using Cygwin's g++ compiler.
Next, concerning linking my binary against straight-windows .dll - I (probably naively) believe, that it could be possible, however, not in an easy way, since in fact, there is an another third party library, which is also using jemalloc for memory allocation in C++. So I will have to build an windows native jemalloc.dll (using VC? or MINGW?) which exports C-interface, and then another wrapper dll (using Cygwin at this time), which adapts calls from Cygwin to native jemalloc C-interface. Not so easy as it seems, taking into account C++ mangling and probably other thing on the way. For the time being, I will try recompiling jemalloc without _WIN32 and then gather the same statistics more accurately, since previously I was only looking at my process commit size in windows task manager.

@davidtgoldblatt
Copy link
Member

Hmm. Yeah, I think we're in sort of uncharted territory here (the mmap and VirtualAlloc interfaces are sufficiently different as to require modified treatment w.r.t. allocation strategies, and getting a mix of both would be "interesting").

I think that compiling jemalloc.dll and wrapping in cygwin might not be as difficult as you fear -- we extern "C" all our public interfaces (so that C++ name mangling shouldn't be an issue), and it's possible to configure jemalloc to do custom namespacing (so that we expose our symbols as, e.g. j0t_malloc, j0t_mallocx, etc.). So you can write your wrapper so that it calls whatever namespaced-version you want, while using the symbols that your target programs expect.

@j0t
Copy link
Author

j0t commented Oct 3, 2017

Well, I suppose there shouldn't be such mixing of interfaces. At least, I was trying to avoid it as much as possible. All memory requests from my code and the libraries as well are directed to jemalloc interface (and there are no significant memory leaks have been discovered by jeprof), so I assume there shouldn't a significant number of calls to mmap was made (Here I'm takling about jemalloc being compiled with -D_WIN32 flag).
Continuing the previous theme, here is the similar graph for jemalloc being compiled without -D_WIN32, just for completeness. It can be seen the same trend for stats.mapped plus the total running time is a slightly longer.
general1
Continue figuring out what to do next...

@davidtgoldblatt
Copy link
Member

A couple questions:

Is the process consuming memory equal to "mapped" instead of "resident" (according to the windows statistics rather than jemalloc ones)?

Could you post the malloc stats for the process? (In particular, I'm interested in some of the opt settings).

@j0t
Copy link
Author

j0t commented Oct 4, 2017

I've decided to concentrate on the module compiled with -D_WIN32 (since it runs faster ;) Here are some results:

  1. gdb session didn't discovered any calls made to mmap, so the chance of interface mixing is low.
  2. statistics produced by running the process with
    export JE_MALLOC_CONF=narenas:4,stats_print:true,prof:true,prof_active:false
___ Begin jemalloc statistics ___
Version: 5.0.1-25-gea91dfa58e11373748f747041c3041f72c9a7658
Assertions disabled
config.malloc_conf: ""
Run-time option settings:
  opt.abort: false
  opt.abort_conf: false
  opt.metadata_thp: false
  opt.retain: false
  opt.dss: "secondary"
  opt.narenas: 4
  opt.percpu_arena: "disabled"
  opt.dirty_decay_ms: 10000 (arenas.dirty_decay_ms: 10000)
  opt.muzzy_decay_ms: 10000 (arenas.muzzy_decay_ms: 10000)
  opt.junk: "false"
  opt.zero: false
  opt.tcache: true
  opt.lg_tcache_max: 15
  opt.prof: true
  opt.prof_prefix: "jeprof"
  opt.prof_active: false (prof.active: false)
  opt.prof_thread_active_init: true (prof.thread_active_init: true)
  opt.lg_prof_sample: 19 (prof.lg_sample: 19)
  opt.prof_accum: false
  opt.lg_prof_interval: -1
  opt.prof_gdump: false
  opt.prof_final: false
  opt.prof_leak: false
  opt.stats_print: true
  opt.stats_print_opts: ""
Arenas: 4
Quantum size: 16
Page size: 65536
Maximum thread-cached size class: 229376
Allocated: 831248, active: 8781824, metadata: 6056312, resident: 65667072, mapped: 528089088, retained: 0
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
background_thread:                  0               0               0               0               0               0           0
ctl:                          6702427               0               0            2521               0               0           0
prof:                            2529               0               0            2521               0               0           0

Merged arenas stats:
assigned threads: 4
uptime: 195858202500
dss allocation precedence: N/A
decaying:  time       npages       sweeps     madvises       purged
   dirty:   N/A          779          454        92105       129359
   muzzy:   N/A            0           72          235          361
                            allocated      nmalloc      ndalloc    nrequests
small:                         831248    100272677    100269502   1167832460
large:                              0          106          106          106
total:                         831248    100272783    100269608   1167832566
active:                       8781824
mapped:                     528089088
retained:                           0
base:                         5796088
internal:                      260224
tcache:                        563776
resident:                    65667072
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                          10116               0               0           10084               0               0           0
extent_avail:                  196917               1              33           14956               0               0           1
extents_dirty:                 326380               0              65           15123               0               0           0
extents_muzzy:                 114385               0               0           14966               0               0           0
extents_retained:              103805               0               0           14699               0               0           0
decay_dirty:                   125444               0               4           12336               0               0           0
decay_muzzy:                   125348               0               3           12312               0               0           0
base:                           24466               0               0           10263               0               0           0
tcache_list:                    10126               0               0           10088               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0           96          549          537      5250370           12            1 8192   1 0.001           26         2549            6            0        12713            0            0              0            0
                  16   1         9008       481930       481367     46302575          563            3 4096   1 0.045       140027       126292           79            0       276626            0            3              0            0
                  32   2        16512      6527533      6527017    860254350          516            8 2048   1 0.031       132036       171934         3153         1480       320423            0            1              0            0
                  48   3        22656     49244892     49244420    175260860          472            4 4096   3 0.028       537111       505067        11756          418      1075814            0           15              0            0
                  64   4        44864      7122602      7121901     43505234          701            6 1024   1 0.114       139023       201433         6956          534       364504            0            6              0            0
                  80   5         8320         3400         3296         2384          104            4 4096   5 0.006          216         2692           52            0        13130            0            0              0            0
                  96   6        12768       432514       432381       252573          133            4 2048   3 0.016       113354       126938          242          128       250893            0            1              0            0
                 112   7            0          100          100       250003            0            0 4096   7 1                1         2532            1            0        12656            0            0              0            0
                 128   8        61952     36005233     36004749     36250064          484            7  512   1 0.135       374736       367060        70374          101       892660            0           16              0            0
                 160   9          160          380          379          133            1            1 2048   5 0.000          126         2659            1            0        12907            0            0              0            0
                 192  10         7104         2469         2432         2457           37            4 1024   3 0.009          284         2743           55            0        13255            0            0              0            0
                 224  11            0          424          424           20            0            0 2048   7 1                8         2545            4            0        12686            0            0              0            0
                 256  12            0          820          820          157            0            0  256   1 1              136         2673          130            0        13194            0            0              0            0
                     ---
                 384  14        14976         2249         2210         1245           39            4  512   3 0.019          116         2646           55            0        12990            0            0              0            0
                     ---
                 512  16            0          430          430           10            0            0  128   1 1                8         2546            4            0        12687            0            0              0            0
                     ---
                 768  18            0          100          100            1            0            0  256   3 1                1         2531            1            0        12655            0            0              0            0
                     ---
                1024  20            0           68           68            3            0            0   64   1 1                2         2533            2            0        12660            0            0              0            0
                     ---
                1536  22            0          100          100            1            0            0  128   3 1                1         2531            1            0        12655            0            0              0            0
                1792  23            0        11396        11396       250000            0            0  256   7 1             6194         8741         6194            0        37444            0            1              0            0
                2048  24         2048           33           32            2            1            1   32   1 0.031            1         2530            2            0        12656            0            0              0            0
                     ---
                3072  26            0           64           64            1            0            0   64   3 1                1         2531            1            0        12655            0            0              0            0
                3584  27       372736       435268       435164       250000          104            3  128   7 0.270       112270       126127         3505          673       255525            0            0              0            0
                4096  28            0           16           16            1            0            0   16   1 1                1         2530            1            0        12654            0            0              0            0
                     ---
                6144  30            0           32           32            1            0            0   32   3 1                1         2530            1            0        12654            0            0              0            0
                7168  31        28672            4            0            4            4            1   64   7 0.062            0         2527            1            0        12653            0            0              0            0
                8192  32            0           10           10            1            0            0    8   1 1                1         2529            2            0        12655            0            0              0            0
                     ---
               12288  34            0           16           16            1            0            0   16   3 1                1         2530            1            0        12654            0            0              0            0
                     ---
               24576  38            0           10           10            1            0            0    8   3 1                1         2530            2            0        12656            0            0              0            0
                     ---
               49152  42            0           10           10            1            0            0    4   3 1                1         2530            3            0        12658            0            0              0            0
               57344  43       229376            5            1            5            4            1    8   7 0.500            0         2527            2            0        12657            0            0              0            0
                     ---
               98304  46            0           10           10            1            0            0    2   3 1                1         2530            5            0        12662            0            0              0            0
                     ---
              196608  50            0           10           10            1            0            0    1   3 1                1         2530           10            0        12672            0            0              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0          100          100          100            0
              393216  54            0            1            1            1            0
                     ---
              786432  58            0            1            1            1            0
                     ---
             1572864  62            0            1            1            1            0
                     ---
             3145728  66            0            1            1            1            0
                     ---
             6291456  70            0            1            1            1            0
                     ---
            12582912  74            0            1            1            1            0
                     ---

arenas[0]:
assigned threads: 1
uptime: 195858202500
dss allocation precedence: secondary
decaying:  time       npages       sweeps     madvises       purged
   dirty: 10000          722          119        22940        32137
   muzzy: 10000            0           19           59          113
                            allocated      nmalloc      ndalloc    nrequests
small:                         279856     25446121     25445780    298896048
large:                              0           31           31           31
total:                         279856     25446152     25445811    298896079
active:                       2818048
mapped:                     172818432
retained:                           0
base:                         2483584
internal:                      260224
tcache:                         12384
resident:                    52625408
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                           2529               0               0            2521               0               0           0
extent_avail:                   49416               0               7            3633               0               0           0
extents_dirty:                  82200               0              17            3676               0               0           0
extents_muzzy:                  28876               0               0            3631               0               0           0
extents_retained:               26232               0               0            3613               0               0           0
decay_dirty:                    31713               0               0            3026               0               0           0
decay_muzzy:                    31685               0               0            3026               0               0           0
base:                            6498               0               0            2569               0               0           0
tcache_list:                     2533               0               0            2522               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0           96          176          164      5250124           12            1 8192   1 0.001           18          662            2            0         3216            0            0              0            0
                  16   1            0       120769       120769     12138427            0            0 4096   1 1            35294        31562           26            0        69441            0            0              0            0
                  32   2         2112      1632356      1632290    215813698           66            1 2048   1 0.032        33030        43015          800          383        80189            0            0              0            0
                  48   3         2304     12311449     12311401     44002417           48            1 4096   3 0.011       134533       126293         2880          129       269117            0            9              0            0
                  64   4        10240      2155795      2155635     12001202          160            3 1024   1 0.052        38482        54142         2050          141        99253            0            1              0            0
                  80   5         2800          893          858          636           35            1 4096   5 0.008           56          697            1            0         3285            0            0              0            0
                  96   6          192       108286       108284        63243            2            1 2048   3 0.000        28386        31800           40           30        62796            0            0              0            0
                 112   7            0          100          100       250003            0            0 4096   7 1                1          657            1            0         3191            0            0              0            0
                 128   8          512      9001283      9001279      9250041            4            1  512   1 0.007        93712        91785        17576           25       223180            0            2              0            0
                 160   9          160          380          379          133            1            1 2048   5 0.000          126          784            1            0         3442            0            0              0            0
                 192  10          192          643          642          627            1            1 1024   3 0.000           68          710            1            0         3310            0            0              0            0
                 224  11            0          106          106            8            0            0 2048   7 1                2          658            1            0         3194            0            0              0            0
                 256  12            0          490          490          134            0            0  256   1 1              129          784          126            0         3696            0            0              0            0
                     ---
                 384  14         1152          577          574          327            3            1  512   3 0.005           31          685            1            0         3248            0            0              0            0
                     ---
                 512  16            0          118          118            3            0            0  128   1 1                3          659            1            0         3195            0            0              0            0
                     ---
                 768  18            0          100          100            1            0            0  256   3 1                1          656            1            0         3190            0            0              0            0
                     ---
                1024  20            0           68           68            3            0            0   64   1 1                2          658            2            0         3195            0            0              0            0
                     ---
                1536  22            0          100          100            1            0            0  128   3 1                1          656            1            0         3190            0            0              0            0
                1792  23            0         2846         2846        62500            0            0  256   7 1             1549         2206         1549            0         9384            0            0              0            0
                2048  24         2048           33           32            2            1            1   32   1 0.031            1          655            2            0         3191            0            0              0            0
                     ---
                3072  26            0           64           64            1            0            0   64   3 1                1          656            1            0         3190            0            0              0            0
                3584  27            0       109366       109366        62500            0            0  128   7 1            27955        31439          883          181        63691            0            0              0            0
                4096  28            0           16           16            1            0            0   16   1 1                1          655            1            0         3189            0            0              0            0
                     ---
                6144  30            0           32           32            1            0            0   32   3 1                1          655            1            0         3189            0            0              0            0
                7168  31        28672            4            0            4            4            1   64   7 0.062            0          652            1            0         3188            0            0              0            0
                8192  32            0           10           10            1            0            0    8   1 1                1          654            2            0         3190            0            0              0            0
                     ---
               12288  34            0           16           16            1            0            0   16   3 1                1          655            1            0         3189            0            0              0            0
                     ---
               24576  38            0           10           10            1            0            0    8   3 1                1          655            2            0         3191            0            0              0            0
                     ---
               49152  42            0           10           10            1            0            0    4   3 1                1          655            3            0         3193            0            0              0            0
               57344  43       229376            5            1            5            4            1    8   7 0.500            0          652            2            0         3192            0            0              0            0
                     ---
               98304  46            0           10           10            1            0            0    2   3 1                1          655            5            0         3197            0            0              0            0
                     ---
              196608  50            0           10           10            1            0            0    1   3 1                1          655           10            0         3207            0            0              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0           25           25           25            0
              393216  54            0            1            1            1            0
                     ---
              786432  58            0            1            1            1            0
                     ---
             1572864  62            0            1            1            1            0
                     ---
             3145728  66            0            1            1            1            0
                     ---
             6291456  70            0            1            1            1            0
                     ---
            12582912  74            0            1            1            1            0
                     ---

arenas[1]:
assigned threads: 1
uptime: 187652733100
dss allocation precedence: secondary
decaying:  time       npages       sweeps     madvises       purged
   dirty: 10000            3          115        23112        32649
   muzzy: 10000            0           21           50           68
                            allocated      nmalloc      ndalloc    nrequests
small:                         184048     24941588     24940682    289644255
large:                              0           25           25           25
total:                         184048     24941613     24940707    289644280
active:                       1966080
mapped:                     120389632
retained:                           0
base:                         1102632
internal:                           0
tcache:                        184048
resident:                     3276800
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                           2529               0               0            2521               0               0           0
extent_avail:                   49286               0               8            3799               0               0           0
extents_dirty:                  81594               0              20            3834               0               0           0
extents_muzzy:                  28543               0               0            3792               0               0           0
extents_retained:               25914               0               0            3727               0               0           0
decay_dirty:                    31251               0               1            3237               0               0           0
decay_muzzy:                    31226               0               1            3231               0               0           0
base:                            5988               0               0            2565               0               0           0
tcache_list:                     2531               0               0            2522               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0            0          124          124           98            0            0 8192   1 1                3          628            1            0         3164            0            0              0            0
                  16   1         3024       119693       119504     11387858          189            1 4096   1 0.046        35233        31732           26            0        69549            0            1              0            0
                  32   2         5120      1631680      1631520    214813386          160            2 2048   1 0.039        32987        42965          785          356        80052            0            0              0            0
                  48   3         5520     12311879     12311764     43752275          115            1 4096   3 0.028       134454       126258         3014           55       269271            0            2              0            0
                  64   4        11904      1655538      1655352     10501034          186            1 1024   1 0.181        33496        49099         1638          134        88412            0            3              0            0
                  80   5         1840          832          809          575           23            1 4096   5 0.005           52          665           25            0         3296            0            0              0            0
                  96   6         4320       107505       107460        63102           45            1 2048   3 0.021        28473        31862           65           32        62994            0            1              0            0
                     ---
                 128   8        16384      9001387      9001259      9000009          128            2  512   1 0.125        93591        91758        17594           26       223066            0            4              0            0
                     ---
                 192  10         2304          634          622          602           12            1 1024   3 0.011           65          679           26            0         3325            0            0              0            0
                 224  11            0          106          106            4            0            0 2048   7 1                2          629            1            0         3164            0            0              0            0
                 256  12            0          106          106            8            0            0  256   1 1                2          629            1            0         3164            0            0              0            0
                     ---
                 384  14         4608          549          537          302           12            1  512   3 0.023           28          653           26            0         3262            0            0              0            0
                     ---
                 512  16            0          106          106            2            0            0  128   1 1                2          629            1            0         3164            0            0              0            0
                     ---
                1792  23            0         2842         2842        62500            0            0  256   7 1             1545         2175         1545            0         9340            0            0              0            0
                     ---
                3584  27       129024       108607       108571        62500           36            1  128   7 0.281        28090        31548          877          158        63921            0            0              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0           25           25           25            0
                     ---

arenas[2]:
assigned threads: 1
uptime: 187652733100
dss allocation precedence: secondary
decaying:  time       npages       sweeps     madvises       purged
   dirty: 10000           16          116        23088        32467
   muzzy: 10000            0           16           76          100
                            allocated      nmalloc      ndalloc    nrequests
small:                         170992     24941750     24940862    289647421
large:                              0           25           25           25
total:                         170992     24941775     24940887    289647446
active:                       1966080
mapped:                     117047296
retained:                           0
base:                         1104936
internal:                           0
tcache:                        170992
resident:                     4128768
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                           2529               0               0            2521               0               0           0
extent_avail:                   49227               1              11            3824               0               0           1
extents_dirty:                  81401               0              20            3839               0               0           0
extents_muzzy:                  28567               0               0            3799               0               0           0
extents_retained:               25887               0               0            3719               0               0           0
decay_dirty:                    31240               0               2            3224               0               0           0
decay_muzzy:                    31219               0               1            3212               0               0           0
base:                            5990               0               0            2566               0               0           0
tcache_list:                     2531               0               0            2522               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0            0          149          149           99            0            0 8192   1 1                4          631            2            0         3171            0            0              0            0
                  16   1         2944       120623       120439     11387855          184            1 4096   1 0.044        34652        31456           26            0        68689            0            1              0            0
                  32   2         3744      1631614      1631497    214814023          117            2 2048   1 0.028        32999        42975          786          362        80087            0            0              0            0
                  48   3         5664     12310451     12310333     43753857          118            1 4096   3 0.028       134303       126263         2933          110       268963            0            4              0            0
                  64   4         9984      1655654      1655498     10501982          156            1 1024   1 0.152        33510        49093         1633          127        88406            0            0              0            0
                  80   5         1840          819          796          575           23            1 4096   5 0.005           52          664           25            0         3295            0            0              0            0
                  96   6         3840       108183       108143        63102           40            1 2048   3 0.019        28300        31693           69           34        62660            0            0              0            0
                     ---
                 128   8        24960      9001315      9001120      9000008          195            2  512   1 0.190        93698        91758        17602           25       223188            0            9              0            0
                     ---
                 192  10         2304          598          586          602           12            1 1024   3 0.011           67          677           26            0         3325            0            0              0            0
                 224  11            0          106          106            4            0            0 2048   7 1                2          629            1            0         3164            0            0              0            0
                 256  12            0          106          106            8            0            0  256   1 1                2          629            1            0         3164            0            0              0            0
                     ---
                 384  14         4608          549          537          302           12            1  512   3 0.023           28          653           26            0         3262            0            0              0            0
                     ---
                 512  16            0          106          106            4            0            0  128   1 1                2          629            1            0         3165            0            0              0            0
                     ---
                1792  23            0         2849         2849        62500            0            0  256   7 1             1546         2176         1546            0         9344            0            0              0            0
                     ---
                3584  27       111104       108628       108597        62500           31            1  128   7 0.242        28109        31566          874          167        63952            0            0              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0           25           25           25            0
                     ---

arenas[3]:
assigned threads: 1
uptime: 187652733100
dss allocation precedence: secondary
decaying:  time       npages       sweeps     madvises       purged
   dirty: 10000           38          104        22965        32106
   muzzy: 10000            0           16           50           80
                            allocated      nmalloc      ndalloc    nrequests
small:                         196352     24943218     24942178    289644736
large:                              0           25           25           25
total:                         196352     24943243     24942203    289644761
active:                       2031616
mapped:                     117833728
retained:                           0
base:                         1104936
internal:                           0
tcache:                        196352
resident:                     5636096
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                           2529               0               0            2521               0               0           0
extent_avail:                   48988               0               7            3700               0               0           0
extents_dirty:                  81185               0               8            3774               0               0           0
extents_muzzy:                  28399               0               0            3744               0               0           0
extents_retained:               25772               0               0            3640               0               0           0
decay_dirty:                    31240               0               1            2849               0               0           0
decay_muzzy:                    31218               0               1            2843               0               0           0
base:                            5990               0               0            2563               0               0           0
tcache_list:                     2531               0               0            2522               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0            0          100          100           49            0            0 8192   1 1                1          628            1            0         3162            0            0              0            0
                  16   1         3040       120845       120655     11388435          190            1 4096   1 0.046        34848        31542            1            0        68947            0            1              0            0
                  32   2         5536      1631883      1631710    214813243          173            3 2048   1 0.028        33020        42979          782          379        80095            0            1              0            0
                  48   3         9168     12311113     12310922     43752311          191            1 4096   3 0.046       133821       126253         2929          124       268463            0            0              0            0
                  64   4        12736      1655615      1655416     10501016          199            1 1024   1 0.194        33535        49099         1635          132        88433            0            2              0            0
                  80   5         1840          856          833          598           23            1 4096   5 0.005           56          666            1            0         3254            0            0              0            0
                  96   6         4416       108540       108494        63126           46            1 2048   3 0.022        28195        31583           68           32        62443            0            0              0            0
                     ---
                 128   8        20096      9001248      9001091      9000006          157            2  512   1 0.153        93735        91759        17602           25       223226            0            1              0            0
                     ---
                 192  10         2304          594          582          626           12            1 1024   3 0.011           84          677            2            0         3295            0            0              0            0
                 224  11            0          106          106            4            0            0 2048   7 1                2          629            1            0         3164            0            0              0            0
                 256  12            0          118          118            7            0            0  256   1 1                3          631            2            0         3170            0            0              0            0
                     ---
                 384  14         4608          574          562          314           12            1  512   3 0.023           29          655            2            0         3218            0            0              0            0
                     ---
                 512  16            0          100          100            1            0            0  128   1 1                1          629            1            0         3163            0            0              0            0
                     ---
                1792  23            0         2859         2859        62500            0            0  256   7 1             1554         2184         1554            0         9376            0            1              0            0
                     ---
                3584  27       132608       108667       108630        62500           37            1  128   7 0.289        28116        31574          871          167        63961            0            0              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0           25           25           25            0
                     ---
--- End jemalloc statistics ---
  1. I don't know exactly which Windows memory usage-related quantity corresponds to "mapped" or "resident", but here is the screenshot from resource monitor:
    capture
    It can be seen that process commit size is about 520Mb, which corresponds to mapped: 528089088, and the same quantity is seen on the graph in my previous message (the last reported 'Mapped' value).

Hope this helps. I could try to build windows native dll (as you suggested later), but I'm still in doubts whether it really helps to resolve the puzzle, but I don't give up yet ː)

Just a side note: the setting stats_print:true also requires prof:true, unless I got a bump related to uninitialized mutex access, see stack below:

Program received signal SIGSEGV, Segmentation fault.
0x0000000076eb8f24 in ntdll!RtlDeNormalizeProcessParams () from /cygdrive/c/Windows/SYSTEM32/ntdll.dll
(gdb) bt
#0  0x0000000076eb8f24 in ntdll!RtlDeNormalizeProcessParams () from /cygdrive/c/Windows/SYSTEM32/ntdll.dll
#1  0x0000000076eb8e54 in ntdll!RtlDeNormalizeProcessParams () from /cygdrive/c/Windows/SYSTEM32/ntdll.dll
#2  0x000000059cff831b in malloc_mutex_lock_final (mutex=0x59d0375a0 <prof_active_mtx>) at ../include/jemalloc/internal/mutex.h:141
#3  je_malloc_mutex_lock_slow (mutex=mutex@entry=0x59d0375a0 <prof_active_mtx>) at ../src/mutex.c:83
#4  0x000000059d00403c in malloc_mutex_lock (mutex=0x59d0375a0 <prof_active_mtx>, tsdn=0x2190008) at ../include/jemalloc/internal/mutex.h:205
#5  je_prof_active_get (tsdn=0x2190008) at ../src/prof.c:2120
#6  0x000000059cfc7db9 in prof_active_ctl (tsd=<optimized out>, mib=<optimized out>, miblen=<optimized out>, oldp=0xffffc650, oldlenp=0xffffc528, newp=0x0, newlen=0)
    at ../src/ctl.c:2377
#7  0x000000059cfe7d1d in je_ctl_byname (tsd=0x2190008, name=name@entry=0x59d01d58a <je_rtree_node_alloc+6586> "prof.active", oldp=oldp@entry=0xffffc650,
    oldlenp=oldlenp@entry=0xffffc528, newp=0x0, newlen=0) at ../src/ctl.c:1175
#8  0x000000059cfb7823 in je_mallctl (name=name@entry=0x59d01d58a <je_rtree_node_alloc+6586> "prof.active", oldp=0xffffc650, oldp@entry=0x2d,
    oldlenp=oldlenp@entry=0xffffc528, newp=newp@entry=0x0, newlen=<optimized out>, newlen@entry=0) at ../src/jemalloc.c:3022
#9  0x000000059d00c3af in stats_general_print (write_cb=write_cb@entry=0x0, cbopaque=cbopaque@entry=0x0, json=json@entry=false, more=true) at ../src/stats.c:821
#10 0x000000059d00caf9 in je_stats_print (write_cb=0x0, cbopaque=0x0, opts=<optimized out>) at ../src/stats.c:1271
#11 0x0000000100401889 in main (argc=9, argv=0xffffcb50) at altfst-align.cc:122

(I've also specified prof_active:false, since I didn't want heap profiling)

@davidtgoldblatt
Copy link
Member

@interwq, anything in the malloc stats jumping out at you?

@j0t
Copy link
Author

j0t commented Oct 6, 2017

Hello! Just noticed, that some of my unit tests are failing:

=== test/unit/tsd ===
test_tsd_main_thread (non-reentrant): pass
test_tsd_sub_thread:../test/unit/tsd.c:83: Failed assertion: (data_cleanup_count) >= (3) --> 0x0 < 0x3: Cleanup function should have executed multiple times.
test_tsd_sub_thread (non-reentrant): fail
test_tsd_reincarnation (non-reentrant): pass
--- pass: 2/3, skip: 0/3, fail: 1/3 ---

This is something related to thread hooking, but does it capable to induce the observed effects?

@davidtgoldblatt
Copy link
Member

That's quite plausible. If you spin up a lot of threads that terminate without flushing their thread caches, you'd expect leaky behavior. Is that a likely explanation given your application behavior?

(This is also something that could be caused by a feature misdetection scenario, which makes it promising as an explanation as well).

@j0t
Copy link
Author

j0t commented Oct 6, 2017

It's really hard to tell... In fact, I use OpenMP, which holds a pool of 4 threads, whose (I believe) just goes to sleep when not needed and then wakes up later upon request. There are no massive thread creation activity during the program lifetime. As I said before, the same effect if observed in single thread mode as well, so I'm in doubt... Anyway, I will try to discover what is happening there and why the test fails.

@interwq
Copy link
Member

interwq commented Oct 6, 2017

Nothing in the stats looks obviously wrong to me. The number of threads reported by jemalloc is 4, so doesn't look like the tsd issue is standing in the way.

@j0t : can you experiment with one more option: "muzzy_decay_ms:0"? This is a relatively new feature and the stats there looks a bit suspicious.

@j0t
Copy link
Author

j0t commented Oct 6, 2017

Hello interwq, thank you for response!
Here it is (as you can see, no big changes yet):
g1

___ Begin jemalloc statistics ___
Version: 5.0.1-25-gea91dfa58e11373748f747041c3041f72c9a7658
Assertions disabled
config.malloc_conf: ""
Run-time option settings:
  opt.abort: false
  opt.abort_conf: false
  opt.metadata_thp: false
  opt.retain: false
  opt.dss: "secondary"
  opt.narenas: 4
  opt.percpu_arena: "disabled"
  opt.dirty_decay_ms: 10000 (arenas.dirty_decay_ms: 10000)
  opt.muzzy_decay_ms: 0 (arenas.muzzy_decay_ms: 0)
  opt.junk: "false"
  opt.zero: false
  opt.tcache: true
  opt.lg_tcache_max: 15
  opt.prof: true
  opt.prof_prefix: "jeprof"
  opt.prof_active: false (prof.active: false)
  opt.prof_thread_active_init: true (prof.thread_active_init: true)
  opt.lg_prof_sample: 19 (prof.lg_sample: 19)
  opt.prof_accum: false
  opt.lg_prof_interval: -1
  opt.prof_gdump: false
  opt.prof_final: false
  opt.prof_leak: false
  opt.stats_print: true
  opt.stats_print_opts: ""
Arenas: 4
Quantum size: 16
Page size: 65536
Maximum thread-cached size class: 229376
Allocated: 835984, active: 8781824, metadata: 6057464, resident: 65798144, mapped: 524288000, retained: 0
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
background_thread:                  0               0               0               0               0               0           0
ctl:                          6702403               0               0            2523               0               0           0
prof:                            2529               0               0            2523               0               0           0

Merged arenas stats:
assigned threads: 4
uptime: 194107102300
dss allocation precedence: N/A
decaying:  time       npages       sweeps     madvises       purged
   dirty:   N/A          781          405        91980       128990
   muzzy:   N/A            0            0            0            0
                            allocated      nmalloc      ndalloc    nrequests
small:                         835984    100269697    100266500   1167832460
large:                              0          106          106          106
total:                         835984    100269803    100266606   1167832566
active:                       8781824
mapped:                     524288000
retained:                           0
base:                         5797240
internal:                      260224
tcache:                        568512
resident:                    65798144
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                          10116               0               0           10092               0               0           0
extent_avail:                  196653               0              14           15022               0               0           0
extents_dirty:                 326692               0              29           15120               0               0           0
extents_muzzy:                 208796               0               1           15047               0               0           0
extents_retained:              103674               0               0           14770               0               0           0
decay_dirty:                   125430               1               1           12540               0               0           1
decay_muzzy:                   220360               0               1           12520               0               0           0
base:                           24467               0               0           10275               0               0           0
tcache_list:                    10126               0               0           10096               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0           96          547          535      5250370           12            1 8192   1 0.001           20         2549            6            0        12709            0            0              0            0
                  16   1         9024       483551       482987     46302575          564            3 4096   1 0.045       138950       125940           55            0       275148            0            3              0            0
                  32   2        16992      6526217      6525686    860254350          531            8 2048   1 0.032       132000       171914         3156         1470       320373            0            5              0            0
                  48   3        22896     49244062     49243585    175260860          477            4 4096   3 0.029       537315       505043        11735          437      1075951            0           14              0            0
                  64   4        44416      7122326      7121632     43505234          694            6 1024   1 0.112       139016       201420         6969          524       364511            0            5              0            0
                  80   5         8320         3377         3273         2384          104            4 4096   5 0.006          223         2694           52            0        13139            0            0              0            0
                  96   6        12864       432685       432551       252573          134            4 2048   3 0.016       113413       127009          251          132       251041            0            1              0            0
                 112   7            0          100          100       250003            0            0 4096   7 1                1         2532            1            0        12656            0            0              0            0
                 128   8        62720     36005157     36004667     36250064          490            7  512   1 0.136       374466       367069        70374          108       892398            0           10              0            0
                 160   9          160          380          379          133            1            1 2048   5 0.000          126         2659            1            0        12907            0            0              0            0
                 192  10         7104         2453         2416         2457           37            4 1024   3 0.009          284         2742           55            0        13254            0            0              0            0
                 224  11            0          424          424           20            0            0 2048   7 1                8         2545            4            0        12687            0            0              0            0
                 256  12            0          820          820          157            0            0  256   1 1              136         2673          131            0        13198            0            0              0            0
                     ---
                 384  14        14976         2249         2210         1245           39            4  512   3 0.019          116         2646           55            0        12990            0            0              0            0
                     ---
                 512  16            0          424          424           10            0            0  128   1 1                8         2546            4            0        12687            0            0              0            0
                     ---
                 768  18            0          100          100            1            0            0  256   3 1                1         2531            1            0        12655            0            0              0            0
                     ---
                1024  20            0           68           68            3            0            0   64   1 1                2         2533            2            0        12660            0            0              0            0
                     ---
                1536  22            0          100          100            1            0            0  128   3 1                1         2531            1            0        12655            0            0              0            0
                1792  23            0        11404        11404       250000            0            0  256   7 1             6200         8747         6200            0        37468            0            0              0            0
                2048  24         2048           33           32            2            1            1   32   1 0.031            1         2530            2            0        12656            0            0              0            0
                     ---
                3072  26            0           64           64            1            0            0   64   3 1                1         2531            1            0        12655            0            0              0            0
                3584  27       376320       433033       432928       250000          105            3  128   7 0.273       112781       126637         3505          658       256546            0            2              0            0
                4096  28            0           16           16            1            0            0   16   1 1                1         2530            1            0        12654            0            0              0            0
                     ---
                6144  30            0           32           32            1            0            0   32   3 1                1         2530            1            0        12654            0            0              0            0
                7168  31        28672            4            0            4            4            1   64   7 0.062            0         2527            1            0        12653            0            0              0            0
                8192  32            0           10           10            1            0            0    8   1 1                1         2529            2            0        12655            0            0              0            0
                     ---
               12288  34            0           16           16            1            0            0   16   3 1                1         2530            1            0        12654            0            0              0            0
                     ---
               24576  38            0           10           10            1            0            0    8   3 1                1         2530            2            0        12656            0            0              0            0
                     ---
               49152  42            0           10           10            1            0            0    4   3 1                1         2530            3            0        12658            0            0              0            0
               57344  43       229376            5            1            5            4            1    8   7 0.500            0         2527            2            0        12657            0            0              0            0
                     ---
               98304  46            0           10           10            1            0            0    2   3 1                1         2530            5            0        12662            0            0              0            0
                     ---
              196608  50            0           10           10            1            0            0    1   3 1                1         2530           10            0        12672            0            0              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0          100          100          100            0
              393216  54            0            1            1            1            0
                     ---
              786432  58            0            1            1            1            0
                     ---
             1572864  62            0            1            1            1            0
                     ---
             3145728  66            0            1            1            1            0
                     ---
             6291456  70            0            1            1            1            0
                     ---
            12582912  74            0            1            1            1            0
                     ---

arenas[0]:
assigned threads: 1
uptime: 194107102300
dss allocation precedence: secondary
decaying:  time       npages       sweeps     madvises       purged
   dirty: 10000          730           87        22846        31839
   muzzy:     0            0            0            0            0
                            allocated      nmalloc      ndalloc    nrequests
small:                         279856     25444863     25444522    298895902
large:                              0           31           31           31
total:                         279856     25444894     25444553    298895933
active:                       2818048
mapped:                     167575552
retained:                           0
base:                         2482432
internal:                      260224
tcache:                         12384
resident:                    53149696
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                           2529               0               0            2523               0               0           0
extent_avail:                   49208               0               3            3656               0               0           0
extents_dirty:                  82000               0               1            3692               0               0           0
extents_muzzy:                  52760               0               0            3667               0               0           0
extents_retained:               26130               0               0            3636               0               0           0
decay_dirty:                    31704               0               0            3107               0               0           0
decay_muzzy:                    55789               0               0            3107               0               0           0
base:                            6497               0               0            2571               0               0           0
tcache_list:                     2533               0               0            2524               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0           96          150          138      5250075           12            1 8192   1 0.001           10          662            2            0         3209            0            0              0            0
                  16   1            0       121928       121928     12138474            0            0 4096   1 1            34614        31326            1            0        68474            0            1              0            0
                  32   2         2112      1631452      1631386    215813560           66            1 2048   1 0.032        33017        43004          792          383        80157            0            2              0            0
                  48   3         2304     12310577     12310529     44002423           48            1 4096   3 0.011       134299       126277         2846          173       268799            0            2              0            0
                  64   4        10240      2155621      2155461     12001194          160            3 1024   1 0.052        38501        54135         2063          134        99290            0            0              0            0
                  80   5         2800          864          829          636           35            1 4096   5 0.008           63          698            1            0         3293            0            0              0            0
                  96   6          192       109143       109141        63243            2            1 2048   3 0.000        28253        31672           47           30        62549            0            0              0            0
                 112   7            0          100          100       250003            0            0 4096   7 1                1          657            1            0         3191            0            0              0            0
                 128   8          512      9001168      9001164      9250040            4            1  512   1 0.007        93606        91793        17568           33       223066            0            3              0            0
                 160   9          160          380          379          133            1            1 2048   5 0.000          126          784            1            0         3442            0            0              0            0
                 192  10          192          613          612          627            1            1 1024   3 0.000           70          708            1            0         3310            0            0              0            0
                 224  11            0          106          106            8            0            0 2048   7 1                2          658            1            0         3194            0            0              0            0
                 256  12            0          490          490          132            0            0  256   1 1              129          784          127            0         3699            0            0              0            0
                     ---
                 384  14         1152          577          574          327            3            1  512   3 0.005           31          685            1            0         3248            0            0              0            0
                     ---
                 512  16            0          106          106            2            0            0  128   1 1                2          659            1            0         3194            0            0              0            0
                     ---
                 768  18            0          100          100            1            0            0  256   3 1                1          656            1            0         3190            0            0              0            0
                     ---
                1024  20            0           68           68            3            0            0   64   1 1                2          658            2            0         3195            0            0              0            0
                     ---
                1536  22            0          100          100            1            0            0  128   3 1                1          656            1            0         3190            0            0              0            0
                1792  23            0         2850         2850        62500            0            0  256   7 1             1549         2206         1549            0         9384            0            0              0            0
                2048  24         2048           33           32            2            1            1   32   1 0.031            1          655            2            0         3191            0            0              0            0
                     ---
                3072  26            0           64           64            1            0            0   64   3 1                1          656            1            0         3190            0            0              0            0
                3584  27            0       108250       108250        62500            0            0  128   7 1            28198        31681          877          177        64164            0            0              0            0
                4096  28            0           16           16            1            0            0   16   1 1                1          655            1            0         3189            0            0              0            0
                     ---
                6144  30            0           32           32            1            0            0   32   3 1                1          655            1            0         3189            0            0              0            0
                7168  31        28672            4            0            4            4            1   64   7 0.062            0          652            1            0         3188            0            0              0            0
                8192  32            0           10           10            1            0            0    8   1 1                1          654            2            0         3190            0            0              0            0
                     ---
               12288  34            0           16           16            1            0            0   16   3 1                1          655            1            0         3189            0            0              0            0
                     ---
               24576  38            0           10           10            1            0            0    8   3 1                1          655            2            0         3191            0            0              0            0
                     ---
               49152  42            0           10           10            1            0            0    4   3 1                1          655            3            0         3193            0            0              0            0
               57344  43       229376            5            1            5            4            1    8   7 0.500            0          652            2            0         3192            0            0              0            0
                     ---
               98304  46            0           10           10            1            0            0    2   3 1                1          655            5            0         3197            0            0              0            0
                     ---
              196608  50            0           10           10            1            0            0    1   3 1                1          655           10            0         3207            0            0              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0           25           25           25            0
              393216  54            0            1            1            1            0
                     ---
              786432  58            0            1            1            1            0
                     ---
             1572864  62            0            1            1            1            0
                     ---
             3145728  66            0            1            1            1            0
                     ---
             6291456  70            0            1            1            1            0
                     ---
            12582912  74            0            1            1            1            0
                     ---

arenas[1]:
assigned threads: 1
uptime: 185799627100
dss allocation precedence: secondary
decaying:  time       npages       sweeps     madvises       purged
   dirty: 10000           19          112        23051        32418
   muzzy:     0            0            0            0            0
                            allocated      nmalloc      ndalloc    nrequests
small:                         170352     24942226     24941346    289647417
large:                              0           25           25           25
total:                         170352     24942251     24941371    289647442
active:                       1966080
mapped:                     120913920
retained:                           0
base:                         1103784
internal:                           0
tcache:                        170352
resident:                     4325376
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                           2529               0               0            2523               0               0           0
extent_avail:                   49170               0               4            3800               0               0           0
extents_dirty:                  81680               0              13            3813               0               0           0
extents_muzzy:                  52027               0               0            3791               0               0           0
extents_retained:               25859               0               0            3727               0               0           0
decay_dirty:                    31243               0               1            3217               0               0           0
decay_muzzy:                    54865               0               1            3213               0               0           0
base:                            5989               0               0            2572               0               0           0
tcache_list:                     2531               0               0            2524               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0            0          124          124           98            0            0 8192   1 1                3          628            1            0         3164            0            0              0            0
                  16   1         2944       120691       120507     11387855          184            1 4096   1 0.044        34649        31453           26            0        68683            0            1              0            0
                  32   2         3744      1631656      1631539    214814018          117            2 2048   1 0.028        33001        42977          785          362        80083            0            0              0            0
                  48   3         5472     12311051     12310937     43753859          114            1 4096   3 0.027       134284       126247         2943          101       268948            0            4              0            0
                  64   4         9920      1655705      1655550     10501982          155            1 1024   1 0.151        33511        49093         1634          128        88409            0            2              0            0
                  80   5         1840          819          796          575           23            1 4096   5 0.005           52          664           25            0         3295            0            0              0            0
                  96   6         3840       108129       108089        63102           40            1 2048   3 0.019        28311        31703           69           34        62681            0            0              0            0
                     ---
                 128   8        24576      9001307      9001115      9000008          192            2  512   1 0.187        93701        91761        17602           25       223194            0            3              0            0
                     ---
                 192  10         2304          598          586          602           12            1 1024   3 0.011           67          677           26            0         3325            0            0              0            0
                 224  11            0          106          106            4            0            0 2048   7 1                2          629            1            0         3164            0            0              0            0
                 256  12            0          106          106            8            0            0  256   1 1                2          629            1            0         3164            0            0              0            0
                     ---
                 384  14         4608          549          537          302           12            1  512   3 0.023           28          653           26            0         3262            0            0              0            0
                     ---
                 512  16            0          106          106            4            0            0  128   1 1                2          629            1            0         3165            0            0              0            0
                     ---
                1792  23            0         2858         2858        62500            0            0  256   7 1             1553         2183         1553            0         9372            0            0              0            0
                     ---
                3584  27       111104       108421       108390        62500           31            1  128   7 0.242        28166        31624          877          164        64073            0            1              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0           25           25           25            0
                     ---

arenas[2]:
assigned threads: 1
uptime: 185799627100
dss allocation precedence: secondary
decaying:  time       npages       sweeps     madvises       purged
   dirty: 10000           25           93        22977        32162
   muzzy:     0            0            0            0            0
                            allocated      nmalloc      ndalloc    nrequests
small:                         201728     24941266     24940196    289644886
large:                              0           25           25           25
total:                         201728     24941291     24940221    289644911
active:                       2031616
mapped:                     114229248
retained:                           0
base:                         1107240
internal:                           0
tcache:                        201728
resident:                     4784128
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                           2529               0               0            2523               0               0           0
extent_avail:                   48995               0               1            3745               0               0           0
extents_dirty:                  81269               0               6            3774               0               0           0
extents_muzzy:                  51929               0               0            3766               0               0           0
extents_retained:               25773               0               0            3667               0               0           0
decay_dirty:                    31230               1               0            3022               0               0           1
decay_muzzy:                    54841               0               0            3016               0               0           0
base:                            5992               0               0            2562               0               0           0
tcache_list:                     2531               0               0            2524               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0            0          124          124           98            0            0 8192   1 1                3          628            1            0         3165            0            0              0            0
                  16   1         3056       121180       120989     11388391          191            1 4096   1 0.046        34466        31439            2            0        68467            0            0              0            0
                  32   2         6016      1631379      1631191    214813386          188            3 2048   1 0.030        32994        42967          794          369        80079            0            1              0            0
                  48   3         9600     12310855     12310655     43752302          200            1 4096   3 0.048       134269       126257         2945           98       268946            0            6              0            0
                  64   4        12352      1655412      1655219     10501023          193            1 1024   1 0.188        33508        49095         1632          128        88397            0            1              0            0
                  80   5         1840          862          839          598           23            1 4096   5 0.005           56          667            1            0         3255            0            0              0            0
                  96   6         4512       107824       107777        63126           47            1 2048   3 0.022        28396        31792           70           36        62857            0            0              0            0
                     ---
                 128   8        21248      9001389      9001223      9000008          166            2  512   1 0.162        93571        91758        17602           25       223061            0            3              0            0
                     ---
                 192  10         2304          608          596          626           12            1 1024   3 0.011           82          678            2            0         3294            0            0              0            0
                 224  11            0          106          106            4            0            0 2048   7 1                2          629            1            0         3165            0            0              0            0
                 256  12            0          106          106            8            0            0  256   1 1                2          629            1            0         3165            0            0              0            0
                     ---
                 384  14         4608          574          562          314           12            1  512   3 0.023           29          655            2            0         3218            0            0              0            0
                     ---
                 512  16            0          106          106            2            0            0  128   1 1                2          629            1            0         3164            0            0              0            0
                     ---
                1792  23            0         2860         2860        62500            0            0  256   7 1             1557         2187         1557            0         9388            0            0              0            0
                     ---
                3584  27       136192       107881       107843        62500           38            1  128   7 0.296        28290        31747          874          160        64314            0            1              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0           25           25           25            0
                     ---

arenas[3]:
assigned threads: 1
uptime: 185798627100
dss allocation precedence: secondary
decaying:  time       npages       sweeps     madvises       purged
   dirty: 10000            7          113        23106        32571
   muzzy:     0            0            0            0            0
                            allocated      nmalloc      ndalloc    nrequests
small:                         184048     24941342     24940436    289644255
large:                              0           25           25           25
total:                         184048     24941367     24940461    289644280
active:                       1966080
mapped:                     121569280
retained:                           0
base:                         1103784
internal:                           0
tcache:                        184048
resident:                     3538944
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                           2529               0               0            2523               0               0           0
extent_avail:                   49280               0               6            3821               0               0           0
extents_dirty:                  81743               0               9            3841               0               0           0
extents_muzzy:                  52080               0               1            3823               0               0           0
extents_retained:               25912               0               0            3740               0               0           0
decay_dirty:                    31253               0               0            3194               0               0           0
decay_muzzy:                    54865               0               0            3184               0               0           0
base:                            5989               0               0            2570               0               0           0
tcache_list:                     2531               0               0            2524               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0            0          149          149           99            0            0 8192   1 1                4          631            2            0         3171            0            0              0            0
                  16   1         3024       119752       119563     11387855          189            1 4096   1 0.046        35221        31722           26            0        69524            0            1              0            0
                  32   2         5120      1631730      1631570    214813386          160            2 2048   1 0.039        32988        42966          785          356        80054            0            2              0            0
                  48   3         5520     12311579     12311464     43752276          115            1 4096   3 0.028       134463       126262         3001           65       269258            0            2              0            0
                  64   4        11904      1655588      1655402     10501035          186            1 1024   1 0.181        33496        49097         1640          134        88415            0            2              0            0
                  80   5         1840          832          809          575           23            1 4096   5 0.005           52          665           25            0         3296            0            0              0            0
                  96   6         4320       107589       107544        63102           45            1 2048   3 0.021        28453        31842           65           32        62954            0            1              0            0
                     ---
                 128   8        16384      9001293      9001165      9000008          128            2  512   1 0.125        93588        91757        17602           25       223077            0            1              0            0
                     ---
                 192  10         2304          634          622          602           12            1 1024   3 0.011           65          679           26            0         3325            0            0              0            0
                 224  11            0          106          106            4            0            0 2048   7 1                2          629            1            0         3164            0            0              0            0
                 256  12            0          118          118            9            0            0  256   1 1                3          631            2            0         3170            0            0              0            0
                     ---
                 384  14         4608          549          537          302           12            1  512   3 0.023           28          653           26            0         3262            0            0              0            0
                     ---
                 512  16            0          106          106            2            0            0  128   1 1                2          629            1            0         3164            0            0              0            0
                     ---
                1792  23            0         2836         2836        62500            0            0  256   7 1             1541         2171         1541            0         9324            0            0              0            0
                     ---
                3584  27       129024       108481       108445        62500           36            1  128   7 0.281        28127        31585          877          157        63995            0            0              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0           25           25           25            0
                     ---
--- End jemalloc statistics ---

@davidtgoldblatt
Copy link
Member

Huh. So, this shouldn't solve the issue, but could get some useful data: could you post the graphs you see with the malloc conf of "muzzy_decay_ms:-1,dirty_decay_ms:-1"?

@j0t
Copy link
Author

j0t commented Oct 6, 2017

No prob, David! Here it is:
g2

___ Begin jemalloc statistics ___
Version: 5.0.1-25-gea91dfa58e11373748f747041c3041f72c9a7658
Assertions disabled
config.malloc_conf: ""
Run-time option settings:
  opt.abort: false
  opt.abort_conf: false
  opt.metadata_thp: false
  opt.retain: false
  opt.dss: "secondary"
  opt.narenas: 4
  opt.percpu_arena: "disabled"
  opt.dirty_decay_ms: -1 (arenas.dirty_decay_ms: -1)
  opt.muzzy_decay_ms: -1 (arenas.muzzy_decay_ms: -1)
  opt.junk: "false"
  opt.zero: false
  opt.tcache: true
  opt.lg_tcache_max: 15
  opt.prof: true
  opt.prof_prefix: "jeprof"
  opt.prof_active: false (prof.active: false)
  opt.prof_thread_active_init: true (prof.thread_active_init: true)
  opt.lg_prof_sample: 19 (prof.lg_sample: 19)
  opt.prof_accum: false
  opt.lg_prof_interval: -1
  opt.prof_gdump: false
  opt.prof_final: false
  opt.prof_leak: false
  opt.stats_print: true
  opt.stats_print_opts: ""
Arenas: 4
Quantum size: 16
Page size: 65536
Maximum thread-cached size class: 229376
Allocated: 813664, active: 8781824, metadata: 6058616, resident: 65863680, mapped: 515047424, retained: 0
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
background_thread:                  0               0               0               0               0               0           0
ctl:                          6702427               0               0            2515               0               0           0
prof:                            2529               0               0            2515               0               0           0

Merged arenas stats:
assigned threads: 4
uptime: 252854462400
dss allocation precedence: N/A
decaying:  time       npages       sweeps     madvises       purged
   dirty:   N/A          782          349        91992       128964
   muzzy:   N/A            0            0            0            0
                            allocated      nmalloc      ndalloc    nrequests
small:                         813664    100273231    100270304   1167832460
large:                              0          106          106          106
total:                         813664    100273337    100270410   1167832566
active:                       8781824
mapped:                     515047424
retained:                           0
base:                         5798392
internal:                      260224
tcache:                        546192
resident:                    65863680
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                          10116               0               0           10060               0               0           0
extent_avail:                  196634               0              23           15004               0               0           0
extents_dirty:                 326660               0              42           15144               0               0           0
extents_muzzy:                 113769               0               1           14998               0               0           0
extents_retained:              103665               0               1           14776               0               0           0
decay_dirty:                   125342               0               0           12599               0               0           0
decay_muzzy:                   125342               0               0           12587               0               0           0
base:                           24468               0               0           10249               0               0           0
tcache_list:                    10126               0               0           10064               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0           96          552          540      5250370           12            1 8192   1 0.001           26         2550            6            0        12716            0            0              0            0
                  16   1         9008       483205       482642     46302575          563            3 4096   1 0.045       138949       125923           56            0       275134            0            1              0            0
                  32   2        16512      6526589      6526073    860254350          516            8 2048   1 0.031       132014       171930         3163         1491       320417            0            1              0            0
                  48   3        17616     49246025     49245658    175260860          367            4 4096   3 0.022       537325       505028        11728          426      1075933            0           17              0            0
                  64   4        39104      7122552      7121941     43505234          611            6 1024   1 0.099       139018       201420         6955          515       364477            0            2              0            0
                  80   5         8320         3380         3276         2384          104            4 4096   5 0.006          216         2691           52            0        13129            0            0              0            0
                  96   6        12768       433418       433285       252573          133            4 2048   3 0.016       113090       126685          251          136       250394            0            2              0            0
                 112   7            0          100          100       250003            0            0 4096   7 1                1         2532            1            0        12656            0            0              0            0
                 128   8        55168     36005204     36004773     36250064          431            7  512   1 0.120       374604       367071        70374          109       892539            2           12        1000000      1000000
                 160   9          160          380          379          133            1            1 2048   5 0.000          126         2659            1            0        12907            0            0              0            0
                 192  10         7104         2438         2401         2457           37            4 1024   3 0.009          285         2741           55            0        13254            0            0              0            0
                 224  11            0          424          424           20            0            0 2048   7 1                8         2545            4            0        12688            0            0              0            0
                 256  12            0          820          820          157            0            0  256   1 1              136         2673          131            0        13198            0            0              0            0
                     ---
                 384  14        14976         2249         2210         1245           39            4  512   3 0.019          116         2646           55            0        12990            0            0              0            0
                     ---
                 512  16            0          430          430           10            0            0  128   1 1                8         2546            5            0        12690            0            0              0            0
                     ---
                 768  18            0          100          100            1            0            0  256   3 1                1         2531            1            0        12655            0            0              0            0
                     ---
                1024  20            0           68           68            3            0            0   64   1 1                2         2533            2            0        12660            0            0              0            0
                     ---
                1536  22            0          100          100            1            0            0  128   3 1                1         2531            1            0        12655            0            0              0            0
                1792  23            0        11416        11416       250000            0            0  256   7 1             6198         8745         6198            0        37460            0            0              0            0
                2048  24         2048           33           32            2            1            1   32   1 0.031            1         2530            2            0        12656            0            0              0            0
                     ---
                3072  26            0           64           64            1            0            0   64   3 1                1         2531            1            0        12655            0            0              0            0
                3584  27       372736       433561       433457       250000          104            3  128   7 0.270       112777       126633         3505          694       256538            0            2              0            0
                4096  28            0           16           16            1            0            0   16   1 1                1         2530            1            0        12654            0            0              0            0
                     ---
                6144  30            0           32           32            1            0            0   32   3 1                1         2530            1            0        12654            0            0              0            0
                7168  31        28672            4            0            4            4            1   64   7 0.062            0         2527            1            0        12653            0            0              0            0
                8192  32            0           10           10            1            0            0    8   1 1                1         2529            2            0        12655            0            0              0            0
                     ---
               12288  34            0           16           16            1            0            0   16   3 1                1         2530            1            0        12654            0            0              0            0
                     ---
               24576  38            0           10           10            1            0            0    8   3 1                1         2530            2            0        12656            0            0              0            0
                     ---
               49152  42            0           10           10            1            0            0    4   3 1                1         2530            3            0        12658            0            0              0            0
               57344  43       229376            5            1            5            4            1    8   7 0.500            0         2527            2            0        12657            0            0              0            0
                     ---
               98304  46            0           10           10            1            0            0    2   3 1                1         2530            5            0        12662            0            0              0            0
                     ---
              196608  50            0           10           10            1            0            0    1   3 1                1         2530           10            0        12672            0            0              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0          100          100          100            0
              393216  54            0            1            1            1            0
                     ---
              786432  58            0            1            1            1            0
                     ---
             1572864  62            0            1            1            1            0
                     ---
             3145728  66            0            1            1            1            0
                     ---
             6291456  70            0            1            1            1            0
                     ---
            12582912  74            0            1            1            1            0
                     ---

arenas[0]:
assigned threads: 1
uptime: 252854462400
dss allocation precedence: secondary
decaying:  time       npages       sweeps     madvises       purged
   dirty:   N/A          721           82        22904        31995
   muzzy:   N/A            0            0            0            0
                            allocated      nmalloc      ndalloc    nrequests
small:                         280496     25446524     25446173    298896055
large:                              0           31           31           31
total:                         280496     25446555     25446204    298896086
active:                       2818048
mapped:                     172294144
retained:                           0
base:                         2481280
internal:                      260224
tcache:                         13024
resident:                    52559872
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                           2529               0               0            2515               0               0           0
extent_avail:                   49343               0               4            3655               0               0           0
extents_dirty:                  82316               0               5            3703               0               0           0
extents_muzzy:                  28722               0               0            3669               0               0           0
extents_retained:               26196               0               0            3641               0               0           0
decay_dirty:                    31692               0               0            3077               0               0           0
decay_muzzy:                    31692               0               0            3077               0               0           0
base:                            6496               0               0            2566               0               0           0
tcache_list:                     2533               0               0            2516               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0           96          179          167      5250124           12            1 8192   1 0.001           18          662            2            0         3217            0            0              0            0
                  16   1            0       120825       120825     12138427            0            0 4096   1 1            35279        31550           27            0        69416            0            0              0            0
                  32   2         2112      1632356      1632290    215813695           66            1 2048   1 0.032        33031        43016          810          387        80208            0            1              0            0
                  48   3         2304     12311724     12311676     44002420           48            1 4096   3 0.011       134502       126281         2865          147       269045            0            3              0            0
                  64   4        10880      2155820      2155650     12001208          170            3 1024   1 0.055        38485        54145         2058          132        99274            0            0              0            0
                  80   5         2800          893          858          636           35            1 4096   5 0.008           56          697            1            0         3285            0            0              0            0
                  96   6          192       108424       108422        63243            2            1 2048   3 0.000        28353        31767           41           29        62732            0            1              0            0
                 112   7            0          100          100       250003            0            0 4096   7 1                1          657            1            0         3191            0            0              0            0
                 128   8          512      9001384      9001380      9250042            4            1  512   1 0.007        93714        91789        17568           34       223171            1            4              0            0
                 160   9          160          380          379          133            1            1 2048   5 0.000          126          784            1            0         3442            0            0              0            0
                 192  10          192          643          642          627            1            1 1024   3 0.000           68          710            1            0         3310            0            0              0            0
                 224  11            0          106          106            8            0            0 2048   7 1                2          658            1            0         3195            0            0              0            0
                 256  12            0          490          490          134            0            0  256   1 1              129          784          127            0         3699            0            0              0            0
                     ---
                 384  14         1152          577          574          327            3            1  512   3 0.005           31          685            1            0         3248            0            0              0            0
                     ---
                 512  16            0          118          118            3            0            0  128   1 1                3          659            2            0         3198            0            0              0            0
                     ---
                 768  18            0          100          100            1            0            0  256   3 1                1          656            1            0         3190            0            0              0            0
                     ---
                1024  20            0           68           68            3            0            0   64   1 1                2          658            2            0         3195            0            0              0            0
                     ---
                1536  22            0          100          100            1            0            0  128   3 1                1          656            1            0         3190            0            0              0            0
                1792  23            0         2846         2846        62500            0            0  256   7 1             1547         2204         1547            0         9376            0            0              0            0
                2048  24         2048           33           32            2            1            1   32   1 0.031            1          655            2            0         3191            0            0              0            0
                     ---
                3072  26            0           64           64            1            0            0   64   3 1                1          656            1            0         3190            0            0              0            0
                3584  27            0       109171       109171        62500            0            0  128   7 1            28009        31493          881          179        63795            0            1              0            0
                4096  28            0           16           16            1            0            0   16   1 1                1          655            1            0         3189            0            0              0            0
                     ---
                6144  30            0           32           32            1            0            0   32   3 1                1          655            1            0         3189            0            0              0            0
                7168  31        28672            4            0            4            4            1   64   7 0.062            0          652            1            0         3188            0            0              0            0
                8192  32            0           10           10            1            0            0    8   1 1                1          654            2            0         3190            0            0              0            0
                     ---
               12288  34            0           16           16            1            0            0   16   3 1                1          655            1            0         3189            0            0              0            0
                     ---
               24576  38            0           10           10            1            0            0    8   3 1                1          655            2            0         3191            0            0              0            0
                     ---
               49152  42            0           10           10            1            0            0    4   3 1                1          655            3            0         3193            0            0              0            0
               57344  43       229376            5            1            5            4            1    8   7 0.500            0          652            2            0         3192            0            0              0            0
                     ---
               98304  46            0           10           10            1            0            0    2   3 1                1          655            5            0         3197            0            0              0            0
                     ---
              196608  50            0           10           10            1            0            0    1   3 1                1          655           10            0         3207            0            0              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0           25           25           25            0
              393216  54            0            1            1            1            0
                     ---
              786432  58            0            1            1            1            0
                     ---
             1572864  62            0            1            1            1            0
                     ---
             3145728  66            0            1            1            1            0
                     ---
             6291456  70            0            1            1            1            0
                     ---
            12582912  74            0            1            1            1            0
                     ---

arenas[1]:
assigned threads: 1
uptime: 244651993300
dss allocation precedence: secondary
decaying:  time       npages       sweeps     madvises       purged
   dirty:   N/A           17           86        23041        32376
   muzzy:   N/A            0            0            0            0
                            allocated      nmalloc      ndalloc    nrequests
small:                         180656     24942063     24941209    289644108
large:                              0           25           25           25
total:                         180656     24942088     24941234    289644133
active:                       1966080
mapped:                     112918528
retained:                           0
base:                         1104936
internal:                           0
tcache:                        180656
resident:                     4194304
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                           2529               0               0            2515               0               0           0
extent_avail:                   49110               0               5            3749               0               0           0
extents_dirty:                  81446               0               8            3773               0               0           0
extents_muzzy:                  28355               0               0            3729               0               0           0
extents_retained:               25829               0               0            3669               0               0           0
decay_dirty:                    31216               0               0            3096               0               0           0
decay_muzzy:                    31216               0               0            3092               0               0           0
base:                            5990               0               0            2557               0               0           0
tcache_list:                     2531               0               0            2516               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0            0          100          100           49            0            0 8192   1 1                1          629            1            0         3163            0            0              0            0
                  16   1         3008       120264       120076     11387921          188            1 4096   1 0.045        34627        31547            1            0        68725            0            1              0            0
                  32   2         4640      1631416      1631271    214813242          145            2 2048   1 0.035        32996        42974          785          375        80072            0            0              0            0
                  48   3         4896     12311420     12311318     43752279          102            1 4096   3 0.024       134295       126258         2942          104       268968            0            5              0            0
                  64   4         7808      1655640      1655518     10501018          122            1 1024   1 0.119        33515        49089         1632          128        88399            0            0              0            0
                  80   5         1840          806          783          575           23            1 4096   5 0.005           52          663           25            0         3294            0            0              0            0
                  96   6         4224       108711       108667        63102           44            1 2048   3 0.021        28121        31515           72           38        62309            0            0              0            0
                     ---
                 128   8        21888      9001139      9000968      9000006          171            2  512   1 0.166        93623        91762        17602           25       223117            0            2              0            0
                     ---
                 192  10         2304          589          577          602           12            1 1024   3 0.011           68          676           26            0         3325            0            0              0            0
                 224  11            0          106          106            4            0            0 2048   7 1                2          629            1            0         3164            0            0              0            0
                 256  12            0          118          118            7            0            0  256   1 1                3          631            2            0         3170            0            0              0            0
                     ---
                 384  14         4608          549          537          302           12            1  512   3 0.023           28          653           26            0         3262            0            0              0            0
                     ---
                 512  16            0          100          100            1            0            0  128   1 1                1          629            1            0         3163            0            0              0            0
                     ---
                1792  23            0         2867         2867        62500            0            0  256   7 1             1552         2182         1552            0         9368            0            0              0            0
                     ---
                3584  27       125440       108238       108203        62500           35            1  128   7 0.273        28253        31710          881          187        64254            0            0              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0           25           25           25            0
                     ---

arenas[2]:
assigned threads: 1
uptime: 244651993300
dss allocation precedence: secondary
decaying:  time       npages       sweeps     madvises       purged
   dirty:   N/A           22           92        23058        32419
   muzzy:   N/A            0            0            0            0
                            allocated      nmalloc      ndalloc    nrequests
small:                         160832     24942382     24941597    289647407
large:                              0           25           25           25
total:                         160832     24942407     24941622    289647432
active:                       1966080
mapped:                     116523008
retained:                           0
base:                         1107240
internal:                           0
tcache:                        160832
resident:                     4521984
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                           2529               0               0            2515               0               0           0
extent_avail:                   49165               0               5            3802               0               0           0
extents_dirty:                  81715               0              13            3821               0               0           0
extents_muzzy:                  28383               0               1            3794               0               0           0
extents_retained:               25857               0               1            3738               0               0           0
decay_dirty:                    31219               0               0            3203               0               0           0
decay_muzzy:                    31219               0               0            3199               0               0           0
base:                            5992               0               0            2561               0               0           0
tcache_list:                     2531               0               0            2516               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0            0          124          124           98            0            0 8192   1 1                3          628            1            0         3165            0            0              0            0
                  16   1         2944       120403       120219     11387855          184            1 4096   1 0.044        34734        31523           26            0        68838            0            0              0            0
                  32   2         3744      1631481      1631364    214814015          117            2 2048   1 0.028        32996        42974          791          373        80086            0            0              0            0
                  48   3         5040     12311576     12311471     43753856          105            1 4096   3 0.025       134291       126249         2975           74       269020            0            3              0            0
                  64   4         8000      1655680      1655555     10501980          125            1 1024   1 0.122        33512        49093         1635          129        88410            0            2              0            0
                  80   5         1840          819          796          575           23            1 4096   5 0.005           52          664           25            0         3295            0            0              0            0
                  96   6         3840       108243       108203        63102           40            1 2048   3 0.019        28275        31666           68           34        62606            0            0              0            0
                     ---
                 128   8        17408      9001321      9001185      9000008          136            2  512   1 0.132        93707        91759        17602           25       223198            1            5        1000000      1000000
                     ---
                 192  10         2304          598          586          602           12            1 1024   3 0.011           67          677           26            0         3325            0            0              0            0
                 224  11            0          106          106            4            0            0 2048   7 1                2          629            1            0         3165            0            0              0            0
                 256  12            0          106          106            8            0            0  256   1 1                2          629            1            0         3165            0            0              0            0
                     ---
                 384  14         4608          549          537          302           12            1  512   3 0.023           28          653           26            0         3262            0            0              0            0
                     ---
                 512  16            0          106          106            2            0            0  128   1 1                2          629            1            0         3164            0            0              0            0
                     ---
                1792  23            0         2849         2849        62500            0            0  256   7 1             1550         2180         1550            0         9360            0            0              0            0
                     ---
                3584  27       111104       108421       108390        62500           31            1  128   7 0.242        28180        31638          872          166        64091            0            0              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0           25           25           25            0
                     ---

arenas[3]:
assigned threads: 1
uptime: 244651993300
dss allocation precedence: secondary
decaying:  time       npages       sweeps     madvises       purged
   dirty:   N/A           22           89        22989        32174
   muzzy:   N/A            0            0            0            0
                            allocated      nmalloc      ndalloc    nrequests
small:                         191680     24942262     24941325    289644890
large:                              0           25           25           25
total:                         191680     24942287     24941350    289644915
active:                       2031616
mapped:                     113311744
retained:                           0
base:                         1104936
internal:                           0
tcache:                        191680
resident:                     4587520
                           n_lock_ops       n_waiting      n_spin_acq  n_owner_switch   total_wait_ns     max_wait_ns  max_n_thds
large:                           2529               0               0            2515               0               0           0
extent_avail:                   49016               0               9            3798               0               0           0
extents_dirty:                  81183               0              16            3847               0               0           0
extents_muzzy:                  28309               0               0            3806               0               0           0
extents_retained:               25783               0               0            3728               0               0           0
decay_dirty:                    31215               0               0            3223               0               0           0
decay_muzzy:                    31215               0               0            3219               0               0           0
base:                            5990               0               0            2565               0               0           0
tcache_list:                     2531               0               0            2516               0               0           0
bins:           size ind    allocated      nmalloc      ndalloc    nrequests      curregs     curslabs regs pgs  util       nfills     nflushes     newslabs      reslabs   n_lock_ops    n_waiting   n_spin_acq  total_wait_ns  max_wait_ns
                   8   0            0          149          149           99            0            0 8192   1 1                4          631            2            0         3171            0            0              0            0
                  16   1         3056       121713       121522     11388372          191            1 4096   1 0.046        34309        31303            2            0        68155            0            0              0            0
                  32   2         6016      1631336      1631148    214813398          188            3 2048   1 0.030        32991        42966          777          356        80051            0            0              0            0
                  48   3         5376     12311305     12311193     43752305          112            1 4096   3 0.027       134237       126240         2946          101       268900            0            6              0            0
                  64   4        12416      1655412      1655218     10501028          194            1 1024   1 0.189        33506        49093         1630          126        88394            0            0              0            0
                  80   5         1840          862          839          598           23            1 4096   5 0.005           56          667            1            0         3255            0            0              0            0
                  96   6         4512       108040       107993        63126           47            1 2048   3 0.022        28341        31737           70           35        62747            0            1              0            0
                     ---
                 128   8        15360      9001360      9001240      9000008          120            2  512   1 0.117        93560        91761        17602           25       223053            0            1              0            0
                     ---
                 192  10         2304          608          596          626           12            1 1024   3 0.011           82          678            2            0         3294            0            0              0            0
                 224  11            0          106          106            4            0            0 2048   7 1                2          629            1            0         3164            0            0              0            0
                 256  12            0          106          106            8            0            0  256   1 1                2          629            1            0         3164            0            0              0            0
                     ---
                 384  14         4608          574          562          314           12            1  512   3 0.023           29          655            2            0         3218            0            0              0            0
                     ---
                 512  16            0          106          106            4            0            0  128   1 1                2          629            1            0         3165            0            0              0            0
                     ---
                1792  23            0         2854         2854        62500            0            0  256   7 1             1549         2179         1549            0         9356            0            0              0            0
                     ---
                3584  27       136192       107731       107693        62500           38            1  128   7 0.296        28335        31792          871          162        64398            0            1              0            0
                     ---
large:          size ind    allocated      nmalloc      ndalloc    nrequests  curlextents
                     ---
              327680  53            0           25           25           25            0
                     ---
--- End jemalloc statistics ---

But still no significant change...

@j0t
Copy link
Author

j0t commented Oct 22, 2017

I did some research related to unit test failure

test_tsd_sub_thread:../test/unit/tsd.c:83: Failed assertion: (data_cleanup_count) >= (3) --> 0x0 < 0x3: Cleanup function should have executed multiple times.

The test fails for both cases (i.e. when compiling either in 'pure Cygwin' or with _WIN32 macro defined), however, the reasons are very different.

  1. 'pure Cygwin' version uses tsd_generic.h which doesn't work properly because of specifics in Cygwin's implementation of pthread:

from limits.h

/* Maximum number of attempts made to destroy a thread's thread-specific
   data values on thread exit. */
/* FIXME: I really don't understand this value.  Why should multiple
   attempts be necessary to destroy thread-specific data?!?  Anyway, the
   current value here is 1, taken originally from our pthread.h file,
   where it was mistakenly defined first.  Unfortunately this value is
   lower than the POSIX defined minimum value, which is 4. */
#undef PTHREAD_DESTRUCTOR_ITERATIONS
#define PTHREAD_DESTRUCTOR_ITERATIONS 1

whereas jemalloc relies on PTHREAD_DESTRUCTOR_ITERATIONS >= 3.
Therefore, there is a serious obstacle in this track by now.

  1. When _WIN32 macro is defined, the thread cleanup routine uses a semi-documented feature of MSVCRT runtime which provides a callback at each thread termination (see. the code near to JEMALLOC_SECTION(".CRT$XLY") JEMALLOC_ATTR(used) in tsd.c). Obviously, it simply don't work being compiled with Cygwin's GCC.

Nevertheless, I did managed to fix this by switching from TlsGetValue to a similar FlsGetValue in tsd_win.h, which provides a convenient callback at thread cleanup.

Now test_tsd_sub_thread passes (but only for case 2., with macro _WIN32).

However, all this doesn't give anything to my main issue, since thread creation/cleanup activity in my process is minimal.

Now I have a plan to log the calls to Windows virtual memory management functions, maybe it helps to get a better understanding what is really happening.

@j0t
Copy link
Author

j0t commented Jan 2, 2018

Hello, dear developers!

Considering jemalloc as a grey box, finally I did some analysis of the particular input and output streams that flows through jemalloc at my application runtime.

Application generates malloc or free events, and jemalloc transforms them into calls of VM management WinAPI. Each event changes some total counter variables an a particular way and the history of that changes is visualized on a series of plots value vs. time.

Specifically, in input we monitor allocated size. Each ptr = malloc(size) will do allocated += usize (where usize is so called 'usable size'), whereas each free(ptr) will do allocated -= usize (we can easily get usize from ptr using rtree_szind_slab_read).

It seems that amount of input events are just enormous (apx. 47*10^7 elements). In order to incorporate them in a reasonable way, we still process each event but sample current allocated value only at each 1000'th event.

In output, all activity leads to the following WinAPI calls:

  • COM: addr = VirtualAlloc(0, size, MEM_RESERVE|MEM_COMMIT,...) will request and commit size bytes from OS.
  • REL: VirtualFree(addr, 0, MEM_RELEASE) will release the whole memory block by addr. Though jemalloc knows the actual size of the block, Windows can't shrink it so zero must be passed as size.
  • RST: VirtualAlloc(addr, size, MEM_RESET,...) indicates that block is no longer of interest. However, the memory block will be used again later, so it should not be decommitted.

Here we monitor two variables: reset and commit. Each COM event will simply do commit += size while each RST will do commit -= size and reset += size. REL event processing is trickier: in fact, we monitor each memory block for its a state, and once it has been put into RST state, the subsequent REL will do reset -= size, otherwise it just does commit -= size.

Naturally, the count of output events is not so big (apx. 75000 elements).

The (unfortunate) results are here:

total

We see that

  • there is no trend in app commit, so there is no (significant) leaks from the application side.
  • jemalloc actively does RST for some previously committed blocks, and hardly reuse them.

Could anyone comment this? Definitely, there as something wrong here...

@j0t
Copy link
Author

j0t commented Jan 24, 2018

Hello again,
Finally I've ended up with opt.dirty_decay_ms=-1, as @interwq suggested earlier.
It has turned out that I've almost forgotten about manual purge requests scattered everywhere, preventing a proper working. After those were eliminated, the memory usage log become:
graph
(take all required memory and do not return it to OS anymore)
The setting opt.dirty_decay_ms=0 also worked pretty well as expected:
graph
(almost immediately return unused memory to OS, without any dirty/muzzy page state processing)
However, just a tiniest change to opt.dirty_decay_ms=1 has led to a significant change in graph
graph
Concluding, either opt.dirty_decay_ms=-1 or opt.dirty_decay_ms=0 appeared to be good for my task, whereas the other ones are not. Still not sure is it a bug or something else.

@Ignition
Copy link
Contributor

Here is my 2 cents (resurrecting this issue). I'm pretty sure MEM_RESET in Windows does not work like madvise's MADV_FREE in Linux. I will expore this soon (becasue I need jemalloc to work on windows), but I am certain that windows API expects MEM_RESET_UNDO calls to explicitly reuse the memory that was offered via MEM_RESET.

@j0t
Copy link
Author

j0t commented Jun 11, 2019

Hm, very interesting! Didn't heard about MEM_RESET_UNDO before. Unfortunately, I'm still under Windows 7, but MEM_RESET_UNDO is available since Windows 8 only, so I can't play with it. For a time being, I've partially resolved my issue simply by setting dirty_decay_ms:-1,muzzy_decay_ms:-1", so my [batch] app just grabbed all the memory ir requires without releasing it back to OS. In such way, all memory alloc/free operations are executed locally, without making calls to OS layer. Very effective and quick. Anyway, thanks for your note. It would be interesting to know more about your experiments.

@j0t j0t mentioned this issue Jul 30, 2019
@j0t
Copy link
Author

j0t commented Aug 12, 2019

The leak is fixed in release 5.2.1, many thanks to all for that! :)

@j0t j0t closed this as completed Aug 12, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants