Memory leak in Wily Introscope
Wygląda na to, że agent Introscope ma wycieki pamięci w natywnym kodzie:
[tomcat@swa158 ~]$ jrcmd 0 print_memusage
18130:
[JRockit] memtrace is collecting data...
[JRockit] *** 0th memory utilization report
(all numbers are in kbytes)
Total mapped ;;;;;;;1192600
; Total in-use ;;;;;;1182252
;; executable ;;;;; 12260
;;; java code ;;;; 7680; 62.6%
;;;; used ;;; 5763; 75.0%
;; shared modules (exec+ro+rw) ;;;;; 4540
;; guards ;;;;; 1056
;; readonly ;;;;; 68
;; rw-memory ;;;;;1177604
;;; Java-heap ;;;; 393216; 33.4%
;;; Stacks ;;;; 22871; 1.9%
;;; Native-memory ;;;; 761516; 64.7%
;;;; java-heap-overhead ;;; 12342
;;;; codegen memory ;;; 904
;;;; classes ;;; 29696; 3.9%
;;;;; method bytecode ;; 2927
;;;;; method structs ;; 3278 (#69939)
;;;;; constantpool ;; 11117
;;;;; classblock ;; 1488
;;;;; class ;; 3060 (#8698)
;;;;; other classdata ;; 4942
;;;;; overhead ;; 280
;;;; threads ;;; 107; 0.0%
;;;; malloc:ed memory ;;; 24265; 3.2%
;;;;; codeinfo ;; 1047
;;;;; codeinfotrees ;; 438
;;;;; exceptiontables ;; 591
;;;;; metainfo/livemaptable ;; 9324
;;;;; codeblock structs ;; 3
;;;;; constants ;; 6
;;;;; livemap global tables ;; 2091
;;;;; callprof cache ;; 0
;;;;; paraminfo ;; 88 (#1284)
;;;;; strings ;; 4991 (#92449)
;;;;; strings(jstring) ;; 0
;;;;; typegraph ;; 1593
;;;;; interface implementor list ;; 48
;;;;; thread contexts ;; 81
;;;;; jar/zip memory ;; 5451
;;;;; native handle memory ;; 39
;;;; unaccounted for memory ;;; 694309; 91.2%;28.61
---------------------!!!
16612:
[JRockit] memtrace is collecting data...
[JRockit] *** 0th memory utilization report
(all numbers are in kbytes)
Total mapped ;;;;;;;1192932
; Total in-use ;;;;;;1181960
;; executable ;;;;; 12004
;;; java code ;;;; 7424; 61.8%
;;;; used ;;; 5796; 78.1%
;; shared modules (exec+ro+rw) ;;;;; 4540
;; guards ;;;;; 1068
;; readonly ;;;;; 68
;; rw-memory ;;;;;1177312
;;; Java-heap ;;;; 393216; 33.4%
;;; Stacks ;;;; 23003; 2.0%
;;; Native-memory ;;;; 761092; 64.6%
;;;; java-heap-overhead ;;; 12342
;;;; codegen memory ;;; 592
;;;; classes ;;; 28928; 3.8%
;;;;; method bytecode ;; 2911
;;;;; method structs ;; 3256 (#69475)
;;;;; constantpool ;; 10845
;;;;; classblock ;; 1441
;;;;; class ;; 2938 (#8350)
;;;;; other classdata ;; 4923
;;;;; overhead ;; 61
;;;; threads ;;; 109; 0.0%
;;;; malloc:ed memory ;;; 24479; 3.2%
;;;;; codeinfo ;; 1019
;;;;; codeinfotrees ;; 420
;;;;; exceptiontables ;; 585
;;;;; metainfo/livemaptable ;; 9489
;;;;; codeblock structs ;; 3
;;;;; constants ;; 7
;;;;; livemap global tables ;; 2183
;;;;; callprof cache ;; 0
;;;;; paraminfo ;; 89 (#1288)
;;;;; strings ;; 4997 (#92452)
;;;;; strings(jstring) ;; 0
;;;;; typegraph ;; 1527
;;;;; interface implementor list ;; 47
;;;;; thread contexts ;; 82
;;;;; jar/zip memory ;; 5451
;;;;; native handle memory ;; 41
;;;; unaccounted for memory ;;; 694751; 91.3%;28.38
---------------------!!!
[tomcat@swa158 ~]$
Tomcaty są skonfigurowane z -Xmx384M a pamięć wirtualna (VSZ) dla procesu po dwóch tygodniach wynosi 1192MB, RSS 900MB. Czyli o 500-800MB za dużo. Sama diagnostyka JRockita pokazuje
unaccounted for memory 91.3%. Ta sama aplikacja chodząca bez Wily’ego zachowuje się poprawnie. Średnio na dzień wycieka około 50MB pamięci.
W rezultacie po pewnym czasie na produkcji wchodzimy w swapa (co już Wily pokazuje jako wydłużenie się requestów). Jedyne rozwiązanie to cotygodniowy restart tomcatów.
Wyciek mamy w natywnym kodzie. Znajdźmy jakieś natywne biblioteczki:
tomcat@swa175:~/tomcatDiag1/wily> find . -name *.so
./ext/libIntroscopeAIX4PSeries32Stats.so
./ext/libIntroscopeSolarisSparc64Stats.so
./ext/libIntroscopeRedHatStats.so
./ext/libIntroscopeHpuxParisc32Stats.so
./ext/libIntroscopeSolarisSparc32Stats.so
./ext/libIntroscopeSolarisAmd64Stats.so
./ext/libIntroscopeAIX52PSeries64Stats.so
./ext/libIntroscopeAIX53PSeries64Stats.so
./ext/libIntroscopeSolarisAmd32Stats.so
./ext/libIntroscopeHpuxItaniumStats.so
./ext/libIntroscopeAIX5PSeries32Stats.so
./ext/libIntroscopeAIX4PSeries64Stats.so
Zobaczmy jaki kod Javy odwołuje się do libIntroscopeRedHatStats.so:
tomcat@swa175:~/tomcatDiag1/wily> nm ./ext/libIntroscopeRedHatStats.so | grep Java
000015e2 T Java_com_wily_introscope_agent_platform_linux_LinuxPlatformStatisticsBackEnd_getAggregateCPUUsage
0000158e T Java_com_wily_introscope_agent_platform_linux_LinuxPlatformStatisticsBackEnd_getParentProcessID
000011c6 T Java_com_wily_introscope_agent_platform_linux_LinuxPlatformStatisticsBackEnd_getProcessCPUUsage
0000153a T Java_com_wily_introscope_agent_platform_linux_LinuxPlatformStatisticsBackEnd_getProcessID
00001524 T Java_com_wily_introscope_agent_platform_linux_LinuxPlatformStatisticsBackEnd_getProtocolVersion
000017a0 T Java_com_wily_introscope_agent_platform_linux_LinuxPlatformStatisticsBackEnd_getThreadCpuTime
0000148a T Java_com_wily_introscope_agent_platform_linux_LinuxPlatformStatisticsBackEnd_getTotalClockTicks
0000152e T Java_com_wily_introscope_agent_platform_linux_LinuxPlatformStatisticsBackEnd_init
00001796 T Java_com_wily_introscope_agent_platform_linux_LinuxPlatformStatisticsBackEnd_isThreadCpuTimeEnabled
00001534 T Java_com_wily_introscope_agent_platform_linux_LinuxPlatformStatisticsBackEnd_term
Zdekompilujmy JAD-em LinuxPlatformStatisticsBackEnd.class i poszukajmy podejrzanych metod ze słowem kluczowym native:
private native long[] getAggregateCPUUsage(String s)
throws PlaformStatUnavailableException;
Założę się, że char* wyjęte ze Stringa javowego nie jest zwalniane.
Podłączamy IBM JDK z parametrem -Xcheck:jni:all i widzimy:
JVMJNCK071W JNI warning: Memory at 0x080C22A0 acquired by GetStringUTFChars was not released before returning from native. This is probably a memory leak.
JVMJNCK078W Warning detected in com/wily/introscope/agent/platform/linux/LinuxPlatformStatisticsBackEnd.getAggregateCPUUsage(Ljava/lang/String;)[J
czyli Wily faktycznie ma wycieki pamięci. Shame on you CA!
Summary: One of Wily native libraries has improper interactions with Java VM via JNI - it doesn't free memory used for accessing Java strings. I have rewritten the library - sources and binary .so file are avalilable
here (archive is protected with password).
