I have found a problem where a shared library that is called with JNA under jetty gets stuck when printing to stderr.
I have simplified the problem to make it easy to reproduce by first creating a very simple C shared library which does nothing more than call fprintf(stderr,"0123456789\n"); 100 times, then return.
On the java side we have a synchronise statement on a global lock to ensure only one thread is in the shared library at a time.
synchronized (lock) {
Foo.INSTANCE.shared_lib_function();
}
I deploy this under jetty and make constant requests to jetty to call the shared library eventually (after less than 100 requests) I find that the shared library gets stuck.
Using jstack we can see the thread which is stuck inside the call to the shared library (classes have been renamed):
Thread 5991: (state = BLOCKED)
- com.whats.going.on.connector.MyFooCaller.callIt() @bci=55, line=105 (Interpreted frame)
- com.whats.going.on.Controller.callSharedLib() @bci=101, line=71 (Interpreted frame)
- com.whats.going.on.Controller$$FastClassBySpringCGLIB$$d6a0f4b3.invoke(int, java.lang.Object, java.lang.Object[]) @bci=72 (Interpreted frame)
- org.springframework.cglib.proxy.MethodProxy.invoke(java.lang.Object, java.lang.Object[]) @bci=19, line=204 (Interpreted frame)
- org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint() @bci=19, line=717 (Interpreted frame)
- org.springframework.aop.framework.ReflectiveMethodInvocation.proceed() @bci=19, line=157 (Interpreted frame)
- org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(org.aopalliance.intercept.MethodInvocation) @bci=7, line=64 (Interpreted frame)
- org.springframework.aop.framework.ReflectiveMethodInvocation.proceed() @bci=101, line=179 (Interpreted frame)
- org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(java.lang.Object, java.lang.reflect.Method, java.lang.Object[], org.springframework.cglib.proxy.MethodProxy) @bci=112, line=653 (Interpreted frame)
Using gdb I am able to get a backtrace from within my shared library:
#0 0x00007f1136ec153d in write () from /lib64/libc.so.6
#1 0x00007f1136e57ad3 in _IO_new_file_write () from /lib64/libc.so.6
#2 0x00007f1136e5799a in _IO_new_file_xsputn () from /lib64/libc.so.6
#3 0x00007f1136e4da4d in fwrite () from /lib64/libc.so.6
#4 0x00007f10ed2dc122 in shared_lib_function () at foo/bar.c:357
#5 0x00007f10ed4d227c in ?? ()
#6 0x000000000000000e in ?? ()
#7 0x00007f110c2309c0 in ?? ()
#8 0x00007f110c230700 in ?? ()
#9 0x00007f10ed4d1ddf in ?? ()
#10 0x0000000000000000 in ?? ()
line 357 is a fprintf() line.
I was concerned that perhaps the issue was something getting stuck only readying from stdout and never stderr. Within java I created a thread which keeps printing to stdout and stderr and I can see both.
I also tried to see what would happen if we did 100 calls to System.err.println("9876543210"); within java and, however that did not cause a thread in java to get stuck.
Originally when logging this stderr and stdout was redirected with:
PrintStream errorLog = new PrintStream(new RolloverFileOutputStream(new Fil("yyyy_mm_dd.error.log").getCanonicalPath(), false, 90));
System.setErr(errorLog);
System.setOut(errorLog);
I was able to see what the shared lib was writing to stderr in the log file. I then removed the redirection of stderr and stdout that and noticed I could no longer see what the shared library was writing to stderr, however I could see that System.err.println() was printing.
When I tried calling the shared library within a test (without jetty) I was unable to reproduce the problem. I ran my test from both eclipse and maven. I also tried redirecting stderr and stdout as above however I found that only writes to stderr and stdout within java was redirected (i.e. fprintf() to stderr from within the shared library continued to show up in eclipse or in the console).
Java version:
java version "1.8.0_25"
Java(TM) SE Runtime Environment (build 1.8.0_25-b17)
Java HotSpot(TM) 64-Bit Server VM (build 25.25-b02, mixed mode)
Jetty version: 9.2.6.v20141205
The problem I had was YAJSW was only reading from jetty's System.out and System.err yet not reading from any shared library's stdout or stderr which would eventually be filled if some error was happening.
The solution was to set wrapper.console.pipestreams=true, see http://yajsw.sourceforge.net/YAJSW%20Configuration%20Parameters.html
Redirecting stdout and stderr with freopen did work in the mean time. Thanks for your help.