写入 stderr 时,共享 C 库 (JNI) 在码头下挂起
Shared C library (JNI) hangs under jetty when writing to stderr
我发现一个问题,当打印到 stderr 时,在 jetty 下使用 JNA 调用的共享库卡住了。
我通过首先创建一个非常简单的 C 共享库来简化问题以使其易于重现,它只调用 fprintf(stderr,"0123456789\n");
100 次,然后调用 return.
在 java 方面,我们在全局锁上有一个同步语句,以确保一次只有一个线程在共享库中。
synchronized (lock) {
Foo.INSTANCE.shared_lib_function();
}
我在 jetty 下部署它并不断请求 jetty 最终调用共享库(在少于 100 个请求之后)我发现共享库卡住了。
使用jstack
我们可以看到卡在共享库调用中的线程(类已重命名):
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)
使用 gdb
我可以从我的共享库中获取回溯:
#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 ?? ()
第 357 行是 fprintf()
行。
我担心问题可能是卡在了只从 stdout 而不是 stderr 准备的地方。在 java 中,我创建了一个线程,它不断打印到 stdout 和 stderr,我可以看到两者。
我也试着看看如果我们在 java 中对 System.err.println("9876543210");
进行 100 次调用会发生什么,但是这并没有导致 java 中的线程卡住。
最初在记录此 stderr 和 stdout 时重定向为:
PrintStream errorLog = new PrintStream(new RolloverFileOutputStream(new Fil("yyyy_mm_dd.error.log").getCanonicalPath(), false, 90));
System.setErr(errorLog);
System.setOut(errorLog);
我能够在日志文件中看到共享库正在向 stderr 写入什么。然后我删除了 stderr 和 stdout 的重定向,并注意到我无法再看到共享库正在向 stderr 写入什么,但是我可以看到 System.err.println()
正在打印。
当我尝试在测试中调用共享库(没有码头)时,我无法重现问题。我 运行 我的测试来自 eclipse 和 maven。我也尝试如上所述重定向 stderr 和 stdout 但是我发现只有 java 内的 stderr 和 stdout 被重定向(即 fprintf()
从共享库中到 stderr 继续出现在 eclipse 或安慰)。
Java版本:
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)
码头版本:9.2.6.v20141205
从 JNI 写入 STDERR,对大多数 java 日志框架来说效果不佳。
选项 #1:Java 侧修复
您需要做什么:
- 不要使用 Jetty 的默认日志记录模块
- 不要使用 Jetty 的 StdErrLog 实现
- 配置替代日志记录框架。从 slf4j 开始并将其设置为使用类似 logback 或 log4j 的东西。
- 将您的备用日志记录框架配置为不捕获 STDERR。
- 将您的备用日志记录框架配置为不写入 STDERR,让它只写入日志文件。
选项 #2:JNI 侧修复
另一种选择是将 JNI 代码编写为从不输出到默认的 STDERR 或 STDOUT 流。但取而代之的是获取对 Java System.err 和 System.out 的文件句柄引用,然后写入这些文件。
可以在
的 comp.lang.java.programmer 组中找到这方面的示例
https://groups.google.com/forum/#!msg/comp.lang.java.programmer/SUN7EEjk8AU/JWjGGaD0ey0J
我遇到的问题是 YAJSW 只从码头的 System.out 和 System.err 读取,但没有从任何共享库的 stdout 或 stderr 读取,如果发生错误,它们最终会被填充。
解决方案是设置 wrapper.console.pipestreams=true,参见 http://yajsw.sourceforge.net/YAJSW%20Configuration%20Parameters.html
同时使用 freopen 重定向 stdout 和 stderr 确实有效。感谢您的帮助。
我发现一个问题,当打印到 stderr 时,在 jetty 下使用 JNA 调用的共享库卡住了。
我通过首先创建一个非常简单的 C 共享库来简化问题以使其易于重现,它只调用 fprintf(stderr,"0123456789\n");
100 次,然后调用 return.
在 java 方面,我们在全局锁上有一个同步语句,以确保一次只有一个线程在共享库中。
synchronized (lock) {
Foo.INSTANCE.shared_lib_function();
}
我在 jetty 下部署它并不断请求 jetty 最终调用共享库(在少于 100 个请求之后)我发现共享库卡住了。
使用jstack
我们可以看到卡在共享库调用中的线程(类已重命名):
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)
使用 gdb
我可以从我的共享库中获取回溯:
#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 ?? ()
第 357 行是 fprintf()
行。
我担心问题可能是卡在了只从 stdout 而不是 stderr 准备的地方。在 java 中,我创建了一个线程,它不断打印到 stdout 和 stderr,我可以看到两者。
我也试着看看如果我们在 java 中对 System.err.println("9876543210");
进行 100 次调用会发生什么,但是这并没有导致 java 中的线程卡住。
最初在记录此 stderr 和 stdout 时重定向为:
PrintStream errorLog = new PrintStream(new RolloverFileOutputStream(new Fil("yyyy_mm_dd.error.log").getCanonicalPath(), false, 90));
System.setErr(errorLog);
System.setOut(errorLog);
我能够在日志文件中看到共享库正在向 stderr 写入什么。然后我删除了 stderr 和 stdout 的重定向,并注意到我无法再看到共享库正在向 stderr 写入什么,但是我可以看到 System.err.println()
正在打印。
当我尝试在测试中调用共享库(没有码头)时,我无法重现问题。我 运行 我的测试来自 eclipse 和 maven。我也尝试如上所述重定向 stderr 和 stdout 但是我发现只有 java 内的 stderr 和 stdout 被重定向(即 fprintf()
从共享库中到 stderr 继续出现在 eclipse 或安慰)。
Java版本:
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)
码头版本:9.2.6.v20141205
从 JNI 写入 STDERR,对大多数 java 日志框架来说效果不佳。
选项 #1:Java 侧修复
您需要做什么:
- 不要使用 Jetty 的默认日志记录模块
- 不要使用 Jetty 的 StdErrLog 实现
- 配置替代日志记录框架。从 slf4j 开始并将其设置为使用类似 logback 或 log4j 的东西。
- 将您的备用日志记录框架配置为不捕获 STDERR。
- 将您的备用日志记录框架配置为不写入 STDERR,让它只写入日志文件。
选项 #2:JNI 侧修复
另一种选择是将 JNI 代码编写为从不输出到默认的 STDERR 或 STDOUT 流。但取而代之的是获取对 Java System.err 和 System.out 的文件句柄引用,然后写入这些文件。
可以在
的 comp.lang.java.programmer 组中找到这方面的示例https://groups.google.com/forum/#!msg/comp.lang.java.programmer/SUN7EEjk8AU/JWjGGaD0ey0J
我遇到的问题是 YAJSW 只从码头的 System.out 和 System.err 读取,但没有从任何共享库的 stdout 或 stderr 读取,如果发生错误,它们最终会被填充。
解决方案是设置 wrapper.console.pipestreams=true,参见 http://yajsw.sourceforge.net/YAJSW%20Configuration%20Parameters.html
同时使用 freopen 重定向 stdout 和 stderr 确实有效。感谢您的帮助。