Re: JNI memory leak?
-BEGIN PGP SIGNED MESSAGE- Hash: SHA256 Mark, On 4/24/20 17:46, Mark Boon wrote: > Thanks Chris for taking the time. > > As you point out, from the threads I can tell we're not using ARP > as the names al all starting with "jsse". AFAI could find out BouncyCastle is a pure Java implementation, so that also can't be the cause. > > Someone suggested PAMLibrary may be the culprit. So I started a thread that makes continuous auth calls to the PAM library. Now there does seems to be an indication memory is leaking very, very slowly. It seems to be roughly in line with the number of auth failures. It looks like PAM throttles auth failures though, hence it's taking such a long time for the evidence to mount. > > So nothing to see here for this group. Just wanted to give a heads > up. Actually, this is great feedback, even if it means there is no action to take by the Tomcat team. 312 bytes leaked per allocation is enough to be dangerous, but not such a huge problem to make it easy to discover . Identifying that it is an authentication library that isn't commonly used with Java (or maybe it is?!) at least puts it into the archives of this list in case someone else is having a similar problem. Thanks, - -chris > On 4/6/20, 12:12 PM, "Christopher Schultz" wrote: > > Mark, > > On 4/3/20 21:48, Mark Boon wrote: >> For the past few months we’ve been trying to trace what looks >> like gradual memory creep. After some long-running experiments it >> seems due to memory leaking when jni_invoke_static(JNIEnv_*, >> JavaValue*, _jobject*, JNICallType, _jmethodID*, >> JNI_ArgumentPusher*, Thread*) is invoked. Somewhere. > >> My environment is Tomcat running a proxy webapp. It does TLS >> termination, authentication and then forwards the call to local >> services. It doesn’t do much else, it’s a relatively small >> application. > >> Some (possibly relevant) versions and config parameters: Tomcat >> 8.5 Java 8u241 (Oracle) Heap size = 360Mb MAX_ALLOC_ARENA=2 >> MALLOC_TRIM_THRESHOLD_=250048 jdk.nio.maxCachedBufferSize=25600 > >> We couldn’t find any proof of memory leaking on the Java side. >> When we turn on NativeMemoryTracking=detail and we take a >> snapshot shortly after starting, we see (just one block shown): > >> [0x03530e462f9a] >> JNIHandleBlock::allocate_block(Thread*)+0xaa [0x03530e3f759a] >> JavaCallWrapper::JavaCallWrapper(methodHandle, Handle, >> JavaValue*, Thread*)+0x6a [0x03530e3fa000] >> JavaCalls::call_helper(JavaValue*, methodHandle*, >> JavaCallArguments*, Thread*)+0x8f0 [0x03530e4454a1] >> jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, >> _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .isra.96] >> [clone .constprop.117]+0x1e1 (malloc=33783KB type=Internal >> #110876) > >> Then we run it under heavy load for a few weeks and take another >> snapshot: > >> [0x03530e462f9a] >> JNIHandleBlock::allocate_block(Thread*)+0xaa [0x03530e3f759a] >> JavaCallWrapper::JavaCallWrapper(methodHandle, Handle, >> JavaValue*, Thread*)+0x6a [0x03530e3fa000] >> JavaCalls::call_helper(JavaValue*, methodHandle*, >> JavaCallArguments*, Thread*)+0x8f0 [0x03530e4454a1] >> jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, >> _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .isra.96] >> [clone .constprop.117]+0x1e1 (malloc=726749KB type=Internal >> #2385226) > >> While other blocks also show some variation, none show growth >> like this one. When I do some math on the number (726749KB - >> 33783KB) / (2385226 – 110876) it comes down to a pretty even 312 >> bytes per allocation. And we leaked just under 700Mb. While not >> immediately problematic, this does not bode well for our >> customers who run this service for months. > >> I’d like to avoid telling them they need to restart this service >> every two weeks to reclaim memory. Has anyone seen something >> like this? Any way it could be avoided? > > That was some very good sleuthing on your part. 312 bytes per > allocation will indeed be very difficult to detect unless you are > really looking hard for it. > > On 4/4/20 13:02, Mark Boon wrote: >> The connector of the webapp uses Http11NioProtocol. My >> understanding is it uses direct-byte-buffers backed by native >> memory for the Nio channels. I don't know for sure if that gets >> allocated through a JNI call, but that was my assumption. > > This will definitely use Tomcat's NIO protocol which doesn't use > the APR connector. However, you still might be using tcnative to > get the crypto engine. Can you confirm the thread-naming convention > of your request-processing threads? They will tell you if JSSE or > OpenSSL (tcnative) is being used. > > A few data points: > > * No Tomcat code directly invokes jni_invoke_static(), but it might > do so indirectly through a variety of means. > > * NIO does use buffers, but those buffers tend to be (a) fairly > large -- on the order of kilobytes -- and (b) re-used for the life > of the request-processor
Re: JNI memory leak?
Thanks Chris for taking the time. As you point out, from the threads I can tell we're not using ARP as the names al all starting with "jsse". AFAI could find out BouncyCastle is a pure Java implementation, so that also can't be the cause. Someone suggested PAMLibrary may be the culprit. So I started a thread that makes continuous auth calls to the PAM library. Now there does seems to be an indication memory is leaking very, very slowly. It seems to be roughly in line with the number of auth failures. It looks like PAM throttles auth failures though, hence it's taking such a long time for the evidence to mount. So nothing to see here for this group. Just wanted to give a heads up. Mark On 4/6/20, 12:12 PM, "Christopher Schultz" wrote: -BEGIN PGP SIGNED MESSAGE- Hash: SHA256 Mark, On 4/3/20 21:48, Mark Boon wrote: > For the past few months we’ve been trying to trace what looks like > gradual memory creep. After some long-running experiments it seems > due to memory leaking when jni_invoke_static(JNIEnv_*, JavaValue*, > _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) > is invoked. Somewhere. > > My environment is Tomcat running a proxy webapp. It does TLS > termination, authentication and then forwards the call to local > services. It doesn’t do much else, it’s a relatively small > application. > > Some (possibly relevant) versions and config parameters: Tomcat > 8.5 Java 8u241 (Oracle) Heap size = 360Mb MAX_ALLOC_ARENA=2 > MALLOC_TRIM_THRESHOLD_=250048 jdk.nio.maxCachedBufferSize=25600 > > We couldn’t find any proof of memory leaking on the Java side. When > we turn on NativeMemoryTracking=detail and we take a snapshot > shortly after starting, we see (just one block shown): > > [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa > [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, > Handle, JavaValue*, Thread*)+0x6a [0x03530e3fa000] > JavaCalls::call_helper(JavaValue*, methodHandle*, > JavaCallArguments*, Thread*)+0x8f0 [0x03530e4454a1] > jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, > _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .isra.96] [clone > .constprop.117]+0x1e1 (malloc=33783KB type=Internal #110876) > > Then we run it under heavy load for a few weeks and take another > snapshot: > > [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa > [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, > Handle, JavaValue*, Thread*)+0x6a [0x03530e3fa000] > JavaCalls::call_helper(JavaValue*, methodHandle*, > JavaCallArguments*, Thread*)+0x8f0 [0x03530e4454a1] > jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, > _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .isra.96] [clone > .constprop.117]+0x1e1 (malloc=726749KB type=Internal #2385226) > > While other blocks also show some variation, none show growth like > this one. When I do some math on the number (726749KB - 33783KB) / > (2385226 – 110876) it comes down to a pretty even 312 bytes per > allocation. And we leaked just under 700Mb. While not immediately > problematic, this does not bode well for our customers who run this > service for months. > > I’d like to avoid telling them they need to restart this service > every two weeks to reclaim memory. Has anyone seen something like > this? Any way it could be avoided? That was some very good sleuthing on your part. 312 bytes per allocation will indeed be very difficult to detect unless you are really looking hard for it. On 4/4/20 13:02, Mark Boon wrote: > The connector of the webapp uses Http11NioProtocol. My > understanding is it uses direct-byte-buffers backed by native > memory for the Nio channels. I don't know for sure if that gets > allocated through a JNI call, but that was my assumption. This will definitely use Tomcat's NIO protocol which doesn't use the APR connector. However, you still might be using tcnative to get the crypto engine. Can you confirm the thread-naming convention of your request-processing threads? They will tell you if JSSE or OpenSSL (tcnative) is being used. A few data points: * No Tomcat code directly invokes jni_invoke_static(), but it might do so indirectly through a variety of means. * NIO does use buffers, but those buffers tend to be (a) fairly large - -- on the order of kilobytes -- and (b) re-used for the life of the request-processor thread. It is very possible that there is a very small leak in Tomcat's handling of NIO buffers. I think it's equally likely that there is a bug in the JVM itself. Are you able to try different JVM versions in your test? I would recommend major-version changes,
Re: JNI memory leak?
-BEGIN PGP SIGNED MESSAGE- Hash: SHA256 Mark, On 4/3/20 21:48, Mark Boon wrote: > For the past few months we’ve been trying to trace what looks like > gradual memory creep. After some long-running experiments it seems > due to memory leaking when jni_invoke_static(JNIEnv_*, JavaValue*, > _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) > is invoked. Somewhere. > > My environment is Tomcat running a proxy webapp. It does TLS > termination, authentication and then forwards the call to local > services. It doesn’t do much else, it’s a relatively small > application. > > Some (possibly relevant) versions and config parameters: Tomcat > 8.5 Java 8u241 (Oracle) Heap size = 360Mb MAX_ALLOC_ARENA=2 > MALLOC_TRIM_THRESHOLD_=250048 jdk.nio.maxCachedBufferSize=25600 > > We couldn’t find any proof of memory leaking on the Java side. When > we turn on NativeMemoryTracking=detail and we take a snapshot > shortly after starting, we see (just one block shown): > > [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa > [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, > Handle, JavaValue*, Thread*)+0x6a [0x03530e3fa000] > JavaCalls::call_helper(JavaValue*, methodHandle*, > JavaCallArguments*, Thread*)+0x8f0 [0x03530e4454a1] > jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, > _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .isra.96] [clone > .constprop.117]+0x1e1 (malloc=33783KB type=Internal #110876) > > Then we run it under heavy load for a few weeks and take another > snapshot: > > [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa > [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, > Handle, JavaValue*, Thread*)+0x6a [0x03530e3fa000] > JavaCalls::call_helper(JavaValue*, methodHandle*, > JavaCallArguments*, Thread*)+0x8f0 [0x03530e4454a1] > jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, > _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .isra.96] [clone > .constprop.117]+0x1e1 (malloc=726749KB type=Internal #2385226) > > While other blocks also show some variation, none show growth like > this one. When I do some math on the number (726749KB - 33783KB) / > (2385226 – 110876) it comes down to a pretty even 312 bytes per > allocation. And we leaked just under 700Mb. While not immediately > problematic, this does not bode well for our customers who run this > service for months. > > I’d like to avoid telling them they need to restart this service > every two weeks to reclaim memory. Has anyone seen something like > this? Any way it could be avoided? That was some very good sleuthing on your part. 312 bytes per allocation will indeed be very difficult to detect unless you are really looking hard for it. On 4/4/20 13:02, Mark Boon wrote: > The connector of the webapp uses Http11NioProtocol. My > understanding is it uses direct-byte-buffers backed by native > memory for the Nio channels. I don't know for sure if that gets > allocated through a JNI call, but that was my assumption. This will definitely use Tomcat's NIO protocol which doesn't use the APR connector. However, you still might be using tcnative to get the crypto engine. Can you confirm the thread-naming convention of your request-processing threads? They will tell you if JSSE or OpenSSL (tcnative) is being used. A few data points: * No Tomcat code directly invokes jni_invoke_static(), but it might do so indirectly through a variety of means. * NIO does use buffers, but those buffers tend to be (a) fairly large - -- on the order of kilobytes -- and (b) re-used for the life of the request-processor thread. It is very possible that there is a very small leak in Tomcat's handling of NIO buffers. I think it's equally likely that there is a bug in the JVM itself. Are you able to try different JVM versions in your test? I would recommend major-version changes, here. I thought I read somewhere that Oracle re-wrote the implementation of the NIO API in a somewhat recent Java release (Java 9?), but I can't seem to find that reference, now. Are you able to try: - - Java 8 - - Java 9/10/11/12 - - Java 13 - -chris PS This bug report may be relevant: https://bugs.openjdk.java.net/browse/JDK-8190395 The bug report says it's closed/incomplete, but they do mention a 312-byte leak with certain invocations. -BEGIN PGP SIGNATURE- Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/ iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl6Lfx8ACgkQHPApP6U8 pFiGEQ/7BweMhSjALeMhEoAURv6NarT33Nb1ydHynOmDXnSXbczO+B6MC1j9QjHD 2sdYsPRLpi8holt2pl3dLxrsWE4gkK27e+2hwNN7568P/9S03m9VzpdciuwBCwfu 0acFtRs8iWcJO0jI29R438lt6w1CY6QGV2rasZKhkhaoBA8K9mSb0J02KUhDlpbn oljBKA2k1oeqEDJpJoejsX7Zwgaf2aM96VZNds8Atly1WZhqj0nENwtU4yaIxel5 HyHrjOLsHMLPZeTDx/5pFs45qTGfFos1YF1lf99EDdKuX9qv+X+Dr2vr0RZW2iw8 5Oxh0EqAjMko9ysvjo2N7cnKK5fLNvAHRAGBIqDlAtcWF51vddeMASHjKYmM+/ha pvN3/Dff65QXK74fgIk10Yqro1REudYcXTXT2+9WdycS06HOORndQaMs3l0qqaLG
Re: JNI memory leak?
> On Sat, Apr 4, 2020 at 10:39 AM Thomas Meyer wrote: > > April 2020 14:53:17 MESZ schrieb calder wrote: [ snip ] > >So, ultimately, I'm confused why we think Tomcat is "to blame" as > >there is no evidence it uses JNI. > >It's my experience JNI memory issues are related to the Java JNI or > >proprietary native code. > > I think jni is used via apr in tomcat. > > Do you use apr http connector? Thomas - thanks for correcting my oversight - I obviously wasn't thinking about the Native Library user@stimpy:~/Desktop/tomcat-source/tomcat-native-1.2.23-src> find . -name "*jni*" -ls 818614714 0 drwxr-xr-x 2 user users 138 Jun 26 2019 ./examples/org/apache/tomcat/jni 544916739 8 -rwxr-xr-x 1 user users7639 Jun 26 2019 ./jnirelease.sh 21107212 12 -rw-r--r-- 1 user users 11352 Jun 26 2019 ./native/src/jnilib.c 812313638 0 drwxr-xr-x 2 user users 150 Jun 26 2019 ./test/org/apache/tomcat/jni 25339941 4 drwxr-xr-x 2 user users4096 Jun 26 2019 ./java/org/apache/tomcat/jni - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: JNI memory leak?
On Sat, Apr 4, 2020, 12:02 Mark Boon wrote: > I don't have 'proof' Tomcat is to blame. Hence the question-mark. All I > have managed is narrow it down to this NMT data, which is not very > informative. I hoped anyone could give me an idea how or where to > investigate further. Or if someone had run into this before. > > The connector of the webapp uses Http11NioProtocol. My understanding is it > uses direct-byte-buffers backed by native memory for the Nio channels. I > don't know for sure if that gets allocated through a JNI call, but that was > my assumption. > > I did not consider trying Mission Control or jvisualvm. Isn't Mission > Control for embedded Java? And AFAIK, jvisualvm is for profiling Java > memory usage and underneath uses tools like jmap, jstat and jcmd. Through > GC logs and jmap heap-dumps I can confidently say there's no memory leak on > the Java side. The NMT data shown comes from jcmd. No type grows beyond > control and full GC always returns to the same baseline for the heap. > Anyway, the Java heap is only 360Mb and this memory-block created by > jni_invoke_static has grown to 700Mb by itself. And I see no out-of-memory > messages. The only hint of this happening is that the RES memory of the > Tomcat process keeps growing over time, as shown by 'top'. And it seems GC > is getting slower over time, but the customers haven't noticed it yet. > (This is after we switched to ParallelGC. We did see considerable slow-down > when using G1GC in the ref-processing, but we couldn't figure out why. It > would slow to a crawl before the memory leak became obvious.) > > Anyway, I was mostly fishing for hints or tips that could help me figure > this out or avoid it. > > The application is simple to the point I'm hard-pressed to think of any > other part making JNI calls. The only library I can think of using JNI is > BouncyCastle doing the SSL encryption/decryption, so maybe I'll switch my > focus there. > Something else to consider - we should keep in mind that a JVM is loaded for the native code, but won't be obvious in a process table : )
[OT] Re: JNI memory leak?
On April 4, 2020 7:26:05 PM UTC, calder wrote: >m > >On Sat, Apr 4, 2020, 14:14 Frank Tornack wrote: > >> Good evening, >> I have a question about your e-mail address. Why does the address end >> on com.INVALID? How do you get such an address? >> > >That question is off topic. Subject line adjusted accordingly. >The invalid is too avoid spam email No it isn't. And to side track for a moment it is very unhelpful to state something as a fact when it is, at best, an educated guess. Especially when, as in this case, that guess is wrong. Guesses can be acceptable responses to questions on this list but it must be made clear to readers that it is a guess The .INVALID is added by the ASF mailing list software (strictly a custom extension written by the ASF does this) when the originator posts from a domain that has a strict SPF record. If the ASF didn't do this, recipients that check SPF records would reject the mail as the originator's domain will not list the ASF mail servers as permitted senders for the originator's domain. In short, .INVALID is added to make sure the message is received by all subscribers. Mark - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: JNI memory leak?
m On Sat, Apr 4, 2020, 14:14 Frank Tornack wrote: > Good evening, > I have a question about your e-mail address. Why does the address end > on com.INVALID? How do you get such an address? > That question is off topic. The invalid is too avoid spam email
Re: JNI memory leak?
Good evening, I have a question about your e-mail address. Why does the address end on com.INVALID? How do you get such an address? Sorry for the interposed question, Am Samstag, den 04.04.2020, 01:48 + schrieb Mark Boon: > For the past few months we’ve been trying to trace what looks like > gradual memory creep. After some long-running experiments it seems > due to memory leaking when > jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, > _jmethodID*, JNI_ArgumentPusher*, Thread*) is invoked. Somewhere. > > My environment is Tomcat running a proxy webapp. It does TLS > termination, authentication and then forwards the call to local > services. It doesn’t do much else, it’s a relatively small > application. > > Some (possibly relevant) versions and config parameters: > Tomcat 8.5 > Java 8u241 (Oracle) > Heap size = 360Mb > MAX_ALLOC_ARENA=2 > MALLOC_TRIM_THRESHOLD_=250048 > jdk.nio.maxCachedBufferSize=25600 > > We couldn’t find any proof of memory leaking on the Java side. > When we turn on NativeMemoryTracking=detail and we take a snapshot > shortly after starting, we see (just one block shown): > > [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa > [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, > Handle, JavaValue*, Thread*)+0x6a > [0x03530e3fa000] JavaCalls::call_helper(JavaValue*, > methodHandle*, JavaCallArguments*, Thread*)+0x8f0 > [0x03530e4454a1] jni_invoke_static(JNIEnv_*, JavaValue*, > _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) > [clone .isra.96] [clone .constprop.117]+0x1e1 > (malloc=33783KB type=Internal #110876) > > Then we run it under heavy load for a few weeks and take another > snapshot: > > [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa > [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, > Handle, JavaValue*, Thread*)+0x6a > [0x03530e3fa000] JavaCalls::call_helper(JavaValue*, > methodHandle*, JavaCallArguments*, Thread*)+0x8f0 > [0x03530e4454a1] jni_invoke_static(JNIEnv_*, JavaValue*, > _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) > [clone .isra.96] [clone .constprop.117]+0x1e1 > (malloc=726749KB type=Internal #2385226) > > While other blocks also show some variation, none show growth like > this one. When I do some math on the number (726749KB - 33783KB) / > (2385226 – 110876) it comes down to a pretty even 312 bytes per > allocation. > And we leaked just under 700Mb. While not immediately problematic, > this does not bode well for our customers who run this service for > months. > > I’d like to avoid telling them they need to restart this service > every two weeks to reclaim memory. Has anyone seen something like > this? Any way it could be avoided? > > Mark Boon > > > - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: JNI memory leak?
I don't have 'proof' Tomcat is to blame. Hence the question-mark. All I have managed is narrow it down to this NMT data, which is not very informative. I hoped anyone could give me an idea how or where to investigate further. Or if someone had run into this before. The connector of the webapp uses Http11NioProtocol. My understanding is it uses direct-byte-buffers backed by native memory for the Nio channels. I don't know for sure if that gets allocated through a JNI call, but that was my assumption. I did not consider trying Mission Control or jvisualvm. Isn't Mission Control for embedded Java? And AFAIK, jvisualvm is for profiling Java memory usage and underneath uses tools like jmap, jstat and jcmd. Through GC logs and jmap heap-dumps I can confidently say there's no memory leak on the Java side. The NMT data shown comes from jcmd. No type grows beyond control and full GC always returns to the same baseline for the heap. Anyway, the Java heap is only 360Mb and this memory-block created by jni_invoke_static has grown to 700Mb by itself. And I see no out-of-memory messages. The only hint of this happening is that the RES memory of the Tomcat process keeps growing over time, as shown by 'top'. And it seems GC is getting slower over time, but the customers haven't noticed it yet. (This is after we switched to ParallelGC. We did see considerable slow-down when using G1GC in the ref-processing, but we couldn't figure out why. It would slow to a crawl before the memory leak became obvious.) Anyway, I was mostly fishing for hints or tips that could help me figure this out or avoid it. The application is simple to the point I'm hard-pressed to think of any other part making JNI calls. The only library I can think of using JNI is BouncyCastle doing the SSL encryption/decryption, so maybe I'll switch my focus there. Thanks for taking the time to think along. Mark On 4/4/20, 5:50 AM, "calder" wrote: On Fri, Apr 3, 2020 at 8:48 PM Mark Boon wrote: > > For the past few months we’ve been trying to trace what looks like gradual memory creep. After some long-running experiments it seems due to memory leaking when > jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) is invoked. Somewhere. > > My environment is Tomcat running a proxy webapp. It does TLS termination, authentication and then forwards the call to local services. It doesn’t do much else, it’s a relatively small application. > > Some (possibly relevant) versions and config parameters: > Tomcat 8.5 > Java 8u241 (Oracle) > Heap size = 360Mb > MAX_ALLOC_ARENA=2 > MALLOC_TRIM_THRESHOLD_=250048 > jdk.nio.maxCachedBufferSize=25600 > > We couldn’t find any proof of memory leaking on the Java side. > When we turn on NativeMemoryTracking=detail and we take a snapshot shortly after starting, we see (just one block shown): > > [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa > [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, Handle, JavaValue*, Thread*)+0x6a > [0x03530e3fa000] JavaCalls::call_helper(JavaValue*, methodHandle*, JavaCallArguments*, Thread*)+0x8f0 > [0x03530e4454a1] jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .isra.96] [clone .constprop.117]+0x1e1 > (malloc=33783KB type=Internal #110876) > > Then we run it under heavy load for a few weeks and take another snapshot: > > [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa > [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, Handle, JavaValue*, Thread*)+0x6a > [0x03530e3fa000] JavaCalls::call_helper(JavaValue*, methodHandle*, JavaCallArguments*, Thread*)+0x8f0 > [0x03530e4454a1] jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .isra.96] [clone .constprop.117]+0x1e1 > (malloc=726749KB type=Internal #2385226) > > While other blocks also show some variation, none show growth like this one. When I do some math on the number (726749KB - 33783KB) / (2385226 – 110876) it comes down to a pretty even 312 bytes per allocation. > And we leaked just under 700Mb. While not immediately problematic, this does not bode well for our customers who run this service for months. > > I’d like to avoid telling them they need to restart this service every two weeks to reclaim memory. Has anyone seen something like this? Any way it could be avoided? I'm a bit confused. Your stated title is "JNI Memory Leak?" Tomcat, to my intimate knowledge, does not use JNI (correct m
Re: JNI memory leak?
Am 4. April 2020 14:53:17 MESZ schrieb calder : >On Fri, Apr 3, 2020 at 8:48 PM Mark Boon >wrote: >> >> For the past few months we’ve been trying to trace what looks like >gradual memory creep. After some long-running experiments it seems due >to memory leaking when >> jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, >_jmethodID*, JNI_ArgumentPusher*, Thread*) is invoked. Somewhere. >> >> My environment is Tomcat running a proxy webapp. It does TLS >termination, authentication and then forwards the call to local >services. It doesn’t do much else, it’s a relatively small application. >> >> Some (possibly relevant) versions and config parameters: >> Tomcat 8.5 >> Java 8u241 (Oracle) >> Heap size = 360Mb >> MAX_ALLOC_ARENA=2 >> MALLOC_TRIM_THRESHOLD_=250048 >> jdk.nio.maxCachedBufferSize=25600 >> >> We couldn’t find any proof of memory leaking on the Java side. >> When we turn on NativeMemoryTracking=detail and we take a snapshot >shortly after starting, we see (just one block shown): >> >> [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa >> [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, >Handle, JavaValue*, Thread*)+0x6a >> [0x03530e3fa000] JavaCalls::call_helper(JavaValue*, >methodHandle*, JavaCallArguments*, Thread*)+0x8f0 >> [0x03530e4454a1] jni_invoke_static(JNIEnv_*, JavaValue*, >_jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) >[clone .isra.96] [clone .constprop.117]+0x1e1 >> (malloc=33783KB type=Internal #110876) >> >> Then we run it under heavy load for a few weeks and take another >snapshot: >> >> [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa >> [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, >Handle, JavaValue*, Thread*)+0x6a >> [0x03530e3fa000] JavaCalls::call_helper(JavaValue*, >methodHandle*, JavaCallArguments*, Thread*)+0x8f0 >> [0x03530e4454a1] jni_invoke_static(JNIEnv_*, JavaValue*, >_jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) >[clone .isra.96] [clone .constprop.117]+0x1e1 >> (malloc=726749KB type=Internal #2385226) >> >> While other blocks also show some variation, none show growth like >this one. When I do some math on the number (726749KB - 33783KB) / >(2385226 – 110876) it comes down to a pretty even 312 bytes per >allocation. >> And we leaked just under 700Mb. While not immediately problematic, >this does not bode well for our customers who run this service for >months. >> >> I’d like to avoid telling them they need to restart this service >every two weeks to reclaim memory. Has anyone seen something like this? >Any way it could be avoided? > >I'm a bit confused. Your stated title is "JNI Memory Leak?" >Tomcat, to my intimate knowledge, does not use JNI (correct me if I'm >rwong) >( quick check > user@stimpy:~/Desktop/tomcat-source/apache-tomcat-8.5.53-src> find . >-name *.c -ls > user@stimpy:~/Desktop/tomcat-source/apache-tomcat-8.5.53-src> find . >-name *.cpp -ls > user@stimpy:~/Desktop/tomcat-source/apache-tomcat-8.5.53-src> find . >-name *.asm -ls > user@stimpy:~/Desktop/tomcat-source/apache-tomcat-8.5.53-src> find . >-name *.pas -ls >} > >a) for the "snapshots" provided, there is NO reference to their >association, ie, "what" code are those related to? >b) could you run Mission Control or jvisualvm to locate a stack trace >for this? > >We have two apps that use JNI and run via Tomcat (and another app >server) - one is "so old" that it is limited to 32-bit . the one >memory leak we have encountered was related to the "native side" (for >us, the native-compiled Pascal side of things (we also use Assembly >code) via Java's JNI code). > >So, ultimately, I'm confused why we think Tomcat is "to blame" as >there is no evidence it uses JNI. >It's my experience JNI memory issues are related to the Java JNI or >proprietary native code. > >- >To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org >For additional commands, e-mail: users-h...@tomcat.apache.org Hi, I think jni is used via apr in tomcat. Do you use apr http connector? -- Diese Nachricht wurde von meinem Android-Gerät mit K-9 Mail gesendet. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: JNI memory leak?
On Fri, Apr 3, 2020 at 8:48 PM Mark Boon wrote: > > For the past few months we’ve been trying to trace what looks like gradual > memory creep. After some long-running experiments it seems due to memory > leaking when > jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, > JNI_ArgumentPusher*, Thread*) is invoked. Somewhere. > > My environment is Tomcat running a proxy webapp. It does TLS termination, > authentication and then forwards the call to local services. It doesn’t do > much else, it’s a relatively small application. > > Some (possibly relevant) versions and config parameters: > Tomcat 8.5 > Java 8u241 (Oracle) > Heap size = 360Mb > MAX_ALLOC_ARENA=2 > MALLOC_TRIM_THRESHOLD_=250048 > jdk.nio.maxCachedBufferSize=25600 > > We couldn’t find any proof of memory leaking on the Java side. > When we turn on NativeMemoryTracking=detail and we take a snapshot shortly > after starting, we see (just one block shown): > > [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa > [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, Handle, > JavaValue*, Thread*)+0x6a > [0x03530e3fa000] JavaCalls::call_helper(JavaValue*, methodHandle*, > JavaCallArguments*, Thread*)+0x8f0 > [0x03530e4454a1] jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, > JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .isra.96] > [clone .constprop.117]+0x1e1 > (malloc=33783KB type=Internal #110876) > > Then we run it under heavy load for a few weeks and take another snapshot: > > [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa > [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, Handle, > JavaValue*, Thread*)+0x6a > [0x03530e3fa000] JavaCalls::call_helper(JavaValue*, methodHandle*, > JavaCallArguments*, Thread*)+0x8f0 > [0x03530e4454a1] jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, > JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .isra.96] > [clone .constprop.117]+0x1e1 > (malloc=726749KB type=Internal #2385226) > > While other blocks also show some variation, none show growth like this one. > When I do some math on the number (726749KB - 33783KB) / (2385226 – 110876) > it comes down to a pretty even 312 bytes per allocation. > And we leaked just under 700Mb. While not immediately problematic, this does > not bode well for our customers who run this service for months. > > I’d like to avoid telling them they need to restart this service every two > weeks to reclaim memory. Has anyone seen something like this? Any way it > could be avoided? I'm a bit confused. Your stated title is "JNI Memory Leak?" Tomcat, to my intimate knowledge, does not use JNI (correct me if I'm rwong) ( quick check user@stimpy:~/Desktop/tomcat-source/apache-tomcat-8.5.53-src> find . -name *.c -ls user@stimpy:~/Desktop/tomcat-source/apache-tomcat-8.5.53-src> find . -name *.cpp -ls user@stimpy:~/Desktop/tomcat-source/apache-tomcat-8.5.53-src> find . -name *.asm -ls user@stimpy:~/Desktop/tomcat-source/apache-tomcat-8.5.53-src> find . -name *.pas -ls } a) for the "snapshots" provided, there is NO reference to their association, ie, "what" code are those related to? b) could you run Mission Control or jvisualvm to locate a stack trace for this? We have two apps that use JNI and run via Tomcat (and another app server) - one is "so old" that it is limited to 32-bit . the one memory leak we have encountered was related to the "native side" (for us, the native-compiled Pascal side of things (we also use Assembly code) via Java's JNI code). So, ultimately, I'm confused why we think Tomcat is "to blame" as there is no evidence it uses JNI. It's my experience JNI memory issues are related to the Java JNI or proprietary native code. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
JNI memory leak?
For the past few months we’ve been trying to trace what looks like gradual memory creep. After some long-running experiments it seems due to memory leaking when jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) is invoked. Somewhere. My environment is Tomcat running a proxy webapp. It does TLS termination, authentication and then forwards the call to local services. It doesn’t do much else, it’s a relatively small application. Some (possibly relevant) versions and config parameters: Tomcat 8.5 Java 8u241 (Oracle) Heap size = 360Mb MAX_ALLOC_ARENA=2 MALLOC_TRIM_THRESHOLD_=250048 jdk.nio.maxCachedBufferSize=25600 We couldn’t find any proof of memory leaking on the Java side. When we turn on NativeMemoryTracking=detail and we take a snapshot shortly after starting, we see (just one block shown): [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, Handle, JavaValue*, Thread*)+0x6a [0x03530e3fa000] JavaCalls::call_helper(JavaValue*, methodHandle*, JavaCallArguments*, Thread*)+0x8f0 [0x03530e4454a1] jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .isra.96] [clone .constprop.117]+0x1e1 (malloc=33783KB type=Internal #110876) Then we run it under heavy load for a few weeks and take another snapshot: [0x03530e462f9a] JNIHandleBlock::allocate_block(Thread*)+0xaa [0x03530e3f759a] JavaCallWrapper::JavaCallWrapper(methodHandle, Handle, JavaValue*, Thread*)+0x6a [0x03530e3fa000] JavaCalls::call_helper(JavaValue*, methodHandle*, JavaCallArguments*, Thread*)+0x8f0 [0x03530e4454a1] jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, Thread*) [clone .isra.96] [clone .constprop.117]+0x1e1 (malloc=726749KB type=Internal #2385226) While other blocks also show some variation, none show growth like this one. When I do some math on the number (726749KB - 33783KB) / (2385226 – 110876) it comes down to a pretty even 312 bytes per allocation. And we leaked just under 700Mb. While not immediately problematic, this does not bode well for our customers who run this service for months. I’d like to avoid telling them they need to restart this service every two weeks to reclaim memory. Has anyone seen something like this? Any way it could be avoided? Mark Boon
