From owner-freebsd-stable@freebsd.org Sat Mar 3 16:12:22 2018 Return-Path: Delivered-To: freebsd-stable@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 827BBF240CC for ; Sat, 3 Mar 2018 16:12:22 +0000 (UTC) (envelope-from jhs@berklix.com) Received: from mailman.ysv.freebsd.org (mailman.ysv.freebsd.org [IPv6:2001:1900:2254:206a::50:5]) by mx1.freebsd.org (Postfix) with ESMTP id D6DBA680F4 for ; Sat, 3 Mar 2018 16:12:21 +0000 (UTC) (envelope-from jhs@berklix.com) Received: by mailman.ysv.freebsd.org (Postfix) id 962C4F240C5; Sat, 3 Mar 2018 16:12:21 +0000 (UTC) Delivered-To: stable@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 6F17BF240C4 for ; Sat, 3 Mar 2018 16:12:21 +0000 (UTC) (envelope-from jhs@berklix.com) Received: from land.berklix.org (land.berklix.org [144.76.10.75]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client CN "land.berklix.org", Issuer "land.berklix.org" (not verified)) by mx1.freebsd.org (Postfix) with ESMTPS id 00752680EF for ; Sat, 3 Mar 2018 16:12:20 +0000 (UTC) (envelope-from jhs@berklix.com) Received: from mart.js.berklix.net (pD9FA8FAD.dip0.t-ipconnect.de [217.250.143.173]) (authenticated bits=0) by land.berklix.org (8.15.2/8.15.2) with ESMTPSA id w23GAe5d059436 (version=TLSv1 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO) for ; Sat, 3 Mar 2018 16:10:48 GMT (envelope-from jhs@berklix.com) Received: from fire.js.berklix.net (fire.js.berklix.net [192.168.91.41]) by mart.js.berklix.net (8.14.3/8.14.3) with ESMTP id w23GC4lh083644 for ; Sat, 3 Mar 2018 17:12:04 +0100 (CET) (envelope-from jhs@berklix.com) Received: from fire.js.berklix.net (localhost [127.0.0.1]) by fire.js.berklix.net (8.14.7/8.14.7) with ESMTP id w23GBk4Z038702 for ; Sat, 3 Mar 2018 17:12:04 +0100 (CET) (envelope-from jhs@berklix.com) Message-Id: <201803031612.w23GBk4Z038702@fire.js.berklix.net> To: stable@freebsd.org Subject: memory leak in Init 10.3-STABLE .svn_revision 304147 ? From: "Julian H. Stacey" Organization: http://berklix.eu BSD Unix Linux Consultants, Munich Germany User-agent: EXMH on FreeBSD http://berklix.eu/free/ X-From: http://www.berklix.eu/~jhs/ In-reply-to: Your message "Fri, 02 Mar 2018 02:20:46 +0100." <201803020121.w221Kkme034444@fire.js.berklix.net> Date: Sat, 03 Mar 2018 17:11:46 +0100 X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.25 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 03 Mar 2018 16:12:22 -0000 Oops! I got Subject & body wrong s/inetd/init/ ! Was: memory leak in inetd 10.3-STABLE .svn_revision 304147 ? Should be: memory leak in init 10.3-STABLE .svn_revision 304147 ? Hi stable@freebsd.org I think I have found a memory leak with init on 10.3-STABLE (server runs in a VM); server ran out of swap. top Mem: 34M Active, 791M Inact, 387M Wired, 200K Cache, 212M Buf, 759M Free Swap: 614M Total, 605M Used, 8744K Free, 98% Inuse uptime 4:47PM up 544 days, 2:56, 2 users, load averages: 0.26, 0.30, 0.32 uname -a FreeBSD slim.domain 10.3-STABLE FreeBSD 10.3-STABLE #0: Tue Aug 16 18:09:22 CEST 2016 jhs@slim.domain:/usr/obj/usr/src/sys/GENERIC amd64 First I just commented out a few trivial getty as a start, ran kill -HUP 1 and was surprised to get loads of swap back: swapinfo Device 1K-blocks Used Avail Capacity /dev/da0p3 628736 81056 547680 13% ( Before I ran `kill -9 541` after seeing this: PID USERNAME THR PRI NICE SIZE RES STATE TIME WCPU COMMAND 541 root 2 52 0 769M 103M select 28.4H 0.00% vmtoolsd but it didn't gain me swap space, hence next the `kill -HUP 1` which I had first avoided, as server is remote. Restarting vmtoolsd leaves swapinfo unchanged. ) top CPU: 0.8% user, 0.0% nice, 3.1% system, 0.0% interrupt, 96.1% idle Mem: 32M Active, 711M Inact, 383M Wired, 176K Cache, 216M Buf, 846M Free Swap: 614M Total, 79M Used, 535M Free, 12% Inuse /var/log/dmesg.today 858 x swap_pager_getswapspace In case someone asks me to de specific debugging, that server has: cd /usr/src cat .svn_revision 304147 cat .ctm_status src-10 1304 Though I'm wary of a reboot with a debug kernel in case it hangs, as it's a remote live server. (So I guess an ideal world would have someone say there used to be a leak but it was fixed long since.) PS Below there's an intriguing "Swap: 32G", presumably coming from hypervisor outside my server. ------------- BEFORE top last pid: 91299; load averages: 0.62, 0.68, 0.49 up 543+22:18:42 12:09:35 47 processes: 1 running, 46 sleeping Mem: 34M Active, 791M Inact, 387M Wired, 200K Cache, 212M Buf, 759M Free Swap: 614M Total, 605M Used, 8744K Free, 98% Inuse PID USERNAME THR PRI NICE SIZE RES STATE TIME WCPU COMMAND 541 root 2 52 0 769M 103M select 28.4H 0.00% vmtoolsd 579 root 1 20 0 21900K 13812K select 862:04 0.00% ntpd 47677 bind 4 20 0 74956K 27996K kqread 227:10 0.00% named 411 root 1 20 0 14524K 1708K select 124:23 0.00% syslogd 313 root 1 20 0 13656K 536K select 121:22 0.00% devd 63839 root 1 20 0 51512K 4852K select 61:12 0.00% sendmail 35589 mailman 1 20 0 108M 13168K select 53:29 0.00% python2. 35592 mailman 1 20 0 108M 14852K select 50:27 0.00% python2. 35588 mailman 1 20 0 112M 15384K select 49:43 0.00% python2. 35593 mailman 1 20 0 107M 13344K select 49:10 0.00% python2. 35590 mailman 1 20 0 112M 15272K select 48:49 0.00% python2. 35591 mailman 1 20 0 113M 18564K select 46:37 0.00% python2. 651 root 1 20 0 61316K 4116K select 17:21 0.00% sshd 676 root 1 20 0 16624K 2228K nanslp 11:02 0.00% cron 63843 smmsp 1 20 0 26480K 4048K pause 0:30 0.00% sendmail 35594 mailman 1 20 0 106M 5932K select 0:27 0.00% python2. 78594 root 1 20 0 16832K 2576K kqread 0:15 0.00% dovecot 78720 root 1 20 0 147M 9512K select 0:09 0.00% httpd ------------- IMMEDIATELY BEFORE last pid: 12063; load averages: 0.02, 0.06, 0.07 up 360+17:30:09 12:05:23 23 processes: 1 running, 22 sleeping CPU: 0.0% user, 0.0% nice, 0.1% system, 0.0% interrupt, 99.9% idle Mem: 242M Active, 18G Inact, 12G Wired, 161M Cache, 240M Free ARC: 8578M Total, 3785M MFU, 809M MRU, 59K Anon, 227M Header, 3758M Other Swap: 32G Total, 200M Used, 32G Free PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAN 97336 bind 11 20 0 109M 30084K kqread 4 57:01 0.00% named 1544 root 1 20 0 14536K 656K select 7 10:19 0.00% syslog 47145 root 1 20 0 41596K 3008K select 2 7:42 0.00% sendma 22566 root 1 20 0 16836K 1324K kqread 6 7:00 0.00% doveco 22567 root 1 20 0 21264K 1176K kqread 6 2:28 0.00% doveco 1704 root 1 20 0 34636K 744K select 2 1:31 0.00% sshd 6181 root 1 20 0 149M 7192K select 4 1:00 0.00% httpd 1764 root 1 20 0 18752K 708K select 2 0:47 0.00% inetd 1749 root 1 20 0 16632K 468K nanslp 2 0:39 0.00% cron 47148 smmsp 1 20 0 29096K 2148K pause 2 0:02 0.00% sendma 11064 www 1 20 0 149M 7360K select 7 0:00 0.00% httpd 11102 www 1 20 0 149M 7344K accept 4 0:00 0.00% httpd 11104 www 1 20 0 149M 7332K accept 4 0:00 0.00% httpd 11681 root 1 20 0 21264K 2468K kqread 3 0:00 0.00% doveco 11303 www 1 20 0 149M 7332K accept 4 0:00 0.00% httpd 11975 jhs 1 20 0 21952K 2492K CPU4 4 0:00 0.00% top 11948 jhs 1 37 0 23604K 3272K pause 6 0:00 0.00% csh 11302 www 1 20 0 149M 7316K accept 5 0:00 0.00% httpd top last pid: 91299; load averages: 0.62, 0.68, 0.49 up 543+22:18:42 12:09:35 47 processes: 1 running, 46 sleeping Mem: 34M Active, 791M Inact, 387M Wired, 200K Cache, 212M Buf, 759M Free Swap: 614M Total, 605M Used, 8744K Free, 98% Inuse PID USERNAME THR PRI NICE SIZE RES STATE TIME WCPU COMMAND 541 root 2 52 0 769M 103M select 28.4H 0.00% vmtoolsd 579 root 1 20 0 21900K 13812K select 862:04 0.00% ntpd 47677 bind 4 20 0 74956K 27996K kqread 227:10 0.00% named 411 root 1 20 0 14524K 1708K select 124:23 0.00% syslogd 313 root 1 20 0 13656K 536K select 121:22 0.00% devd 63839 root 1 20 0 51512K 4852K select 61:12 0.00% sendmail 35589 mailman 1 20 0 108M 13168K select 53:29 0.00% python2. 35592 mailman 1 20 0 108M 14852K select 50:27 0.00% python2. 35588 mailman 1 20 0 112M 15384K select 49:43 0.00% python2. 35593 mailman 1 20 0 107M 13344K select 49:10 0.00% python2. 35590 mailman 1 20 0 112M 15272K select 48:49 0.00% python2. 35591 mailman 1 20 0 113M 18564K select 46:37 0.00% python2. 651 root 1 20 0 61316K 4116K select 17:21 0.00% sshd 676 root 1 20 0 16624K 2228K nanslp 11:02 0.00% cron 63843 smmsp 1 20 0 26480K 4048K pause 0:30 0.00% sendmail 35594 mailman 1 20 0 106M 5932K select 0:27 0.00% python2. 78594 root 1 20 0 16832K 2576K kqread 0:15 0.00% dovecot 78720 root 1 20 0 147M 9512K select 0:09 0.00% httpd ps -laxww | more UID PID PPID CPU PRI NI VSZ RSS MWCHAN STAT TT TIME COMMAND 0 0 0 0 -8 0 0 144 - DLs - 4:42.13 [kernel] 0 1 0 0 20 0 9512 128 wait SLs - 0:48.15 /sbin/init -- 0 2 0 0 -16 0 0 32 - DL - 55:14.71 [cam] 0 3 0 0 -16 0 0 16 idle DL - 0:00.00 [mpt_recovery0] 0 4 0 0 -16 0 0 16 - DL - 5:43.13 [fdc0] 0 5 0 0 -16 0 0 16 waiting_ DL - 0:00.00 [sctp_iterator] 0 6 0 0 -16 0 0 32 umarcl DL - 93:37.08 [pagedaemon] 0 7 0 0 -16 0 0 16 psleep DL - 0:00.00 [vmdaemon] 0 8 0 0 155 0 0 16 pgzero DL - 0:02.78 [pagezero] 0 9 0 0 20 0 0 32 sdflush DL - 31:47.71 [bufdaemon] 0 10 0 0 -16 0 0 16 audit_wo DL - 0:00.00 [audit] 0 11 0 0 155 0 0 16 - RL - 769327:03.04 [idle] 0 12 0 0 -76 0 0 224 - WL - 1025:24.01 [intr] 0 13 0 0 -8 0 0 48 - DL - 0:00.05 [geom] 0 14 0 0 -16 0 0 16 - DL - 158:35.64 [rand_harvestq] 0 15 0 0 20 0 0 16 vlruwt DL - 6:34.70 [vnlru] 0 16 0 0 16 0 0 16 syncer DL - 1362:58.23 [syncer] 0 313 1 0 20 0 13656 536 select Ss - 121:24.12 /sbin/devd 0 401 0 0 -16 0 0 16 vmhgfs_w IL - 0:00.00 [HgfsKReqWorker] 0 411 1 0 20 0 14524 1708 select Ss - 124:26.53 /usr/sbin/syslogd -s 0 579 1 0 20 0 21900 13812 select Ss - 862:27.23 /usr/sbin/ntpd -g -c /etc/ntp.conf -p /var/run/ntpd.pid -f /var/db/ntpd.drift 0 651 1 0 21 0 61316 4116 select Ss - 17:21.09 /usr/sbin/sshd 0 676 1 0 20 0 16624 2228 nanslp Is - 11:02.70 /usr/sbin/cron -s 91 35587 1 0 20 0 108488 10832 wait Is - 0:00.54 /usr/local/bin/python2.7 /usr/local/mailman/bin/mailmanctl -s -q start 91 35588 35587 0 20 0 115156 15384 select S - 49:48.20 /usr/local/bin/python2.7 /usr/local/mailman/bin/qrunner --runner=ArchRunner:0:1 -s 91 35589 35587 0 20 0 110536 13168 select S - 53:33.77 /usr/local/bin/python2.7 /usr/local/mailman/bin/qrunner --runner=BounceRunner:0:1 -s 91 35590 35587 0 20 0 114888 15272 select S - 48:53.67 /usr/local/bin/python2.7 /usr/local/mailman/bin/qrunner --runner=CommandRunner:0:1 -s 91 35591 35587 0 20 0 115668 18564 select S - 46:41.33 /usr/local/bin/python2.7 /usr/local/mailman/bin/qrunner --runner=IncomingRunner:0:1 -s 91 35592 35587 0 20 0 110292 14852 select S - 50:32.31 /usr/local/bin/python2.7 /usr/local/mailman/bin/qrunner --runner=OutgoingRunner:0:1 -s 91 35593 35587 0 20 0 110024 13344 select S - 49:14.36 /usr/local/bin/python2.7 /usr/local/mailman/bin/qrunner --runner=VirginRunner:0:1 -s 91 35594 35587 0 20 0 108488 5932 select I - 0:27.29 /usr/local/bin/python2.7 /usr/local/mailman/bin/qrunner --runner=RetryRunner:0:1 -s 53 47677 1 0 20 0 74956 27996 kqread Ss - 227:22.82 /usr/local/sbin/named -4 -u bind -c /usr/local/etc/namedb/named.conf 0 63839 1 0 20 0 51512 4852 select Ss - 61:18.19 sendmail: accepting connections (sendmail) 25 63843 1 0 20 0 26480 4048 pause Is - 0:30.08 sendmail: Queue runner@00:30:00 for /var/spool/clientmqueue (sendmail) 0 78594 1 0 20 0 16832 2576 kqread Ss - 0:21.69 /usr/local/sbin/dovecot -c /usr/local/etc/dovecot.conf 0 78595 78594 0 20 0 21260 2796 kqread S - 0:04.84 dovecot-auth 0 78720 1 0 20 0 150768 9512 select Ss - 0:10.67 /usr/local/sbin/httpd -DNOHTTPACCEPT 0 86419 1 0 52 0 17096 2512 wait I - 0:00.00 /bin/sh /etc/periodic/daily/480.leapfile-ntpd 0 86425 86419 0 52 0 8260 1924 nanslp I - 0:00.00 sleep 50591 ------------- AFTER last pid: 95078; load averages: 0.26, 0.31, 0.32 up 544+03:02:39 16:53:32 48 processes: 1 running, 47 sleeping Mem: 34M Active, 715M Inact, 384M Wired, 176K Cache, 213M Buf, 837M Free Swap: 614M Total, 79M Used, 535M Free, 12% Inuse PID USERNAME THR PRI NICE SIZE RES STATE TIME WCPU COMMAND 94918 www 1 20 0 147M 9684K select 0:00 0.10% httpd 579 root 1 20 0 21900K 13812K select 862:28 0.00% ntpd 47677 bind 4 20 0 74956K 27996K kqread 227:23 0.00% named 411 root 1 20 0 14524K 1708K select 124:27 0.00% syslogd 313 root 1 20 0 13656K 536K select 121:24 0.00% devd 63839 root 1 20 0 51512K 4852K select 61:18 0.00% sendmail 35589 mailman 1 20 0 108M 13168K select 53:34 0.00% python2.7 35592 mailman 1 20 0 108M 14852K select 50:32 0.00% python2.7 35588 mailman 1 20 0 112M 15384K select 49:48 0.00% python2.7 35593 mailman 1 20 0 107M 13344K select 49:15 0.00% python2.7 35590 mailman 1 20 0 112M 15272K select 48:54 0.00% python2.7 35591 mailman 1 20 0 113M 18564K select 46:42 0.00% python2.7 651 root 1 20 0 61316K 4116K select 17:21 0.00% sshd 676 root 1 20 0 16624K 2228K nanslp 11:03 0.00% cron 91232 jhs 1 20 0 21948K 3112K select 0:39 0.00% top 63843 smmsp 1 20 0 26480K 4048K pause 0:30 0.00% sendmail 35594 mailman 1 20 0 106M 5932K select 0:27 0.00% python2.7 78594 root 1 20 0 16832K 2576K kqread 0:22 0.00% dovecot ------------- Cheers, Julian -- Julian Stacey, Computer Consultant, Systems Engineer, BSD Linux Unix, Munich Brexit Referendum stole 3,700,000 votes, inc. 700,000 from British in EU. UK Govt. lied it's "democratic" in Article 50 letter to EU paragraph 3. Petition for votes: http://berklix.eu/queen/