Bug 235748 - Using swap with free memory available
Summary: Using swap with free memory available
Status: New
Alias: None
Product: Base System
Classification: Unclassified
Component: kern (show other bugs)
Version: 11.2-RELEASE
Hardware: amd64 Any
: --- Affects Only Me
Assignee: freebsd-bugs (Nobody)
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-02-14 17:42 UTC by info
Modified: 2019-02-14 20:37 UTC (History)
1 user (show)

See Also:


Attachments
procstat of mysqld (959.02 KB, text/plain)
2019-02-14 17:55 UTC, info
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description info 2019-02-14 17:42:39 UTC
Since updating to FreeBSD 11.2 from 11.1 I've been experiencing swap usage growing consistently over several weeks until there's none left, despite having free ram available. I detailed the issue on one of the smaller servers here: https://serverfault.com/questions/953819/freebsd-swap-usage-with-mysql

I have a larger server exhibiting the same issue but it's at the point where it's logging the following 20-40 times in a second, every couple minutes:
Feb 14 09:31:48 rad-myecr kernel: swap_pager_getswapspace(6): failed

MySQL is the process using the memory, and its data directory is on a zvol with  vfs.zfs.arc_max="256M"

root@rad-myecr:/var/log # vmstat
procs  memory       page                    disks     faults         cpu
r b w  avm   fre   flt  re  pi  po    fr   sr da0 da1   in    sy    cs us sy id
2 0 1 2.1T  434M   850 886  10   5   569 1103   0   0  827   759   320  2  1 97

root@rad-myecr:/var/log # zpool list
NAME   SIZE  ALLOC   FREE  CKPOINT  EXPANDSZ   FRAG    CAP  DEDUP  HEALTH  ALTROOT
data  1.12T   345G   799G        -         -    70%    30%  1.00x  ONLINE  -



last pid: 75850;  load averages:  1.80,  1.71,  1.54                                         up 42+15:02:10  09:38:24
29 processes:  1 running, 28 sleeping
CPU:  2.6% user,  0.0% nice,  1.5% system,  0.0% interrupt, 96.0% idle
Mem: 17G Active, 9096M Inact, 2219M Laundry, 3295M Wired, 1551M Buf, 347M Free
ARC: 252M Total, 110M MFU, 31M MRU, 1380K Anon, 4992K Header, 104M Other
     30M Compressed, 198M Uncompressed, 6.54:1 Ratio
Swap: 20G Total, 16G Used, 3638M Free, 82% Inuse, 20K In

last pid: 75910;  load averages:  1.85,  1.76,  1.58                                         up 42+15:03:57  09:40:11
29 processes:  1 running, 28 sleeping
CPU:  6.0% user,  0.0% nice,  1.1% system,  0.1% interrupt, 92.8% idle
Mem: 17G Active, 8662M Inact, 2218M Laundry, 3294M Wired, 1551M Buf, 772M Free
ARC: 253M Total, 110M MFU, 37M MRU, 1008K Anon, 4984K Header, 100M Other
     34M Compressed, 202M Uncompressed, 5.87:1 Ratio
Swap: 20G Total, 16G Used, 3642M Free, 82% Inuse, 152K In

  PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME    WCPU COMMAND
10914 mysql        43  22    0 63717M 27468M select  4 487.4H 148.46% mysqld
75880 root          1  20    0  7920K  3628K CPU16  16   0:00   0.08% top
  125 root          2  20    0 32472K  4520K select  4  46:58   0.07% vmtoolsd
  452 root          1  20    0  9184K   696K select 12   4:41   0.02% devd
36456 root          1  28    0   534M   408M nanslp  3   5:29   0.02% php
75614 dfairley      1  20    0 13164K  8084K select  2   0:00   0.02% sshd
33400 root          1  23    0   255M 37376K select  9  13:15   0.02% snmpd
  619 root          1  20    0  6416K  2008K select  7   3:04   0.00% syslogd
  709 root          1  20    0 12456K 12552K select 15   3:51   0.00% ntpd
 1273 root          1  20    0 10456K  5092K select 19   1:02   0.00% sendmail
 1280 root          1  20    0  6468K   768K nanslp  0   0:14   0.00% cron
  401 root          1  42    0  6548K  1912K select  7   0:02   0.00% dhclient
 1276 smmsp         1  20    0 10456K   876K pause  17   0:01   0.00% sendmail
  447 _dhcp         1  20    0  6548K  2004K select 21   0:01   0.00% dhclient
 1270 root          1  20    0 12852K  5264K select 13   0:00   0.00% sshd
75619 root          1  20    0  7416K  4336K pause  20   0:00   0.00% csh
10428 mysql         1  52    0  7064K     0K wait   18   0:00   0.00% <sh>
75615 dfairley      1  20    0  7416K  4360K pause   6   0:00   0.00% csh
75612 root          1  23    0 13164K  7964K select 22   0:00   0.00% sshd
75617 root          1  22    0  7612K  3832K select  9   0:00   0.00% sudo
75618 root          1  24    0  6936K  3104K wait    1   0:00   0.00% su
 1335 root          1  52    0  6408K  1796K ttyin   2   0:00   0.00% getty
 1333 root          1  52    0  6408K  1796K ttyin   5   0:00   0.00% getty
 1334 root          1  52    0  6408K  1796K ttyin   0   0:00   0.00% getty
 1336 root          1  52    0  6408K  1796K ttyin  12   0:00   0.00% getty
 1332 root          1  52    0  6408K  1796K ttyin  11   0:00   0.00% getty
 1331 root          1  52    0  6408K  1796K ttyin   3   0:00   0.00% getty
 1329 root          1  52    0  6408K  1796K ttyin   7   0:00   0.00% getty
 1330 root          1  52    0  6408K  1796K ttyin  21   0:00   0.00% getty
Comment 1 Mark Johnston freebsd_committer freebsd_triage 2019-02-14 17:46:09 UTC
Can you show "vmstat -s" from the system after it's been running for a while?

mysqld has quite a lot of memory mapped; can you provide "procstat -v $(pgrep mysqld)" output?
Comment 2 info 2019-02-14 17:55:36 UTC
Created attachment 202031 [details]
procstat of mysqld

Thanks, I've added an attachment for the procstat. 

root@rad-myecr:~ # uptime
 9:50AM  up 42 days, 15:15, 1 user, load averages: 1.45, 1.95, 1.82

root@rad-myecr:~ # vmstat -s
1189780296 cpu context switches
3046164253 device interrupts
509514893 software interrupts
2810291712 traps
2835479046 system calls
     3612 kernel threads created
  2184108  fork() calls
  1882952 vfork() calls
        2 rfork() calls
 37533884 swap pager pageins
 86255308 swap pager pages paged in
 16981628 swap pager pageouts
 52873480 swap pager pages paged out
   113928 vnode pager pageins
   419334 vnode pager pages paged in
        0 vnode pager pageouts
        0 vnode pager pages paged out
    78120 page daemon wakeups
4082076759 pages examined by the page daemon
      112 clean page reclamation shortfalls
3265739232 pages reactivated by the page daemon
2034406972 copy-on-write faults
   113946 copy-on-write optimized faults
3044055381 zero fill pages zeroed
  1928460 zero fill pages prezeroed
 39660240 intransit blocking page faults
3146228353 total VM faults taken
 37486586 page faults requiring I/O
        0 pages affected by kernel thread creation
 90811730 pages affected by  fork()
316676567 pages affected by vfork()
      100 pages affected by rfork()
2109563709 pages freed
297910633 pages freed by daemon
1625523369 pages freed by exiting processes
  4153160 pages active
  2610854 pages inactive
   493550 pages in the laundry queue
   844755 pages wired down
    62450 pages free
     4096 bytes per page
23816437703 total name lookups
          cache hits (95% pos + 3% neg) system 0% per-directory
          deletions 0%, falsehits 0%, toolong 0%
Comment 3 Mark Johnston freebsd_committer freebsd_triage 2019-02-14 18:52:34 UTC
Right, so mysqld's memory usage is nearly all anonymous memory, so swapping is required in order to recycle it.  There is indeed some free RAM available, but not very much; the page daemon is trying to maintain vm.stats.vm.v_free_target free pages available.

I'm surprised that you didn't see similar swap usage on 11.1, especially since we didn't make any major changes to the algorithm which decides when and how much to swap between 11.1 and 11.2.  Is it possible that mysqld is somehow using more memory than before?
Comment 4 info 2019-02-14 19:20:21 UTC
Mysqld is actually using less memory than before. It's tuned to only use 19GB of its 32GB ram, 60%. The normal recommendation is for 80%. I lowered it from 70% when this issue started happening but it doesn't seem to have helped.

Note that it starts using swap from the very beginning, after a reboot, when MySQL has only used a couple of GB of ram.

I did notice it using a significant amount of swap in 11.1, but it didn't ever take all of it. I assumed the issue was that I hadn't set arc_max, so it and MySQL were competing for memory. I upgraded to 11.2 and set the arc_max at the same time.
Comment 5 Mark Johnston freebsd_committer freebsd_triage 2019-02-14 19:43:43 UTC
(In reply to info from comment #4)
mysqld is pretty clearly using more than 19GB here though, so something's missing.
Comment 6 info 2019-02-14 20:37:30 UTC
The following is from mysqltuner.pl which collates some of the internals from mysql:

[--] Up for: 41d 14h 10m 5s (1B q [366.392 qps], 28M conn, TX: 497G, RX: 155G)
[--] Physical Memory     : 32.0G
[--] Max MySQL memory    : 22.5G
[--] Other process memory: 0B
[--] Total buffers: 19.1G global + 11.2M per thread (200 max threads)
[--] P_S Max memory usage: 1G
[OK] Maximum reached memory usage: 21.8G (68.07% of installed RAM)
[OK] Maximum possible memory usage: 22.5G (70.51% of installed RAM)
[OK] Overall possible memory usage with other process is compatible with memory available
[OK] Highest usage of available connections: 64% (129/200)


I previously neglected to include the per-connection buffers, but even with those, MySQL doesn't reckon it'll use more than 22.5G. I'm at a loss at what caused this. It's a production server so I can't try out 11.1 to confirm 11.2 isn't the issue, so all I can try is reverting the arc_max change. This cluster has been pretty happy since FreeBSD 8. Thanks for the questions though, it's given me a lot of stuff I can research.