[Swan-dev] Pluto memory consumption

[Erik Andersson]

Hi,

I'm running libreswan 3.19 on two centos 7 machines. For debugging 
purposes the ike and sa lifetimes are set very low, 90 and 70 seconds 
respectively.

I'm running one gateway to gateway tunnel and one subnet to subnet 
tunnel between "Host A" (10.48.28.60) and "Host B" (10.48.28.70).

ipsec.conf files for host A and host B:

https://www.dropbox.com/s/orp0t5ho8xqy333/ipsec_host_A.conf?dl=0
https://www.dropbox.com/s/983bbeoj56rqjwn/ipsec_host_B.conf?dl=0

I ran the tunnels for 6 days and recognized that the memory consumption 
of pluto was quite high. It started using around 8 MB and after six days 
it used around 140 MB on both hosts.

# ps auxw | grep pluto
root      2982  0.0 13.6 315284 138868 ?       Ssl  feb21   4:02 
/usr/local/libexec/ipsec/pluto --leak-detective --config /etc/ipsec.conf 
--nofork

The leak detective reported the following when I shutdown pluto:

Feb 27 13:56:13: leak: EVENT_SHUNT_SCAN, item size: 32
Feb 27 13:56:13: leak: EVENT_PENDING_DDNS, item size: 32
Feb 27 13:56:13: leak: EVENT_SD_WATCHDOG, item size: 32
Feb 27 13:56:13: leak: EVENT_PENDING_PHASE2, item size: 32
Feb 27 13:56:13: leak: EVENT_REINIT_SECRET, item size: 32
Feb 27 13:56:13: leak: EVENT_LOG_DAILY, item size: 32
Feb 27 13:56:13: leak detective found 6 leaks, total size 192

Is this "normal" memory consumption? 140 MB seems quite high to me but 
I'm not sure.

Last 1000 lines of pluto.log for the hosts:

https://www.dropbox.com/s/ybksnh38be1f537/pluto_last_1000_A.log?dl=0
https://www.dropbox.com/s/d4cw3i2udx939y2/pluto_last_1000_B.log?dl=0

I ran another test with valgrind over night. The pluto process started 
with 8 MB and rose to 25 MB. I noticed two places where a lot of memory 
were still reachable:

==2935==
==2935== 5,095,216 bytes in 938 blocks are still reachable in loss 
record 652 of 653
==2935==    at 0x4C2B975: calloc (vg_replace_malloc.c:711)
==2935==    by 0x6B3B351: PORT_ZAlloc_Util (in /usr/lib64/libnssutil3.so)
==2935==    by 0xC5C085E: ??? (in /usr/lib64/libsoftokn3.so)
==2935==    by 0xC5C098F: ??? (in /usr/lib64/libsoftokn3.so)
==2935==    by 0xC5BD4BA: ??? (in /usr/lib64/libsoftokn3.so)
==2935==    by 0x4E8568E: PK11_DeriveWithTemplate (in /usr/lib64/libnss3.so)
==2935==    by 0x4E857B1: PK11_DeriveWithFlags (in /usr/lib64/libnss3.so)
==2935==    by 0x16B228: symkey_from_symkey (crypt_symkey.c:283)
==2935==    by 0x18957C: init_symkey (ike_alg_nss_prf_ops.c:103)
==2935==    by 0x16BF9C: crypt_prf_init_symkey (crypt_prf.c:68)
==2935==    by 0x16CE31: ikev2_prfplus (ikev2_prf.c:295)
==2935==    by 0x16DACF: ikev2_child_sa_keymat (ikev2_prf.c:389)
==2935==
==2935==

7,202,832 bytes in 1,326 blocks are still reachable in loss record 653 
of 653
==2935==    at 0x4C2B975: calloc (vg_replace_malloc.c:711)
==2935==    by 0x6B3B351: PORT_ZAlloc_Util (in /usr/lib64/libnssutil3.so)
==2935==    by 0xC5C085E: ??? (in /usr/lib64/libsoftokn3.so)
==2935==    by 0xC5C098F: ??? (in /usr/lib64/libsoftokn3.so)
==2935==    by 0xC5B270D: ??? (in /usr/lib64/libsoftokn3.so)
==2935==    by 0x4E7AC11: ??? (in /usr/lib64/libnss3.so)
==2935==    by 0x4E82FB8: ??? (in /usr/lib64/libnss3.so)
==2935==    by 0x4E83E58: PK11_ImportSymKeyWithFlags (in 
/usr/lib64/libnss3.so)
==2935==    by 0x4E8454B: ??? (in /usr/lib64/libnss3.so)
==2935==    by 0x16B356: chunk_from_symkey (crypt_symkey.c:319)
==2935==    by 0x18987F: digest_symkey (ike_alg_nss_prf_ops.c:153)
==2935==    by 0x16CE4A: ikev2_prfplus (ikev2_prf.c:297)
==2935==

The full valgrind log can be found here:

https://www.dropbox.com/s/fl87en2kb6ghvj3/pluto_valgrind.txt?dl=0

Regards,

/Erik