Memory leak in FR 2.1.10 and 2.2.0 ?
Hello, I'm experiencing an infinitely growth of memory footprint of freeradius process in our production environment (of course, in our test env. everything goes right). Clients : - ~60 Alcatel omnistack OS6200 switches doing MAC Authentication (via EAP-MD5), - a few WiFi AP doing either EAP-TLS or EAP-PEAP. - Average load : 5 auth/minute On my first environment production I used : - Server : CentOS 5.6 32 bits on VM, 2 CPUs, 512 Mb RAM - freeradius2 2.1.10-1 i686 packages - MySQL on a different CentOS 5.6 server used for NAS, postauth, checks, etc. process get killed by kernel in less than 48 hours. As it was not the latest freeradius release, I recently moved to : - Server : Debian 4 32 bits on VM, 2 CPUs, 256 Mb RAM - freeradius 2.2.0 downloaded directly, and packaged on the debian server using this wiki page : http://wiki.freeradius.org/building/Build#Building-Debian-packages process get killed by kernel in less than 36 hours. As I cannot reproduce this on my test environment by using eapol_test, I suspect alcatel frames to trigger a kind of memory leak in freeradius. I collected different things : - pcap of eap-md5 exchange between freeradius and a switch - valgrind log on my production server - pidstat showing memory usage of freeradius process For now, i'm running out of new ideas to fix this issue... Rgds. -- Philippe MARASSE Service Informatique - Centre Hospitalier Henri Laborit BP 587 - 370 avenue Jacques Coeur 86021 Poitiers Cedex Tel : 05.49.44.57.19
Philippe MARASSE wrote:
I'm experiencing an infinitely growth of memory footprint of freeradius process in our production environment (of course, in our test env. everything goes right).
That's an issue.
As I cannot reproduce this on my test environment by using eapol_test, I suspect alcatel frames to trigger a kind of memory leak in freeradius.
Possible.
I collected different things : - pcap of eap-md5 exchange between freeradius and a switch - valgrind log on my production server - pidstat showing memory usage of freeradius process
So... what were the results? Did valgrind say anything useful? The main issue is that the memory might not be leaked. It might be referenced, but unused. That's much harder to track down. Alan DeKok.
First, thanks for the two answers. Le 08/01/2013 14:55, Alan DeKok a écrit :
Philippe MARASSE wrote:
I'm experiencing an infinitely growth of memory footprint of freeradius process in our production environment (of course, in our test env. everything goes right). That's an issue.
As I cannot reproduce this on my test environment by using eapol_test, I suspect alcatel frames to trigger a kind of memory leak in freeradius. Possible.
I collected different things : - pcap of eap-md5 exchange between freeradius and a switch - valgrind log on my production server - pidstat showing memory usage of freeradius process So... what were the results? As the complete log is pretty big (around 1 Mb) I did not post the entire result (and it exceeds 500kb limit of pastebin), but I can send by mail valgrind log, pcap and other possibly useful things.
Did valgrind say anything useful? I've never used valgrind before but here's some extract that I've think relevant and the summary :
==00:01:17:29.869 24818== 10,033,120 (16,016 direct, 10,017,104 indirect) bytes in 143 blocks are definitely lost in loss record 723 of 724 ==00:01:17:29.869 24818== at 0x4023F50: malloc (vg_replace_malloc.c:236) ==00:01:17:29.869 24818== by 0x806B2EC: rad_malloc (in /usr/sbin/freeradius) ==00:01:17:29.869 24818== by 0x47FBBE5: ??? ==00:01:17:29.869 24818== by 0x47F9A15: ??? ==00:01:17:29.869 24818== by 0x47F8E99: ??? ==00:01:17:29.869 24818== by 0x8065C0A: modcall (in /usr/sbin/freeradius) ==00:01:17:29.869 24818== by 0x8061CDF: indexed_modcall (in /usr/sbin/freeradius) ==00:01:17:29.869 24818== by 0x80620FB: module_authenticate (in /usr/sbin/freeradius) ==00:01:17:29.869 24818== by 0x804FFAD: rad_authenticate (in /usr/sbin/freeradius) ==00:01:17:29.869 24818== by 0x8074089: radius_handle_request (in /usr/sbin/freeradius) ==00:01:17:29.869 24818== by 0x806AAF5: ??? (in /usr/sbin/freeradius) ==00:01:17:29.869 24818== by 0x4081954: start_thread (pthread_create.c:300) ==00:01:17:29.869 24818== ==00:01:17:29.869 24818== LEAK SUMMARY: ==00:01:17:29.869 24818== definitely lost: 51,904 bytes in 382 blocks ==00:01:17:29.869 24818== indirectly lost: 26,398,375 bytes in 15,411 blocks ==00:01:17:29.869 24818== possibly lost: 2,145,153 bytes in 1,719 blocks ==00:01:17:29.869 24818== still reachable: 40,292 bytes in 2,493 blocks ==00:01:17:29.869 24818== suppressed: 0 bytes in 0 blocks ==00:01:17:29.869 24818== Reachable blocks (those to which a pointer was found) are not shown. ==00:01:17:29.869 24818== To see them, rerun with: --leak-check=full --show-reachable=yes ==00:01:17:29.869 24818== ==00:01:17:29.869 24818== For counts of detected and suppressed errors, rerun with: -v ==00:01:17:29.869 24818== Use --track-origins=yes to see where uninitialised values come from ==00:01:17:29.869 24818== ERROR SUMMARY: 493967 errors from 561 contexts (suppressed: 97 from 12) I don't know if I've missed something as there's some "???" in the call stacks ?
The main issue is that the memory might not be leaked. It might be referenced, but unused. That's much harder to track down.
Rgds. -- Philippe MARASSE Service Informatique - Centre Hospitalier Henri Laborit BP 587 - 370 avenue Jacques Coeur 86021 Poitiers Cedex Tel : 05.49.44.57.19
Philippe MARASSE wrote:
As the complete log is pretty big (around 1 Mb) I did not post the entire result (and it exceeds 500kb limit of pastebin), but I can send by mail valgrind log, pcap and other possibly useful things.
For this, send valgrind logs to me personally.
I've never used valgrind before but here's some extract that I've think relevant and the summary :
==00:01:17:29.869 24818== 10,033,120 (16,016 direct, 10,017,104 indirect) bytes in 143 blocks are definitely lost in loss record 723 of 724 ==00:01:17:29.869 24818== at 0x4023F50: malloc (vg_replace_malloc.c:236) ==00:01:17:29.869 24818== by 0x806B2EC: rad_malloc (in /usr/sbin/freeradius) ==00:01:17:29.869 24818== by 0x47FBBE5: ??? ==00:01:17:29.869 24818== by 0x47F9A15: ??? ==00:01:17:29.869 24818== by 0x47F8E99: ???
Well... that needs to be fixed.
I don't know if I've missed something as there's some "???" in the call stacks ?
You need to build the server with debugging symbols. See doc/bugs The ??? indicates that valgrind couldn't find symbols for one of the modules which was loaded. And even the above trace might not be useful. This is leaked at *exit*. The server might be tracking memory correctly, so it's not exactly a "leak". And that tracked memory is cleaned up at exit. i.e. there may be one of two issues here: - actual leaked memory - memory which SHOULD have been free'd, but wasn't. It's still tracked, just not used. Alan DeKok.
Le 08/01/2013 16:24, Alan DeKok a écrit :
Philippe MARASSE wrote:
As the complete log is pretty big (around 1 Mb) I did not post the entire result (and it exceeds 500kb limit of pastebin), but I can send by mail valgrind log, pcap and other possibly useful things. For this, send valgrind logs to me personally.
I've never used valgrind before but here's some extract that I've think relevant and the summary :
==00:01:17:29.869 24818== 10,033,120 (16,016 direct, 10,017,104 indirect) bytes in 143 blocks are definitely lost in loss record 723 of 724 ==00:01:17:29.869 24818== at 0x4023F50: malloc (vg_replace_malloc.c:236) ==00:01:17:29.869 24818== by 0x806B2EC: rad_malloc (in /usr/sbin/freeradius) ==00:01:17:29.869 24818== by 0x47FBBE5: ??? ==00:01:17:29.869 24818== by 0x47F9A15: ??? ==00:01:17:29.869 24818== by 0x47F8E99: ??? Well... that needs to be fixed.
I don't know if I've missed something as there's some "???" in the call stacks ? You need to build the server with debugging symbols. See doc/bugs
The ??? indicates that valgrind couldn't find symbols for one of the modules which was loaded. I'm a bit confused : I built debian package with rules provided in tarball, configure options are :
./configure --build i486-linux-gnu \ --prefix=/usr \ --exec-prefix=/usr \ --mandir=/usr/share/man \ --sysconfdir=/etc \ --libdir=/usr/lib/freeradius \ --datadir=/usr/share \ --localstatedir=/var \ --with-raddbdir=/etc/freeradius \ --with-logdir=/var/log/freeradius \ --enable-ltdl-install=no --enable-strict-dependencies \ --with-large-files --with-udpfromto --with-edir \ --enable-developer \ --config-cache \ --without-rlm_eap_tnc \ --with-rlm_sql_postgresql_lib_dir=`pg_config --libdir` \ --with-rlm_sql_postgresql_include_dir=`pg_config --includedir` \ --without-rlm_eap_ikev2 \ --without-rlm_sql_oracle \ --without-rlm_sql_unixodbc \ --with-system-libtool \ --with-system-libltdl unless I've missed something, --enable-developer should be sufficient to generate debugging symbols for freeradius modules ?
And even the above trace might not be useful. This is leaked at *exit*. The server might be tracking memory correctly, so it's not exactly a "leak". And that tracked memory is cleaned up at exit.
i.e. there may be one of two issues here:
- actual leaked memory
- memory which SHOULD have been free'd, but wasn't. It's still tracked, just not used.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Regards -- Philippe MARASSE Service Informatique - Centre Hospitalier Henri Laborit BP 587 - 370 avenue Jacques Coeur 86021 Poitiers Cedex Tel : 05.49.44.57.19
Le 08/01/2013 21:56, Alan DeKok a écrit :
Philippe MARASSE wrote:
I'm a bit confused : I built debian package with rules provided in tarball, configure options are : It should work. If it doesn't, check that there aren't *other* modules on the system. They could have been built without debugging symbols. I found that I've forgotten to install freedebug-dbg package, it's much more explicit now. I'll try to do a valgrind log tomorrow within business hours.
Rgds.
participants (4)
-
Alan DeKok -
Phil Mayers -
Philippe MARASSE -
Philippe Marasse